Audio dropouts that disappear when queue2 logging is enabled

Carlos Rafael Giani dv at pseudoterminal.org
Fri Sep 2 14:55:25 UTC 2016


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

-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://lists.freedesktop.org/archives/gstreamer-devel/attachments/20160902/65aef783/attachment.html>


More information about the gstreamer-devel mailing list