Audio dropouts that disappear when queue2 logging is enabled
Carlos Rafael Giani
dv at pseudoterminal.org
Sat Sep 3 15:17:43 UTC 2016
How is the pipeline behavior with this? gst-launch-1.0 uridecodebin
uri="http://10.0.1.120:50002/m/NDLNA/396487.flac" buffer-size=4000000
buffer-duration=0 ! audioconvert ! audioresample ! autoaudiosink
On 2016-09-03 11:53, Jonathan Miles wrote:
>
> Thanks for your help.
>
>
> Here's the pipeline image: http://imgur.com/a/WV5DF
>
> For the sake of completeness, here's the the drop-out
> (PLAYING->PAUSED): http://imgur.com/a/dBnhq
>
> And restart (PAUSED->PLAYING): http://imgur.com/a/IqMoU
>
>
> Assuming I'm looking at the right part of uridecodebin, here's the
> queue size set-up:
>
>
> 0:00:03.801279251 786 0x28af50 DEBUG uridecodebin
> gsturidecodebin.c:1110:decoded_pad_event_probe:<decodebin0:src_0>
> found bitrate 0
> 0:00:03.892754459 786 0x28af50 DEBUG uridecodebin
> gsturidecodebin.c:1110:decoded_pad_event_probe:<decodebin0:src_0>
> found bitrate 1411429
> 0:00:03.899845626 786 0x28af50 DEBUG uridecodebin
> gsturidecodebin.c:1065:configure_stream_buffering:<uridecodebin0>
> overall bitrate 1411429
> 0:00:03.915355626 786 0x28af50 DEBUG uridecodebin
> gsturidecodebin.c:1077:configure_stream_buffering:<uridecodebin0>
> queue buffering time 0:00:02.000000000
> 0:00:03.917613084 786 0x28af50 DEBUG uridecodebin
> gsturidecodebin.c:1080:configure_stream_buffering:<uridecodebin0>
> corresponds to buffer size 352857
> ------------------------------------------------------------------------
> *From:* gstreamer-devel
> <gstreamer-devel-bounces at lists.freedesktop.org> on behalf of Carlos
> Rafael Giani <dv at pseudoterminal.org>
> *Sent:* 02 September 2016 19:29:58
> *To:* gstreamer-devel at lists.freedesktop.org
> *Subject:* Re: Audio dropouts that disappear when queue2 logging is
> enabled
> Can you also produce a dot dump? Just run the gst-launch line with the
> GST_DEBUG_DUMP_DOT_DIR environment variable set to "." or "/tmp/". In
> that directory, GStreamer will then generate a bunch of .dot files.
> Pick the one with "PAUSED_PLAYING" in its filename, convert it to PNG
> with the dot tool (dot -Tpng -o dot-dump.png <filename.dot>), and put
> it on Imgur.
>
> It is possible that the maximum internal queue2 size is too small.
> I've had this problem with FLAC before. The two most common reasons
> for this (which I've observed) were: (1) queue2 figured out a size
> that is too low because it looked at the incoming data rate, which
> just happened to be low at this moment (2) uridecodebin got a bogus
> bitrate from the FLAC parser that is way too low (can happen with
> FLACs that start with silence), so it calculates a small size based on
> that.
>
> On 2016-09-02 17:05, Jonathan Miles wrote:
>> Here's the info from the identity element:
>>
>> /GstPipeline:pipeline0/GstIdentity:identity0: last-message = chain
>> ******* (identity0:sink) (18432 bytes, dts: none, pts:
>> 0:00:51.408979591, duration: 0:00:00.104489796, offset: -1,
>> offset_end: -1, flags: 00000000 ) 0xb4180df8
>> /GstPipeline:pipeline0/GstIdentity:identity0: last-message = chain
>> ******* (identity0:sink) (18432 bytes, dts: none, pts:
>> 0:00:51.513469387, duration: 0:00:00.104489796, offset: -1,
>> offset_end: -1, flags: 00000000 ) 0xb4f2ec10
>> Buffering, setting pipeline to PAUSED ...
>> Done buffering, setting pipeline to PLAYING ...
>> /GstPipeline:pipeline0/GstIdentity:identity0: last-message = chain
>> ******* (identity0:sink) (18432 bytes, dts: none, pts:
>> 0:00:51.617959183, duration: 0:00:00.104489796, offset: -1,
>> offset_end: -1, flags: 00000000 ) 0xb4f12200
>> /GstPipeline:pipeline0/GstIdentity:identity0: last-message = chain
>> ******* (identity0:sink) (18432 bytes, dts: none, pts:
>> 0:00:51.722448979, duration: 0:00:00.104489796, offset: -1,
>> offset_end: -1, flags: 00000000 ) 0xb4f2e990
>> /GstPipeline:pipeline0/GstIdentity:identity0: last-message = chain
>> ******* (identity0:sink) (18432 bytes, dts: none, pts:
>> 0:00:51.826938775, duration: 0:00:00.104489796, offset: -1,
>> offset_end: -1, flags: 00000000 ) 0xb43d18f0
>>
>> ------------------------------------------------------------------------
>> *From:* gstreamer-devel
>> <gstreamer-devel-bounces at lists.freedesktop.org> on behalf of Carlos
>> Rafael Giani <dv at pseudoterminal.org>
>> *Sent:* 02 September 2016 15:55:25
>> *To:* gstreamer-devel at lists.freedesktop.org
>> *Subject:* Re: Audio dropouts that disappear when queue2 logging is
>> enabled
>>
>> It is possible that downstream consumes the entire buffered data in
>> one go. Try this:
>>
>>
>> gst-launch-1.0 -v uridecodebin
>> uri="http://10.0.1.120:50002/m/NDLNA/396487.flac" ! identity
>> silent=false ! audioconvert ! audioresample ! autoaudiosink
>>
>>
>> Then you'll get lines from the identity element which tell you about
>> the size of the passing buffers. Paste a few of those lines here.
>>
>>
>>
>> On 2016-09-02 16:39, Jonathan Miles wrote:
>>>
>>> Tweaking the logging, I'm seeing the following dance between queue2
>>> and souphttpsrc:
>>>
>>>
>>> Done buffering, setting pipeline to PLAYING ...
>>> 0:00:20.721441002 3095 0x286150 INFO queue2
>>> gstqueue2.c:2447:gst_queue2_locked_dequeue:<queue2-0> cur_level.bytes=0
>>> 0:00:20.721910210 3095 0x286150 INFO queue2
>>> gstqueue2.c:1070:gst_queue2_get_buffering_message:<queue2-0> Going
>>> to post buffering: 0%
>>> 0:00:20.723109877 3095 0x3f6ac0 INFO queue2
>>> gstqueue2.c:2328:gst_queue2_locked_enqueue:<queue2-0>
>>> cur_level.bytes=886192
>>> buffering... 0%
>>> Buffering, setting pipeline to PAUSED ...
>>> 0:00:20.731298335 3095 0x3f6ac0 INFO queue2
>>> gstqueue2.c:1070:gst_queue2_get_buffering_message:<queue2-0> Going
>>> to post buffering: 100%
>>> 0:00:20.795157794 3095 0x3f6ac0 DEBUG souphttpsrc
>>> gstsouphttpsrc.c:1640:gst_soup_http_src_read_buffer:<source> Read
>>> 947616 bytes from http input
>>> 0:00:20.797286460 3095 0x3f6ac0 DEBUG souphttpsrc
>>> gstsouphttpsrc.c:1744:gst_soup_http_src_create:<source> Returning 0 ok
>>> buffering... 100%
>>> Done buffering, setting pipeline to PLAYING ...
>>> 0:00:26.157894003 3095 0x286150 INFO queue2
>>> gstqueue2.c:2447:gst_queue2_locked_dequeue:<queue2-0> cur_level.bytes=0
>>> 0:00:26.158368253 3095 0x286150 INFO queue2
>>> gstqueue2.c:1070:gst_queue2_get_buffering_message:<queue2-0> Going
>>> to post buffering: 0%
>>> 0:00:26.159438128 3095 0x3f6ac0 INFO queue2
>>> gstqueue2.c:2328:gst_queue2_locked_enqueue:<queue2-0>
>>> cur_level.bytes=947616
>>> buffering... 0%
>>> Buffering, setting pipeline to PAUSED ...
>>> 0:00:26.165946669 3095 0x3f6ac0 INFO queue2
>>> gstqueue2.c:1070:gst_queue2_get_buffering_message:<queue2-0> Going
>>> to post buffering: 100%
>>> 0:00:26.230684461 3095 0x3f6ac0 DEBUG souphttpsrc
>>> gstsouphttpsrc.c:1640:gst_soup_http_src_read_buffer:<source> Read
>>> 947896 bytes from http input
>>> 0:00:26.232809503 3095 0x3f6ac0 DEBUG souphttpsrc
>>> gstsouphttpsrc.c:1744:gst_soup_http_src_create:<source> Returning 0 ok
>>> buffering... 100%
>>> Done buffering, setting pipeline to PLAYING ...
>>>
>>>
>>> It looks like queue2 is sending the "buffering 0%" message before
>>> souphttpsrc has had a chance to re-fill the queue.
>>>
>>>
>>> Some more info on my set-up
>>>
>>>
>>> - Building from git master
>>>
>>> - Crossed compiled for ARM
>>>
>>> - Running on an ARM AM335x (like a Beagle Bone)
>>>
>>> - Linux 3.8.11 - no kernel pre-emption enabled
>>>
>>> ------------------------------------------------------------------------
>>> *From:* gstreamer-devel
>>> <gstreamer-devel-bounces at lists.freedesktop.org> on behalf of
>>> Jonathan Miles <jonathan.miles at cambridgeaudio.com>
>>> *Sent:* 02 September 2016 11:57:55
>>> *To:* gstreamer-devel at lists.freedesktop.org
>>> *Subject:* Audio dropouts that disappear when queue2 logging is enabled
>>> While playing a FLAC file from a Synology NAS, I'm getting audio
>>> dropouts as a result of re-buffering:
>>>
>>> ~ # gst-launch-1.0 playbin
>>> uri="http://10.0.1.120:50002/m/NDLNA/396487.flac"
>>> Setting pipeline to PAUSED ...
>>> Pipeline is PREROLLING ...
>>> WARNING: from element /GstPlayBin:playbin0/GstPlaySink:playsink: No
>>> volume control found
>>> Additional debug info:
>>> /home/jonathanm/build/v010-a/build-glibc-glibc/work/armv7a-vfp-neon-oe-linux-gnueabi/gstreamer1.0-plugins-base/git-r0/git/gst/playback/gstplaysink.c(2857):
>>> gen_audio_chain (): /GstPlayBin:playbin0/GstPlaySink:playsink:
>>> Volume/mute is not available
>>> Redistribute latency...
>>> Pipeline is PREROLLED ...
>>> Setting pipeline to PLAYING ...
>>> New clock: GstAudioSinkClock
>>> Buffering, setting pipeline to PAUSED ...
>>> Done buffering, setting pipeline to PLAYING ...
>>> Buffering, setting pipeline to PAUSED ...
>>> Done buffering, setting pipeline to PLAYING ...
>>>
>>> If I enable queue2 debugging (GST_DEBUG="queue2:5"), the audio
>>> drop-outs disappear, as the pipeline doesn't get set to PAUSED,
>>> although it looks like the rebuffering is still happening:
>>>
>>> 0:00:32.967181462 1648 0x2cfb50 DEBUG queue2
>>> gstqueue2.c:842:apply_buffer:<queue2-0> position updated to
>>> 0:00:00.000000000
>>> 0:00:32.967705879 1648 0x2cfb50 DEBUG queue2
>>> gstqueue2.c:740:update_time_level:<queue2-0> sink 0:00:00.000000000,
>>> src 0:00:00.000000000
>>> 0:00:32.968154921 1648 0x2cfb50 DEBUG queue2
>>> gstqueue2.c:1221:update_out_rates:<queue2-0> rates: period 5.950074,
>>> out 1048576
>>> 0:00:32.968559296 1648 0x2cfb50 DEBUG queue2
>>> gstqueue2.c:1239:update_out_rates:<queue2-0> rates: out
>>> 266973.567011, time 0:00:00.000000000
>>> 0:00:32.969009754 1648 0x2cfb50 DEBUG queue2
>>> gstqueue2.c:1199:update_in_rates:<queue2-0> rates: in
>>> 1361330.412743, time 0:00:00.000000000
>>> 0:00:32.969451212 1648 0x2cfb50 DEBUG queue2
>>> gstqueue2.c:1004:get_buffering_level:<queue2-0> buffering 0, level 0
>>> 0:00:32.969777004 1648 0x2cfb50 DEBUG queue2
>>> gstqueue2.c:1122:update_buffering:<queue2-0> buffering 0 percent
>>> 0:00:32.972558504 1648 0x4408c0 DEBUG queue2
>>> gstqueue2.c:842:apply_buffer:<queue2-0> position updated to
>>> 0:00:00.000000000
>>> 0:00:32.973054296 1648 0x4408c0 DEBUG queue2
>>> gstqueue2.c:740:update_time_level:<queue2-0> sink 0:00:00.000000000,
>>> src 0:00:00.000000000
>>> 0:00:32.973499504 1648 0x4408c0 DEBUG queue2
>>> gstqueue2.c:1199:update_in_rates:<queue2-0> rates: in
>>> 1361330.412743, time 0:00:00.779502162
>>> 0:00:32.973981379 1648 0x4408c0 DEBUG queue2
>>> gstqueue2.c:1199:update_in_rates:<queue2-0> rates: in
>>> 1361330.412743, time 0:00:00.779502162
>>> 0:00:32.974428254 1648 0x4408c0 DEBUG queue2
>>> gstqueue2.c:1004:get_buffering_level:<queue2-0> buffering 1, level
>>> 1000000
>>> 0:00:32.974764921 1648 0x4408c0 DEBUG queue2
>>> gstqueue2.c:1116:update_buffering:<queue2-0> buffering 100 percent
>>> 0:00:32.975315546 1648 0x4408c0 DEBUG queue2
>>> gstqueue2.c:1070:gst_queue2_get_buffering_message:<queue2-0> Going
>>> to post buffering: 100%
>>> Done buffering, setting pipeline to PLAYING ...
>>>
>>> Anyone got any ideas as to what might be going here?
>>>
>>> Thanks,
>>>
>>> Jonathan
>>>
>>>
>>> Audio Partnership PLC, Gallery Court, Hankey Place, London SE1 4BB,
>>> UK Reg No. 2953313 This e-mail is confidential and for the addressee
>>> only. Please refer to Disclaimer
>>> <https://www.cambridgeaudio.com/disclaimer> for important notices.
>>>
>>>
>>> Audio Partnership PLC, Gallery Court, Hankey Place, London SE1 4BB,
>>> UK Reg No. 2953313 This e-mail is confidential and for the addressee
>>> only. Please refer to Disclaimer
>>> <https://www.cambridgeaudio.com/disclaimer> for important notices.
>>>
>>>
>>> _______________________________________________
>>> gstreamer-devel mailing list
>>> gstreamer-devel at lists.freedesktop.org
>>> https://lists.freedesktop.org/mailman/listinfo/gstreamer-devel
>>
>>
>>
>> Audio Partnership PLC, Gallery Court, Hankey Place, London SE1 4BB,
>> UK Reg No. 2953313 This e-mail is confidential and for the addressee
>> only. Please refer to Disclaimer
>> <https://www.cambridgeaudio.com/disclaimer> for important notices.
>>
>>
>> _______________________________________________
>> gstreamer-devel mailing list
>> gstreamer-devel at lists.freedesktop.org
>> https://lists.freedesktop.org/mailman/listinfo/gstreamer-devel
>
>
>
> Audio Partnership PLC, Gallery Court, Hankey Place, London SE1 4BB, UK
> Reg No. 2953313 This e-mail is confidential and for the addressee
> only. Please refer to Disclaimer
> <https://www.cambridgeaudio.com/disclaimer> for important notices.
>
>
> _______________________________________________
> gstreamer-devel mailing list
> gstreamer-devel at lists.freedesktop.org
> https://lists.freedesktop.org/mailman/listinfo/gstreamer-devel
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://lists.freedesktop.org/archives/gstreamer-devel/attachments/20160903/5b7bca83/attachment-0001.html>
More information about the gstreamer-devel
mailing list