New issue
Advanced search Search tips
Note: Color blocks (like █ or █) mean that a user may not be available. Tooltip shows the reason.

Issue 825744 link

Starred by 2 users
Status: Assigned
Owner:
grunell@chromium.org
Cc:
tommi@chromium.org
ossu@chromium.org
dalecur...@chromium.org
solenberg@chromium.org
peah@chromium.org
█ olka@chromium.org
Components:
EstimatedDays: ----
NextAction: ----
OS: Windows
Pri: 3
Type: Bug



Sign in to add a comment

Incorrect input audio capture time on Windows

Project Member Reported by grunell@chromium.org, Mar 26 2018 
The input audio capture time on Windows is incorrect. We use IAudioClock::GetPosition() if available (it normally is) to get the "capture time" instead of using the capture time provided by IAudioCaptureClient::GetBuffer(). The reason is that for some devices the values are incorrect[1].

However, the timestamp from IAudioClock::GetPosition() is not the same as from IAudioCaptureClient::GetBuffer().

GetBuffer() gives "the value of the performance counter at the time that the audio endpoint device recorded the device position of the first audio frame in the data packet"[2]. (This is what we want.)

IAudioClock gives "the performance counter at the time that the audio endpoint device read the device position (*pu64Position) in response to the GetPosition call"[3]. I.e. the position the device happens to be at when the function is called. This can give an incorrect timestamp for the current buffer we're processing.

The below output confirms that the timestamp is not correct. CL for output in [4]. The delay is expected to be 10 ms or a little more, since the buffer size is 10 ms (480 frames). This output is from a HP Z620 with built-in Realtek device. The same pattern for Jabra 410 and SoundBlaster Tactic3D Rage USB devices. Every other buffer the IAudioClock calculation yields 0 ms (or close to) delay.

[7592:16108:0326/102222.961:ERROR:audio_low_latency_input_win.cc(479)] GetBuffer:  capture_time_100ns = 27260375465281, device_position = 0, num_frames_to_read = 480, flags = 1, now = 2726037556788 bogo-microseconds
[7592:16108:0326/102222.961:ERROR:audio_low_latency_input_win.cc(487)] GetBuffer delay:  10 ms
[7592:16108:0326/102222.961:ERROR:audio_low_latency_input_win.cc(510)] AudioClock: capture_time_100ns = 0, device_position = 1920
[7592:16108:0326/102222.961:ERROR:audio_low_latency_input_win.cc(520)] No capture time ya'll
[7592:16108:0326/102222.962:ERROR:audio_low_latency_input_win.cc(524)] AudioClock delay: 0 ms
[7592:16108:0326/102222.971:ERROR:audio_low_latency_input_win.cc(479)] GetBuffer:  capture_time_100ns = 27260375565305, device_position = 480, num_frames_to_read = 480, flags = 0, now = 2726037566770 bogo-microseconds
[7592:16108:0326/102222.974:ERROR:audio_low_latency_input_win.cc(487)] GetBuffer delay:  13 ms
[7592:16108:0326/102222.974:ERROR:audio_low_latency_input_win.cc(510)] AudioClock: capture_time_100ns = 27260375665930, device_position = 3840
[7592:16108:0326/102222.975:ERROR:audio_low_latency_input_win.cc(524)] AudioClock delay: 3 ms
[7592:16108:0326/102222.981:ERROR:audio_low_latency_input_win.cc(479)] GetBuffer:  capture_time_100ns = 27260375665297, device_position = 960, num_frames_to_read = 480, flags = 0, now = 2726037576735 bogo-microseconds
[7592:16108:0326/102222.981:ERROR:audio_low_latency_input_win.cc(487)] GetBuffer delay:  10 ms
[7592:16108:0326/102222.981:ERROR:audio_low_latency_input_win.cc(510)] AudioClock: capture_time_100ns = 27260375665930, device_position = 5760
[7592:16108:0326/102222.981:ERROR:audio_low_latency_input_win.cc(524)] AudioClock delay: 10 ms
[7592:16108:0326/102222.992:ERROR:audio_low_latency_input_win.cc(479)] GetBuffer:  capture_time_100ns = 27260375765326, device_position = 1440, num_frames_to_read = 480, flags = 0, now = 2726037587425 bogo-microseconds
[7592:16108:0326/102222.992:ERROR:audio_low_latency_input_win.cc(487)] GetBuffer delay:  11 ms
[7592:16108:0326/102222.992:ERROR:audio_low_latency_input_win.cc(510)] AudioClock: capture_time_100ns = 27260375872409, device_position = 7680
[7592:16108:0326/102222.992:ERROR:audio_low_latency_input_win.cc(524)] AudioClock delay: 0 ms
[7592:16108:0326/102223.002:ERROR:audio_low_latency_input_win.cc(479)] GetBuffer:  capture_time_100ns = 27260375865339, device_position = 1920, num_frames_to_read = 480, flags = 0, now = 2726037597456 bogo-microseconds
[7592:16108:0326/102223.002:ERROR:audio_low_latency_input_win.cc(487)] GetBuffer delay:  11 ms
[7592:16108:0326/102223.002:ERROR:audio_low_latency_input_win.cc(510)] AudioClock: capture_time_100ns = 27260375872409, device_position = 9600
[7592:16108:0326/102223.002:ERROR:audio_low_latency_input_win.cc(524)] AudioClock delay: 10 ms
[7592:16108:0326/102223.011:ERROR:audio_low_latency_input_win.cc(479)] GetBuffer:  capture_time_100ns = 27260375965273, device_position = 2400, num_frames_to_read = 480, flags = 0, now = 2726037606893 bogo-microseconds
[7592:16108:0326/102223.014:ERROR:audio_low_latency_input_win.cc(487)] GetBuffer delay:  13 ms
[7592:16108:0326/102223.015:ERROR:audio_low_latency_input_win.cc(510)] AudioClock: capture_time_100ns = 27260376067565, device_position = 11520
[7592:16108:0326/102223.015:ERROR:audio_low_latency_input_win.cc(524)] AudioClock delay: 3 ms
[7592:16108:0326/102223.021:ERROR:audio_low_latency_input_win.cc(479)] GetBuffer:  capture_time_100ns = 27260376065439, device_position = 2880, num_frames_to_read = 480, flags = 0, now = 2726037616867 bogo-microseconds
[7592:16108:0326/102223.021:ERROR:audio_low_latency_input_win.cc(487)] GetBuffer delay:  10 ms
[7592:16108:0326/102223.021:ERROR:audio_low_latency_input_win.cc(510)] AudioClock: capture_time_100ns = 27260376067565, device_position = 13440
[7592:16108:0326/102223.021:ERROR:audio_low_latency_input_win.cc(524)] AudioClock delay: 10 ms
[7592:16108:0326/102223.031:ERROR:audio_low_latency_input_win.cc(479)] GetBuffer:  capture_time_100ns = 27260376165448, device_position = 3360, num_frames_to_read = 480, flags = 0, now = 2726037626874 bogo-microseconds
[7592:16108:0326/102223.031:ERROR:audio_low_latency_input_win.cc(487)] GetBuffer delay:  10 ms
[7592:16108:0326/102223.031:ERROR:audio_low_latency_input_win.cc(510)] AudioClock: capture_time_100ns = 27260376267531, device_position = 15360
[7592:16108:0326/102223.031:ERROR:audio_low_latency_input_win.cc(524)] AudioClock delay: 0 ms

[1] https://cs.chromium.org/chromium/src/media/audio/win/audio_low_latency_input_win.cc?l=489

[2] https://msdn.microsoft.com/en-us/library/windows/desktop/dd370859(v=vs.85).aspx

[3] https://msdn.microsoft.com/en-us/library/windows/desktop/dd370889(v=vs.85).aspx

[4] https://chromium-review.googlesource.com/c/chromium/src/+/979804

Comment 1 by grunell@chromium.org, Mar 26 2018 

Fwiw, I can't repro  issue 528894  on Win 10 with a Plantronics 648USB.

Tommi, do you remember if it repro'd consistently? Which Jabra device did you use? The jump you mention, did that happen only when the delay was way off?

I was looking into reporting stats for audio device/engine delay to see if it would increase (on some devices) if setting the buffer size to a larger value when initializing the audio client (as an experiment). The audio clock capture time cannot be used for this, but the GetBuffer() one should be possible to use.

We should prefer to use GetBuffer()'s timestamp, but if it's messed up in some cases we need to handle that.

There's the options of detecting incorrect GetBuffer() timestamps, falling back on audio clock, but that has its drawbacks.

The currently used AEC in WebRTC uses the capture time (or rather the delay calculated from it), but only in the beginning of the session. The new AEC (AEC3) doesn't.

For the delay stats I'll use the GetBuffer() value throw away unreasonable data. I'll also add a histogram for how often we get this unreasonable data.

Comment 2 by tommi@chromium.org, Mar 26 2018 

I'd guess one of those jabra pods... or possibly a set of headphones that are on my desk.
This was a few years ago though, so I don't remember the details.

Comment 3 by solenberg@chromium.org, Jun 25 2018 

Is there anything that should be done here?

Comment 4 by grunell@chromium.org, Jun 25 2018

Labels: -Pri-2 Pri-3
We should think about if there's a way to mitigate both this problem and the problem with using the timestamp from GetBuffer(). The timestamp is, afaik, only used for WebRTC's AEC in the first few seconds of a stream, and not at all in the new AEC under experiment. So priority isn't high.
►

Sign in to add a comment