Live Audio Playback from Microphone Going Silent on Windows

Tue Oct 23 00:36:31 UTC 2018

Hi,

I have been recently dealing with audio playback issues in the latest 
versions of gstreamer.  I have been using 1.14.4 on windows 7/10.  It 
seems as though if you use directsoundsink or wasapisink with 
directsoundsrc or wasapisrc audio playback will go silent after a 
certain amount of time.  However in the situations where we are 
recording the audio to a file as well, the audio in the file is fine.

A simple pipeline to reproduce this issue would be something like:

wasapisrc  ! queue ! audioconvert ! audioresample ! wasapisink
(the audioconvert and audioresample are probably superfluous)

The audio will usually play for a few seconds, go silent for about 15-20 
seconds, then play again for another 3 seconds.  It usually repeats this 
process until it will eventually cut out completely.
Running the pipeline with gst-debug="ringbuffer:5" gives log output that 
appears to indicate that the read pointer is getting ahead of the write 
pointer in the ringbuffer (the diff goes negative and the sink stops 
playing the audio).
I do not get this issue with file or network sources of audio.  It is 
more common / severe with wasapisrc over directsoundsrc (it takes much 
longer for directsoundsrc to play nothing)

At this point I am not sure what to try, I am not sure if i just need 
higher values for latency-time and buffer-time, but even with those 
values increased by 10x, I am still losing some audio, which is 
unacceptable for recording / monitoring.
I am not sure if this is a bug or if this is just a misconfiguration on 
my part.  But with such a simple pipeline, and getting the behavior on 
multiple different machines, it seems really weird to be the only one 
getting this behavior.  Any feedback or suggestions on how to debug this 
would be welcome.

This is an excerpt of the ringbuffer:5 log.  In this section the diff 
goes to -20 out of 20 (segtotal):

0:01:57.311782688  6772 0000000003124F00 WARN wasapisrc 
gstwasapisrc.c:597:gst_wasapi_src_read:<wasapisrc0> captured too many 
frames: have 448, want 447
0:01:57.311865096  6772 0000000003124F00 DEBUG ringbuffer 
gstaudioringbuffer.c:2085:gst_audio_ring_buffer_set_timestamp:<audiosrcringbuffer0> 
Storing timestamp 99:99:99.999999999 @ 0
0:01:57.311927580  6772 0000000003124F00 DEBUG ringbuffer 
gstaudioringbuffer.c:1935:gst_audio_ring_buffer_advance:<audiosrcringbuffer0> 
signal waiter
0:01:57.312022062  6772 0000000003124EC0 DEBUG ringbuffer 
gstaudioringbuffer.c:1791:gst_audio_ring_buffer_read:<audiosrcringbuffer0> 
pointer at 11535, sample 5155698, read from 11534-0, to_read 447, diff 
1, segtotal 2, segsize 3576
0:01:57.312107187  6772 0000000003124EC0 DEBUG ringbuffer 
gstaudioringbuffer.c:1816:gst_audio_ring_buffer_read:<audiosrcringbuffer0> 
read @00000000031EC1A0 seg 0, off 0, sampleslen 447
0:01:57.312184463  6772 0000000003124EC0 DEBUG ringbuffer 
gstaudioringbuffer.c:1844:gst_audio_ring_buffer_read:<audiosrcringbuffer0> 
Retrieved timestamp 99:99:99.999999999 @ 0
0:01:57.312264757  6772 0000000003124EC0 DEBUG ringbuffer 
gstaudioringbuffer.c:1791:gst_audio_ring_buffer_read:<audiosrcringbuffer0> 
pointer at 11535, sample 5156145, read from 11535-0, to_read 447, diff 
0, segtotal 2, segsize 3576
0:01:57.312328148  6772 0000000003124EC0 DEBUG ringbuffer 
gstaudioringbuffer.c:1363:wait_segment:<audiosrcringbuffer0> waiting..
0:01:57.312332978  6772 0000000003124E80 DEBUG ringbuffer 
gstaudioringbuffer.c:1554:default_commit:<audiosinkringbuffer0> write 
447 : 447
0:01:57.312550618  6772 0000000003124E80 DEBUG ringbuffer 
gstaudioringbuffer.c:1574:default_commit:<audiosinkringbuffer0> pointer 
at 11731, write to 11712-1652, diff -19, segtotal 20, segsize 1764, base 0
0:01:57.312615518  6772 0000000003124E80 DEBUG ringbuffer 
gstaudioringbuffer.c:1604:default_commit:<audiosinkringbuffer0> write 
@0000000003246B30 seg 12, sps 441, off 1652, avail 112
0:01:57.312676192  6772 0000000003124E80 DEBUG ringbuffer 
gstaudioringbuffer.c:1630:default_commit: copy 112 bytes
0:01:57.312738073  6772 0000000003124E80 DEBUG ringbuffer 
gstaudioringbuffer.c:1574:default_commit:<audiosinkringbuffer0> pointer 
at 11731, write to 11713-0, diff -18, segtotal 20, segsize 1764, base 0
0:01:57.312801765  6772 0000000003124E80 DEBUG ringbuffer 
gstaudioringbuffer.c:1604:default_commit:<audiosinkringbuffer0> write 
@0000000003247214 seg 13, sps 441, off 0, avail 1676
0:01:57.312859420  6772 0000000003124E80 DEBUG ringbuffer 
gstaudioringbuffer.c:1630:default_commit: copy 1676 bytes
0:01:57.321782081  6772 0000000003124F00 WARN wasapisrc 
gstwasapisrc.c:597:gst_wasapi_src_read:<wasapisrc0> captured too many 
frames: have 448, want 447
0:01:57.321878072  6772 0000000003124F00 DEBUG ringbuffer 
gstaudioringbuffer.c:2085:gst_audio_ring_buffer_set_timestamp:<audiosrcringbuffer0> 
Storing timestamp 99:99:99.999999999 @ 1
0:01:57.321941161  6772 0000000003124F00 DEBUG ringbuffer 
gstaudioringbuffer.c:1935:gst_audio_ring_buffer_advance:<audiosrcringbuffer0> 
signal waiter
0:01:57.322038964  6772 0000000003124EC0 DEBUG ringbuffer 
gstaudioringbuffer.c:1791:gst_audio_ring_buffer_read:<audiosrcringbuffer0> 
pointer at 11536, sample 5156145, read from 11535-0, to_read 447, diff 
1, segtotal 2, segsize 3576
0:01:57.322126503  6772 0000000003124EC0 DEBUG ringbuffer 
gstaudioringbuffer.c:1816:gst_audio_ring_buffer_read:<audiosrcringbuffer0> 
read @00000000031ECF98 seg 1, off 0, sampleslen 447
0:01:57.322193515  6772 0000000003124EC0 DEBUG ringbuffer 
gstaudioringbuffer.c:1844:gst_audio_ring_buffer_read:<audiosrcringbuffer0> 
Retrieved timestamp 99:99:99.999999999 @ 1
0:01:57.322278942  6772 0000000003124EC0 DEBUG ringbuffer 
gstaudioringbuffer.c:1791:gst_audio_ring_buffer_read:<audiosrcringbuffer0> 
pointer at 11536, sample 5156592, read from 11536-0, to_read 447, diff 
0, segtotal 2, segsize 3576
0:01:57.322342332  6772 0000000003124EC0 DEBUG ringbuffer 
gstaudioringbuffer.c:1363:wait_segment:<audiosrcringbuffer0> waiting..
0:01:57.322387007  6772 0000000003124E80 DEBUG ringbuffer 
gstaudioringbuffer.c:1554:default_commit:<audiosinkringbuffer0> write 
447 : 447
0:01:57.322505940  6772 0000000003124E80 DEBUG ringbuffer 
gstaudioringbuffer.c:1574:default_commit:<audiosinkringbuffer0> pointer 
at 11732, write to 11713-1676, diff -19, segtotal 20, segsize 1764, base 0
0:01:57.322573556  6772 0000000003124E80 DEBUG ringbuffer 
gstaudioringbuffer.c:1604:default_commit:<audiosinkringbuffer0> write 
@0000000003247214 seg 13, sps 441, off 1676, avail 88
0:01:57.322633023  6772 0000000003124E80 DEBUG ringbuffer 
gstaudioringbuffer.c:1630:default_commit: copy 88 bytes
0:01:57.322711808  6772 0000000003124E80 DEBUG ringbuffer 
gstaudioringbuffer.c:1574:default_commit:<audiosinkringbuffer0> pointer 
at 11732, write to 11714-0, diff -18, segtotal 20, segsize 1764, base 0
0:01:57.322776406  6772 0000000003124E80 DEBUG ringbuffer 
gstaudioringbuffer.c:1604:default_commit:<audiosinkringbuffer0> write 
@00000000032478F8 seg 14, sps 441, off 0, avail 1700
0:01:57.322834363  6772 0000000003124E80 DEBUG ringbuffer 
gstaudioringbuffer.c:1630:default_commit: copy 1700 bytes
0:01:57.331773626  6772 0000000003124F00 WARN wasapisrc 
gstwasapisrc.c:597:gst_wasapi_src_read:<wasapisrc0> captured too many 
frames: have 448, want 447
0:01:57.331856939  6772 0000000003124F00 DEBUG ringbuffer 
gstaudioringbuffer.c:2085:gst_audio_ring_buffer_set_timestamp:<audiosrcringbuffer0> 
Storing timestamp 99:99:99.999999999 @ 0
0:01:57.331928782  6772 0000000003124F00 DEBUG ringbuffer 
gstaudioringbuffer.c:1935:gst_audio_ring_buffer_advance:<audiosrcringbuffer0> 
signal waiter
0:01:57.332030810  6772 0000000003124EC0 DEBUG ringbuffer 
gstaudioringbuffer.c:1791:gst_audio_ring_buffer_read:<audiosrcringbuffer0> 
pointer at 11537, sample 5156592, read from 11536-0, to_read 447, diff 
1, segtotal 2, segsize 3576
0:01:57.332124085  6772 0000000003124EC0 DEBUG ringbuffer 
gstaudioringbuffer.c:1816:gst_audio_ring_buffer_read:<audiosrcringbuffer0> 
read @00000000031EC1A0 seg 0, off 0, sampleslen 447
0:01:57.332192305  6772 0000000003124EC0 DEBUG ringbuffer 
gstaudioringbuffer.c:1844:gst_audio_ring_buffer_read:<audiosrcringbuffer0> 
Retrieved timestamp 99:99:99.999999999 @ 0
0:01:57.332285881  6772 0000000003124EC0 DEBUG ringbuffer 
gstaudioringbuffer.c:1791:gst_audio_ring_buffer_read:<audiosrcringbuffer0> 
pointer at 11537, sample 5157039, read from 11537-0, to_read 447, diff 
0, segtotal 2, segsize 3576
0:01:57.332351083  6772 0000000003124EC0 DEBUG ringbuffer 
gstaudioringbuffer.c:1363:wait_segment:<audiosrcringbuffer0> waiting..
0:01:57.332463978  6772 0000000003124E80 DEBUG ringbuffer 
gstaudioringbuffer.c:1554:default_commit:<audiosinkringbuffer0> write 
447 : 447
0:01:57.332562988  6772 0000000003124E80 DEBUG ringbuffer 
gstaudioringbuffer.c:1574:default_commit:<audiosinkringbuffer0> pointer 
at 11732, write to 11714-1700, diff -18, segtotal 20, segsize 1764, base 0
0:01:57.332628794  6772 0000000003124E80 DEBUG ringbuffer 
gstaudioringbuffer.c:1604:default_commit:<audiosinkringbuffer0> write 
@00000000032478F8 seg 14, sps 441, off 1700, avail 64
0:01:57.332741689  6772 0000000003124E80 DEBUG ringbuffer 
gstaudioringbuffer.c:1630:default_commit: copy 64 bytes
0:01:57.332804778  6772 0000000003124E80 DEBUG ringbuffer 
gstaudioringbuffer.c:1574:default_commit:<audiosinkringbuffer0> pointer 
at 11734, write to 11715-0, diff -19, segtotal 20, segsize 1764, base 0
0:01:57.332869677  6772 0000000003124E80 DEBUG ringbuffer 
gstaudioringbuffer.c:1604:default_commit:<audiosinkringbuffer0> write 
@0000000003247FDC seg 15, sps 441, off 0, avail 1724
0:01:57.333061962  6772 0000000003124E80 DEBUG ringbuffer 
gstaudioringbuffer.c:1630:default_commit: copy 1724 bytes
0:01:57.341805318  6772 0000000003124F00 WARN wasapisrc 
gstwasapisrc.c:597:gst_wasapi_src_read:<wasapisrc0> captured too many 
frames: have 448, want 447
0:01:57.341897084  6772 0000000003124F00 DEBUG ringbuffer 
gstaudioringbuffer.c:2085:gst_audio_ring_buffer_set_timestamp:<audiosrcringbuffer0> 
Storing timestamp 99:99:99.999999999 @ 1
0:01:57.341959267  6772 0000000003124F00 DEBUG ringbuffer 
gstaudioringbuffer.c:1935:gst_audio_ring_buffer_advance:<audiosrcringbuffer0> 
signal waiter
0:01:57.342057975  6772 0000000003124EC0 DEBUG ringbuffer 
gstaudioringbuffer.c:1791:gst_audio_ring_buffer_read:<audiosrcringbuffer0> 
pointer at 11538, sample 5157039, read from 11537-0, to_read 447, diff 
1, segtotal 2, segsize 3576
0:01:57.342156984  6772 0000000003124EC0 DEBUG ringbuffer 
gstaudioringbuffer.c:1816:gst_audio_ring_buffer_read:<audiosrcringbuffer0> 
read @00000000031ECF98 seg 1, off 0, sampleslen 447
0:01:57.342233355  6772 0000000003124EC0 DEBUG ringbuffer 
gstaudioringbuffer.c:1844:gst_audio_ring_buffer_read:<audiosrcringbuffer0> 
Retrieved timestamp 99:99:99.999999999 @ 1
0:01:57.342326931  6772 0000000003124EC0 DEBUG ringbuffer 
gstaudioringbuffer.c:1791:gst_audio_ring_buffer_read:<audiosrcringbuffer0> 
pointer at 11538, sample 5157486, read from 11538-0, to_read 447, diff 
0, segtotal 2, segsize 3576
0:01:57.342390925  6772 0000000003124EC0 DEBUG ringbuffer 
gstaudioringbuffer.c:1363:wait_segment:<audiosrcringbuffer0> waiting..
0:01:57.342413565  6772 0000000003124E80 WARN audiobasesink 
gstaudiobasesink.c:1463:gst_audio_base_sink_skew_slaving:<directsoundsink0> 
correct clock skew +0:00:00.022705801 > +0:00:00.020000000
0:01:57.342604642  6772 0000000003124E80 DEBUG ringbuffer 
gstaudioringbuffer.c:1554:default_commit:<audiosinkringbuffer0> write 
447 : 447
0:01:57.342724782  6772 0000000003124E80 DEBUG ringbuffer 
gstaudioringbuffer.c:1574:default_commit:<audiosinkringbuffer0> pointer 
at 11735, write to 11715-1724, diff -20, segtotal 20, segsize 1764, base 0
0:01:57.342790889  6772 0000000003124E80 DEBUG ringbuffer 
gstaudioringbuffer.c:1604:default_commit:<audiosinkringbuffer0> write 
@0000000003247FDC seg 15, sps 441, off 1724, avail 40
0:01:57.342850054  6772 0000000003124E80 DEBUG ringbuffer 
gstaudioringbuffer.c:1630:default_commit: copy 40 bytes
0:01:57.342912538  6772 0000000003124E80 DEBUG ringbuffer 
gstaudioringbuffer.c:1574:default_commit:<audiosinkringbuffer0> pointer 
at 11735, write to 11716-0, diff -19, segtotal 20, segsize 1764, base 0
0:01:57.342977136  6772 0000000003124E80 DEBUG ringbuffer 
gstaudioringbuffer.c:1604:default_commit:<audiosinkringbuffer0> write 
@00000000032486C0 seg 16, sps 441, off 0, avail 1748
0:01:57.343035093  6772 0000000003124E80 DEBUG ringbuffer 
gstaudioringbuffer.c:1630:default_commit: copy 1748 bytes
0:01:57.351786600  6772 0000000003124F00 WARN wasapisrc 
gstwasapisrc.c:597:gst_wasapi_src_read:<wasapisrc0> captured too many 
frames: have 448, want 447

--
This message has been scanned by E.F.A. Project and is believed to be clean.