GNOME Bugzilla – Bug 796354
wasapi: playback noise
Last modified: 2018-11-03 14:23:58 UTC
Created attachment 372357 [details] recording Setup: * Windows 7 * Not in a VM * GStreamer 1.14.1 with the patches from bug 796280 I sometimes get crackling noise when using wasapisink. I can atm only reproduce with Quod Libet and not with gst-play/gst-launch alone. Sometimes it works but then starts the noise when I seek. I'll look if I can create a reproducer which is self contained. Attached is a sound sample, recorded using Audacity + wasapi loopback device. It starts normally, after a few seconds I initiate a seek to about the same position and then the noise starts.
This sounds like the pipeline is sometimes sending buffers too late to wasapisink. Can you attach the output of GST_DEBUG=wasapi*:4 here? Do you pass any options to wasapisink like low-latency=true? Do you set a higher thread priority for your gstreamer pipeline? The element does that for itself (see: gst_wasapi_util_set_thread_characteristics()), but it can't set that for the rest of the pipeline.
(In reply to Nirbheek Chauhan from comment #1) > This sounds like the pipeline is sometimes sending buffers too late to > wasapisink. Specifically, wasapisink seems to be unable to write out buffers in time, causing underruns.
(In reply to Nirbheek Chauhan from comment #1) > This sounds like the pipeline is sometimes sending buffers too late to > wasapisink. Can you attach the output of GST_DEBUG=wasapi*:4 here? 0:00:00.648601893 4796 5c4c6a8 INFO wasapisink gstwasapisink.c:369:gst_wasapi_sink_get_caps:<wasapisink0> positions are: [ FL FR ] 0:00:00.680755991 4796 5d758d0 INFO wasapisink gstwasapisink.c:311:gst_wasapi_sink_can_audioclient3:<wasapisink0> AudioClient3 not available on this OS 0:00:00.680947332 4796 5d758d0 INFO wasapi gstwasapiutil.c:854:gst_wasapi_util_initialize_audioclient:<wasapisink0> wasapi default period: 101587, min period: 30000 0:00:00.702882230 4796 5d758d0 INFO wasapisink gstwasapisink.c:501:gst_wasapi_sink_prepare:<wasapisink0> buffer size is 8820 frames, device period is 447 frames, bpf is 8 bytes, rate is 44100 Hz 0:00:00.702945133 4796 5d758d0 INFO wasapisink gstwasapisink.c:510:gst_wasapi_sink_prepare:<wasapisink0> segsize is 3576, segtotal is 19 0:00:00.703034367 4796 5d758d0 INFO wasapisink gstwasapisink.c:517:gst_wasapi_sink_prepare:<wasapisink0> wasapi stream latency: 116100 (11ms) 0:00:00.703106925 4796 5d758d0 INFO wasapisink gstwasapisink.c:529:gst_wasapi_sink_prepare:<wasapisink0> got render client 0:00:10.831675628 4796 5b93ee0 INFO wasapisink gstwasapisink.c:681:gst_wasapi_sink_reset:<wasapisink0> reset called > Do you pass any options to wasapisink like low-latency=true? no > Do you set a higher thread priority for your gstreamer pipeline? The element > does that for itself (see: gst_wasapi_util_set_thread_characteristics()), > but it can't set that for the rest of the pipeline. no
When I set low-latency=true things deadlock and I have to kill it.
Another, maybe unrelated, finding: GST_DEBUG=wasapi*:5 gst-launch-1.0 -v audiotestsrc ! wasapisink low-latency=true starts to have lots of noise after some seconds: It starts printing: gst_wasapi_sink_get_can_frames:<wasapisink0> 448 unread frames (padding) then that value goes down to 0 slowly and then the noise starts: gst_wasapi_sink_get_can_frames:<wasapisink0> 0 unread frames (padding)
ok, my reported problem is the same thing, the buffer gets filled upfront and then gets slowly emptied. seeking resets and clears the buffer completely. I'll try to debug/hack this more some other time. Maybe my gst-launch-1.0 example from above is reproducible on other machines if someone else wants to :)
(In reply to Christoph Reiter (lazka) from comment #3) > 0:00:00.680947332 4796 5d758d0 INFO wasapi > gstwasapiutil.c:854:gst_wasapi_util_initialize_audioclient:<wasapisink0> > wasapi default period: 101587, min period: 30000 > 0:00:00.702882230 4796 5d758d0 INFO wasapisink > gstwasapisink.c:501:gst_wasapi_sink_prepare:<wasapisink0> buffer size is > 8820 frames, device period is 447 frames, bpf is 8 bytes, rate is 44100 Hz > 0:00:00.702945133 4796 5d758d0 INFO wasapisink > gstwasapisink.c:510:gst_wasapi_sink_prepare:<wasapisink0> segsize is 3576, > segtotal is 19 Okay, so the configured buffer size is quite large, and there should be more than enough time for the plugin to deliver buffers to the OS and for the OS to pass it on to the sound card. Can you try playing something with Audacity with the WASAPI backend and see if that works fine or also crackles? (In reply to Christoph Reiter (lazka) from comment #6) > Maybe my gst-launch-1.0 example from above is reproducible on other machines > if someone else wants to :) I tested that gst-launch example (with and without low-latency=true) on Windows 7 (VM), 8.1, and 10 (VM and real). It worked perfectly. I was able to get crackling/noise on Windows 7 with low-latency=true if I reduced the number of CPUs available to just 1, but I figured that was because of insufficient CPU availability.
> Can you try playing something with Audacity with the WASAPI backend and see if that works fine or also crackles? Audacity+WASAPI works fine.
So the problem seems to be that in write() we WaitForSingleObject() every time for a new buffer which returns after is has space for 448 frames, but we always write 447 frames after that, slowly starving it. What I'm wondering is what the ideal implementation of the write() function is supposed to be. Wouldn't it be better to only sleep when we can't fit our data into the buffer?
Tested the gst-launch example on Windows 10 with a MSYS2/MinGW64 build and don't get crackling (with and without low-latency=true). But I _sometimes_ get some WARNING/CRITICAL: $ gst-launch-1.0 audiotestsrc ! wasapisink Setting pipeline to PAUSED ... Pipeline is PREROLLING ... ** (gst-launch-1.0:11060): WARNING **: 21:38:25.279: Invalid channel positions ** (gst-launch-1.0:11060): WARNING **: 21:38:25.279: Invalid channel positions ** (gst-launch-1.0:11060): CRITICAL **: 21:38:25.311: gst_audio_get_channel_reorder_map: assertion 'check_valid_channel_positions (from, channels, FALSE, NULL)' failed ** (gst-launch-1.0:11060): CRITICAL **: 21:38:25.311: file ../../../../gst-plugins-base-1.14.1/gst-libs/gst/audio/gstaudioringbuffer.c: line 2045 (gst_audio_ring_buffer_set_channel_positions): should not be reached Redistribute latency... Pipeline is PREROLLED ... Setting pipeline to PLAYING ... New clock: GstAudioSinkClock
Created attachment 372370 [details] [review] wasapisink: fix missing unlock in case IAudioClient_Start fails something I've noticed along the way
Created attachment 372371 [details] [review] wasapisink: Don't wait for a new buffer if the existing one will do In case the wasapi buffer size was larger than the data we wanted to write out we would always wait for X new buffer and then fill it with <X data, slowly starving the wasapi buffer without a way to recover. Instead skip waiting for a new buffer if the existing one will do and even if after waiting we can't write everything, at least write what we have. Also don't loop until all data is written since the base class can handle that for us and under normal circumstances this doesn't happen anyway. This fixes noisy (buffer underrun) playback with the wasapisink.
Looks like patch 2 (don't wait) contains patch 1 (unlock).
(In reply to Philippe Renon from comment #13) > Looks like patch 2 (don't wait) contains patch 1 (unlock). Yes, patch 2 depends on patch 1 :)
ok, this needs more work, exclusive mode requires that you wait for the event first.
Created attachment 372377 [details] [review] wasapisink: fix a rounding error when calculating the buffer frame count The calculation for the frame count in the non-aligned case resulted in a one too low buffer frame count. This resulted in: 1) exclusive mode not working as the frame count has to match exactly there. 2) Buffer underruns in shared mode as the current write() code doesn't handle catching up to low buffer levels (fixed in the next commit) To fix just use the wasapi API to get the buffer size which will always be correct.
Created attachment 372378 [details] [review] wasapisink: recover from low buffer levels in shared mode In case the wasapi buffer levels got low in shared mode we would still wait until more buffer is available until writing something in it, which means we could never catch up and recover. Instead skip waiting for a new buffer if the existing one will do and even if after waiting we can't write everything, at least write what we have. Also don't loop until all data is written since the base class can handle that for us and under normal circumstances this doesn't happen anyway. This only works in shared mode, as in exclusive mode we have to exactly fill the buffer and always have to wait first. This fixes noisy (buffer underrun) playback with the wasapisink under load.
Now all combinations of low-latency/exclusive work here. The problem fixed by the second patch is likely why only I was having problems.
Review of attachment 372370 [details] [review]: nice catch
Review of attachment 372377 [details] [review]: Makes sense.
Review of attachment 372378 [details] [review]: ::: sys/wasapi/gstwasapisink.c @@ +647,2 @@ + if (have_frames > can_frames) { + dwWaitResult = WaitForSingleObject (self->event_handle, INFINITE); What happens if we only wait if there's no available space at all, and just write out whatever we can otherwise?
Created attachment 372388 [details] [review] wasapisink: recover from low buffer levels in shared mode
(In reply to Nirbheek Chauhan from comment #21) > Review of attachment 372378 [details] [review] [review]: > > ::: sys/wasapi/gstwasapisink.c > @@ +647,2 @@ > + if (have_frames > can_frames) { > + dwWaitResult = WaitForSingleObject (self->event_handle, INFINITE); > > What happens if we only wait if there's no available space at all, and just > write out whatever we can otherwise? Sounds good to me.
Review of attachment 372388 [details] [review]: lgtm, which platforms have you tested this on? If we get it tested on Windows 8.1 and 10 I'll be happier pushing it to the stable branch too. If you don't have access to those, I'll do it on Tuesday (at a conference right now).
All pushed to master, first two pushed to stable, last will be pushed to stable after more testing. Attachment 372388 [details] pushed as 3b1c7ef - wasapisink: recover from low buffer levels in shared mode
Should any of these be backported into the 1.14 branch?
(In reply to Tim-Philipp Müller from comment #26) > Should any of these be backported into the 1.14 branch? That's what I mean by "stable" above. I've pushed the first two there. Will push the third after more testing.
(In reply to Nirbheek Chauhan from comment #24) > Review of attachment 372388 [details] [review] [review]: > > lgtm, which platforms have you tested this on? If we get it tested on > Windows 8.1 and 10 I'll be happier pushing it to the stable branch too. If > you don't have access to those, I'll do it on Tuesday (at a conference right > now). I've only tested on Win7 and don't have easy access to anything else right now.
I've tested it a bit in an ooooold win10 vm, shared works, but low-latency and exclusive give garbage. Might be due to the VM, so not sure.
Tested 1.14.1 (with and without the 4 wasapi patches) on Windows 10 (native) built with MSYS2/MinGW64. gst-launch-1.0.exe audiotestsrc ! wasapisink low-latency=false exclusive=false plain : OK patched : KO! (there is beating and crackling) gst-launch-1.0.exe audiotestsrc ! wasapisink low-latency=true exclusive=false plain : OK patched : OK gst-launch-1.0.exe audiotestsrc ! wasapisink low-latency=false exclusive=true plain : OK patched : OK gst-launch-1.0.exe audiotestsrc ! wasapisink low-latency=true exclusive=true plain : KO! patched : KO! (there is droning... i.e. not same problem as false/false).
:( thanks for testing
More testing with the 5th patch (available on master only) shows that use case 1 (false/false) works, but use case 4 (true/true) is still broken.
With 5th patch, use case 2 (true/false) is also broken. gst-launch-1.0.exe audiotestsrc ! wasapisink low-latency=false exclusive=false plain : OK 4 patch : KO! (there is beating and crackling) 5 patch : OK gst-launch-1.0.exe audiotestsrc ! wasapisink low-latency=true exclusive=false plain : OK 4 patch : OK 5 patch : KO! gst-launch-1.0.exe audiotestsrc ! wasapisink low-latency=false exclusive=true plain : OK 4 patch : OK 5 patch : OK gst-launch-1.0.exe audiotestsrc ! wasapisink low-latency=true exclusive=true plain : KO! 4 patch : KO! (there is droning... i.e. not same problem as false/false). 5 patch : KO! (same as above).
What's the output in the error cases with "GST_DEBUG=wasapi*:5"?
Created attachment 372419 [details] GST_DEBUG=wasapi*:5;gst-launch-1.0.exe audiotestsrc ! wasapisink low-latency=true exclusive=false 2> log1.txt Log of below command (with all 5 patches) attached as log1.txt: GST_DEBUG=wasapi*:5;gst-launch-1.0.exe audiotestsrc ! wasapisink low-latency=true exclusive=false 2> log1.txt Strange thing is that with wasapi debug option there is almost no crackling (just a bit of crackling when starting the pipeline but none after).
Thanks, so compared to win7 the sink sets the buffer size to something larger than the device buffer size. I'll try to do the same for the win7 case to see if I can reproduce.
ok, two problems: * my rounding error fix is wrong, that should have only been used in the exclusive case. * re win10 crackling, audioclient3 completely ignores the buffer spec, so afaics it's no wonder it has a hard time keeping up with 2 segments instead of 20 which I get by default with audioclient1.
I confirm that on win10 (native), disabling audioclient3 improves things. This pipeline works: gst-launch-1.0.exe audiotestsrc ! wasapisink low-latency=true exclusive=false use-audioclient3=false while this one does not: gst-launch-1.0.exe audiotestsrc ! wasapisink low-latency=true exclusive=false
Created attachment 372428 [details] [review] wasapisink: fix segment size in shared mode (regression from previous fix) In commit fd806628a8 I changed the segment size to match exactly the buffer size. I missed that this is only valid in exclusive mode and in shared mode the buffer size is a multiple of the device period. Revert the logic for the shared mode.
Created attachment 372429 [details] [review] wasapisink: disable audioclient3 by default audioclient3 ignores the buffer-time/latency-time of the baseaudiosink and the default buffer size is way less then what we get with audioclient1 (8 times less by default). As this makes it prone to buffer underruns and can lead to confusion when things work on win7 and don't on win10 disable it by default.
Created attachment 372432 [details] gst-launch-1.0.exe audiotestsrc ! wasapisink low-latency=true exclusive=true 2> log2.txt With the last two patches, all uses cases work except the last one (low-latency=true exclusive=true). See attached log2.txt.
Created attachment 372433 [details] GST_DEBUG=wasapi*:5;gst-launch-1.0.exe audiotestsrc ! wasapisink low-latency=true exclusive=true 2> log2.txt Attached proper log.
Comment on attachment 372429 [details] [review] wasapisink: disable audioclient3 by default I just saw that it's disable anyway for non-low latency, oops.
Created attachment 372434 [details] GST_DEBUG=wasapi*:5;gst-launch-1.0.exe audiotestsrc ! wasapisink low-latency=true exclusive=true 2> log2.txt again...
(In reply to Philippe Renon from comment #41) > Created attachment 372432 [details] > gst-launch-1.0.exe audiotestsrc ! wasapisink low-latency=true exclusive=true > 2> log2.txt > > With the last two patches, all uses cases work except the last one > (low-latency=true exclusive=true). See attached log2.txt. Yeah, I don't really know how this is supposed to work. Some questions I've had * What's the advantage of using audioclient3? * If we want to use audioclient3 do we need an extra buffer in the element so we can respect buffer-time and latency-time? * Do we need an extra buffer for exclusive mode? * Why is there a low-latency mode instead of just setting buffer-time/latency-time?
Comment on attachment 372428 [details] [review] wasapisink: fix segment size in shared mode (regression from previous fix) Patch looks good to me, and I've tested it too. Pushed to 1.14 branch and master.
(In reply to Christoph Reiter (lazka) from comment #45) > (In reply to Philippe Renon from comment #41) > > Created attachment 372432 [details] > > gst-launch-1.0.exe audiotestsrc ! wasapisink low-latency=true exclusive=true > > 2> log2.txt > > > > With the last two patches, all uses cases work except the last one > > (low-latency=true exclusive=true). See attached log2.txt. > > Yeah, I don't really know how this is supposed to work. Some questions I've > had > > * What's the advantage of using audioclient3? The latency is much lower, and currently we only enable audioclient3 when low-latency is TRUE. > * If we want to use audioclient3 do we need an extra buffer in the element > so we can respect buffer-time and latency-time? > * Do we need an extra buffer for exclusive mode? We already have our own audio ringbuffer in all cases, so we already have an extra buffer, I am not sure what you mean by this? > * Why is there a low-latency mode instead of just setting > buffer-time/latency-time? Because it is impossible for the user to know which values of buffer-time/latency-time will yield the lowest possible safe values in the audio interface, only we can know by querying the AudioClient3 API; specifically see low_latency conditionals in gst_wasapi_util_initialize_audioclient(). audioclient3 should always be safe to enable on Windows 10, because if the underlying driver doesn't support the low device periods that it enables, we will stick with the 10ms period that we get with audioclient. (In reply to Philippe Renon from comment #35) > Created attachment 372419 [details] > GST_DEBUG=wasapi*:5;gst-launch-1.0.exe audiotestsrc ! wasapisink > low-latency=true exclusive=false 2> log1.txt > > Log of below command (with all 5 patches) attached as log1.txt: > > GST_DEBUG=wasapi*:5;gst-launch-1.0.exe audiotestsrc ! wasapisink > low-latency=true exclusive=false 2> log1.txt > > Strange thing is that with wasapi debug option there is almost no crackling > (just a bit of crackling when starting the pipeline but none after). In these logs, the device period is 480 frames, which is 10ms at 48KHz, and that's what we'd get without audioclient3 too. We need to figure out why the crackling is happening. (In reply to Philippe Renon from comment #44) > Created attachment 372434 [details] > GST_DEBUG=wasapi*:5;gst-launch-1.0.exe audiotestsrc ! wasapisink > low-latency=true exclusive=true 2> log2.txt > > again... What device is this? The device period is 144 frames, which is 3ms, and that's not achievable without audioclient3 at all, afaik. Can you paste the wasapi*:4 log with audioclient3 disabled? And then the same with exclusive=false?
(In reply to Nirbheek Chauhan from comment #47) > What device is this? The device period is 144 frames, which is 3ms, and > that's not achievable without audioclient3 at all, afaik. Can you paste the > wasapi*:4 log with audioclient3 disabled? > > And then the same with exclusive=false? Ah, nvm, this is exclusive mode and you can get very low latencies with it in all wasapi API versions. Audioclient3 is not used for exclusive mode at all. It only makes sense in the AudioClient3 API for shared mode. What's the audio issue that you're seeing in this log?
-- GitLab Migration Automatic Message -- This bug has been migrated to freedesktop.org's GitLab instance and has been closed from further activity. You can subscribe and participate further through the new bug through this link to our GitLab instance: https://gitlab.freedesktop.org/gstreamer/gst-plugins-bad/issues/714.