New issue
Advanced search Search tips

Issue 859870 link

Starred by 2 users

Issue metadata

Status: Started
Owner:
Components:
EstimatedDays: ----
NextAction: ----
OS: Linux , Mac
Pri: 2
Type: Bug



Sign in to add a comment

Clock drift between AudioContext currentTime and getOutputTimestamp when under load

Reported by andrew.macpherson@soundtrap.com, Jul 3

Issue description

UserAgent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_5) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/67.0.3396.99 Safari/537.36

Steps to reproduce the problem:
1. Go to https://jsfiddle.net/mvg2dran/1/ and click in the document area to start the script.
2. Nodes will be added to the web audio graph until "AudioContext.currentTime - AudioContext.getOutputTimestamp().contextTime" starts returning negative values.
3. Whenever there is an audible glitch the value goes further negative and never recovers.

What is the expected behavior?

What went wrong?
This isn't currently causing a problem but came up during other AudioWorklet-related testing and seemed strange enough to warrant filing a bug. The issue may also be OSX-specific as the drift didn't seem to be permanent on Windows.

The problem only occurs in the new AudioWorklet threading model, commenting out the line calling "enableWorklet()" causes the issue to go away. That the "latency" value from the above calculation varies and even goes negative under load may be reasonable but what seems like a bug is that this drift between the two values never recovers, even if nodes are later removed from the graph so that the audio thread is no longer overloaded.

Did this work before? N/A 

Does this work in other browsers? N/A

Chrome version: 67.0.3396.99  Channel: stable
OS Version: OS X 10.13.5
Flash Version:
 
Labels: Needs-Triage-M67
Labels: Triaged-ET M-69 Target-69 FoundIn-69 OS-Linux
Status: Untriaged (was: Unconfirmed)
Able to reproduce the issue on Mac 10.13.3 and Ubuntu 17.10 using chrome reported version #67.0.3396.99 and latest canary #69.0.3482.0. Issue is not seen in OS-win.
This is a non-regression issue as it is observed from M66 old builds. 
Note: The builds older to M-66 did not start the script upon clicking the document area.

Hence, marking it as untriaged to get more inputs from dev team.

Thanks...!!
Owner: hongchan@chromium.org
Status: Assigned (was: Untriaged)
Thanks for filing the issue, Andrew! Investigating...
The AudioWorklet code doesn't do anything special in terms of the timestamp. But I found that |frames_skipped| in AudioDestination always returns 0 no matter what. (on MacOS)
Screen Shot 2018-07-11 at 9.21.22 AM.png
67.4 KB View Download
Strangely enough, the tracing tool on Windows Canary doesn't show the WebAudio module anymore.
The spec says:

"After the context’s rendering graph has started processing of blocks of audio, its currentTime attribute value always exceeds the contextTime value obtained from getOutputTimestamp method call."

So basically clamping |contextTime| with |currentTime| will be a workaround this problem.

andrew.macpherson@ WDYT? I am curious about your plan on using this feature.
Project Member

Comment 7 by bugdroid1@chromium.org, Jul 17

The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/aaf227f7bd74557f983b187c50c322180f0f38a7

commit aaf227f7bd74557f983b187c50c322180f0f38a7
Author: Hongchan Choi <hongchan@chromium.org>
Date: Tue Jul 17 22:32:29 2018

Clamp contextTime in AudioOutputTimestamp

Under the high pressure in WebAudio rendering using AudioWorkletThread,
the |contextTime| value can be negative and the current code does not
address it correctly. This CL clamps |contextTime| so it cannot past
|currentTime|.

Spec: https://webaudio.github.io/web-audio-api/#dom-audiocontext-getoutputtimestamp

"After the context’s rendering graph has started processing of blocks of audio,
its currentTime attribute value always exceeds the contextTime value obtained
from getOutputTimestamp method call."

Bug: 859870
Test: The time difference in the repro case does not go negative.
Change-Id: I2460de263045762659319a18722ace27c2b0bd47
Reviewed-on: https://chromium-review.googlesource.com/1140505
Reviewed-by: Raymond Toy <rtoy@chromium.org>
Commit-Queue: Hongchan Choi <hongchan@chromium.org>
Cr-Commit-Position: refs/heads/master@{#575811}
[modify] https://crrev.com/aaf227f7bd74557f983b187c50c322180f0f38a7/third_party/blink/renderer/modules/webaudio/audio_context.cc

Thanks hongchan@!

We have no plans to use getOutputTimestamp right now so this isn't a big issue for us, we were doing some investigation with AudioWorklets under load and seeing if there were any metrics we could use to guess that we might be getting close to glitching and this calculation was one thing we were looking at to make that guess (if we're close to 0 or negative then we may be overloading the audio processing).

I think the CL makes sense so that the implementation matches the spec (negative values not allowed) but what I was more curious about was why the value goes negative and never recovers. Running the jsfiddle above initially gives values hovering around 0ms but pretty quickly starts returning hundreds of ms difference, then multiple seconds, and continues to even if all nodes are later removed from the graph. Does this mean that there really is some kind of output lag or is it just a bug in the getOutputTimestamp implementation?
Labels: TE-Verified-M69 TE-Verified-69.0.3495.0
Able to reproduce the issue on Mac 10.13.3 using chrome build without fix.

Verified the fix on Mac 10.13.3, Win-10 and Ubuntu 14.04 using latest chrome version #69.0.3495.0 as per the comment #0.
Attaching screen cast for reference.
Observed that whenever there is an audible glitch the value did not go further negative.
Hence, the fix is working as expected. 
Adding the verified labels.

Thanks...!!
859870.mp4
520 KB View Download
Status: Started (was: Assigned)
Re #8:

This is my comment from CL: "To best of my knowledge, the cross-thread jumping costs a bit of delay and I think we need to take it into account when calculating the timestamp."
The fix is a workaround based on what the spec says. I will investigate how the timestamp is calculated and try to fix the root cause.

Sign in to add a comment