2520 replies to this topic

[mx3L]

Hi,

 

Just found out that every raw audio is played by dvbaudiosink with enabled synchronization!

 

When decodebin tries to create decode chain for example for wav audio, it will not find dvbaudiosink as last element of chain, but it finds wavparse element, since it provides raw caps on src pad and decode chain is then finished:

GST_DEBUG_FILE=/tmp/waw_autoaudiosink_sync_true.log GST_DEBUG_NO_COLOR=1 GST_DEBUG=decodebin:6,autodetect:6,playbin:6,playsink:6,dvbaudiosink:5,basesink:6 gst-launch-1.0 playbin uri=file:///media/net/DOMA/Test/24bit_44kHz_
Brake5.wav

0:00:01.647201037  1888 0x763335b0 DEBUG              decodebin gstdecodebin2.c:2834:pad_added_cb:<wavparse0:src> pad added, chain:0x4fe9b0
0:00:01.647676481  1888 0x763335b0 DEBUG              decodebin gstdecodebin2.c:1499:analyze_new_pad:<decodebin0> Pad wavparse0:src caps:audio/x-raw, format=(string)S24LE, layout=(string)interleaved, channels=(int)2, channel-mask=(bitma
sk)0x0000000000000003, rate=(int)44100
0:00:01.659665999  1888 0x763335b0 DEBUG                playbin gstplaybin2.c:4490:autoplug_continue_cb:<playbin0> continue autoplugging group 0x4f9f20 for '':decodepad0, audio/x-raw, format=(string)S24LE, layout=(string)interleaved, ch
annels=(int)2, channel-mask=(bitmask)0x0000000000000003, rate=(int)44100: 1
0:00:01.660832777  1888 0x763335b0 DEBUG              decodebin gstdecodebin2.c:1351:gst_decode_bin_autoplug_continue:<decodebin0> autoplug-continue returns TRUE
0:00:01.661163999  1888 0x763335b0 LOG                decodebin gstdecodebin2.c:3042:are_final_caps:<decodebin0> Checking with caps audio/x-raw, format=(string)S24LE, layout=(string)interleaved, channels=(int)2, channel-mask=(bitmask)0x
0000000000000003, rate=(int)44100
0:00:01.661902703  1888 0x763335b0 LOG                decodebin gstdecodebin2.c:3049:are_final_caps:<decodebin0> Caps are final caps
0:00:01.662169259  1888 0x763335b0 LOG                decodebin gstdecodebin2.c:1791:analyze_new_pad:<decodebin0> Pad is final. autoplug-continue:1

If that happens then playsink is used for creation of sink element, which creates dvbaudiosink by using autoaudiosink, which sets sync setting to TRUE for dvbaudiosink after we initially set it to FALSE in NULL state:

0:00:01.720812074  1888 0x763335b0 DEBUG               playsink gstplaysink.c:3259:gst_play_sink_do_reconfigure:<playsink> audio:1, video:0, vis:0, text:0
0:00:01.721144925  1888 0x763335b0 DEBUG               playsink gstplaysink.c:3393:gst_play_sink_do_reconfigure:<playsink> no video needed
0:00:01.721435740  1888 0x763335b0 DEBUG               playsink gstplaysink.c:3460:gst_play_sink_do_reconfigure:<playsink> adding audio
0:00:01.721796518  1888 0x763335b0 DEBUG               playsink gstplaysink.c:3515:gst_play_sink_do_reconfigure:<playsink> creating new audio chain
0:00:01.722069036  1888 0x763335b0 DEBUG               playsink gstplaysink.c:2668:gen_audio_chain:<playsink> making audio chain 0x53cf88
0:00:01.722326222  1888 0x763335b0 DEBUG               playsink gstplaysink.c:2677:gen_audio_chain:<playsink> trying autoaudiosink
0:00:01.736406259  1888 0x763335b0 DEBUG             autodetect gstautodetect.c:369:gst_auto_detect_detect:<audiosink> Creating new kid
0:00:01.743965148  1888 0x763335b0 LOG               autodetect gstautodetect.c:277:gst_auto_detect_find_best:<audiosink> Trying to find usable audio elements ...
0:00:01.752318962  1888 0x763335b0 DEBUG             autodetect gstautodetect.c:286:gst_auto_detect_find_best:<audiosink> Testing dvbaudiosink
0:00:01.755005703  1888 0x763335b0 DEBUG             autodetect gstautodetect.c:296:gst_auto_detect_find_best:<audiosink> Checking caps: audio/x-raw vs. audio/mpeg, mpegversion=(int)1, layer=(int)[ 1, 3 ], parsed=(boolean)true; audio/mp
eg, mpegversion=(int){ 2, 4 }, profile=(string)lc, stream-format=(string){ raw, adts, adif, loas }, framed=(boolean)true; audio/x-ac3, framed=(boolean)true; audio/x-private1-ac3, framed=(boolean)true; audio/x-eac3, framed=(boolean)true;
 audio/x-private1-eac3, framed=(boolean)true; audio/x-private1-lpcm; audio/x-wma; audio/x-raw, format=(string){ S32LE, S24LE, S16LE, S8, U32LE, U24LE, U16LE, U8 }, layout=(string){ interleaved, non-interleaved }, rate=(int)[ 1, 48000 ],
 channels=(int)[ 1, 2 ]
0:00:01.756792592  1888 0x763335b0 DEBUG             autodetect gstautodetect.c:305:gst_auto_detect_find_best:<audiosink> Found compatible caps
0:00:01.757201888  1888 0x763335b0 DEBUG           dvbaudiosink gstdvbaudiosink.c:1525:gst_dvbaudiosink_change_state:<audiosink-actual-sink-dvbaudio> GST_STATE_CHANGE_NULL_TO_READY
0:00:01.757455111  1888 0x763335b0 DEBUG           dvbaudiosink gstdvbaudiosink.c:1423:gst_dvbaudiosink_start:<audiosink-actual-sink-dvbaudio> start
0:00:01.759019925  1888 0x763335b0 DEBUG             autodetect gstautodetect.c:312:gst_auto_detect_find_best:<audiosink> This worked!
0:00:01.759296222  1888 0x763335b0 DEBUG             autodetect gstautodetect.c:328:gst_auto_detect_find_best:<audiosink> done trying
0:00:01.760956259  1888 0x763335b0 DEBUG             autodetect gstautodetect.c:391:gst_auto_detect_detect:<audiosink> Re-assigning ghostpad
0:00:01.761625666  1888 0x763335b0 DEBUG             autodetect gstautodetect.c:396:gst_auto_detect_detect:<audiosink> done changing auto audio sink

It's not possible to see setup of sync property in debug, you can look in sources of gstautodetect.c(function gst_auto_detect_detect, 360 line) or you can see it in in basesink debug, when we synchronize in gst_base_sink_wait_clock:

0:00:04.438940886  1915   0x512320 DEBUG               basesink gstbasesink.c:3401:gst_base_sink_chain_unlocked:<audiosink-actual-sink-dvbaudio> got times start: 0:00:02.200000000, end: 0:00:02.240000000
0:00:04.439385108  1915   0x512320 DEBUG               basesink gstbasesink.c:1950:gst_base_sink_get_sync_times:<audiosink-actual-sink-dvbaudio> got times start: 0:00:02.200000000, stop: 0:00:02.240000000, do_sync 1
0:00:04.439879034  1915   0x512320 LOG                 basesink gstbasesink.c:2487:gst_base_sink_do_sync:<audiosink-actual-sink-dvbaudio> avg frame diff 0:00:00.040000000
0:00:04.440212071  1915   0x512320 DEBUG               basesink gstbasesink.c:2527:gst_base_sink_do_sync:<audiosink-actual-sink-dvbaudio> reset rc_time to time 0:00:02.200000000
0:00:04.440493627  1915   0x512320 DEBUG               basesink gstbasesink.c:2539:gst_base_sink_do_sync:<audiosink-actual-sink-dvbaudio> possibly waiting for clock to reach 0:00:02.200000000, adjusted 0:00:02.200000000
0:00:04.440956627  1915   0x512320 LOG                 basesink gstbasesink.c:2121:gst_base_sink_wait_clock:<audiosink-actual-sink-dvbaudio> time 0:00:02.200000000, base_time 113:44:16.392776500
0:00:04.473878701  1915   0x512320 DEBUG               basesink gstbasesink.c:2546:gst_base_sink_do_sync:<audiosink-actual-sink-dvbaudio> clock returned 0, jitter -0:00:00.032223298
0:00:04.474251256  1915   0x512320 DEBUG               basesink gstbasesink.c:2865:gst_base_sink_is_too_late:<audiosink-actual-sink-dvbaudio> object was scheduled in time
0:00:04.474469256  1915   0x512320 DEBUG               basesink gstbasesink.c:3501:gst_base_sink_chain_unlocked:<audiosink-actual-sink-dvbaudio> rendering object 0x5a7c08
0:00:04.474699701  1915   0x512320 DEBUG               basesink gstbasesink.c:946:gst_base_sink_set_last_buffer_unlocked:<audiosink-actual-sink-dvbaudio> setting last buffer to 0x5a7c08
0:00:04.476496775  1915   0x512320 DEBUG               basesink gstbasesink.c:3547:gst_base_sink_chain_unlocked:<audiosink-actual-sink-dvbaudio> object unref after render 0x5a7c08

If we don't synchronize it looks like this(look gst_base_sink_wait_clock):

GST_DEBUG_FILE=/tmp/waw_dvbaudiosink_sync_false.log GST_DEBUG_NO_COLOR=1 GST_DEBUG=decodebin:6,autodetect:6,playbin:6,playsink:6,dvbaudiosink:5,basesink:6 gst-launch-1.0 playbin uri=file:///media/net/DOMA/Test/24bit_44kHz_
Brake5.wav audio-sink="dvbaudiosink"

0:00:02.989006664  1922   0x515350 DEBUG               basesink gstbasesink.c:3401:gst_base_sink_chain_unlocked:<dvbaudiosink0> got times start: 0:00:03.520000000, end: 0:00:03.560000000
0:00:02.989405220  1922   0x515350 DEBUG               basesink gstbasesink.c:1950:gst_base_sink_get_sync_times:<dvbaudiosink0> got times start: 0:00:03.520000000, stop: 0:00:03.560000000, do_sync 1
0:00:02.989903776  1922   0x515350 LOG                 basesink gstbasesink.c:2487:gst_base_sink_do_sync:<dvbaudiosink0> avg frame diff 0:00:00.040000000
0:00:02.990242220  1922   0x515350 DEBUG               basesink gstbasesink.c:2527:gst_base_sink_do_sync:<dvbaudiosink0> reset rc_time to time 0:00:03.520000000
0:00:02.990517590  1922   0x515350 DEBUG               basesink gstbasesink.c:2539:gst_base_sink_do_sync:<dvbaudiosink0> possibly waiting for clock to reach 0:00:03.520000000, adjusted 0:00:03.520000000
0:00:02.990979887  1922   0x515350 DEBUG               basesink gstbasesink.c:2167:gst_base_sink_wait_clock:<dvbaudiosink0> sync disabled
0:00:02.991205442  1922   0x515350 DEBUG               basesink gstbasesink.c:2546:gst_base_sink_do_sync:<dvbaudiosink0> clock returned 4, jitter  0:00:00.000000000
0:00:02.991485887  1922   0x515350 DEBUG               basesink gstbasesink.c:3501:gst_base_sink_chain_unlocked:<dvbaudiosink0> rendering object 0x575ad8
0:00:02.991840590  1922   0x515350 DEBUG               basesink gstbasesink.c:946:gst_base_sink_set_last_buffer_unlocked:<dvbaudiosink0> setting last buffer to 0x575ad8
0:00:02.992983701  1922   0x515350 DEBUG               basesink gstbasesink.c:3547:gst_base_sink_chain_unlocked:<dvbaudiosink0> object unref after render 0x575ad8

It also triggered this resolved problem with preroll lock, which wouldn't happen if sync was turned off:

http://forums.openpl...-34#entry480811

 

So we should make sure that sync is disabled, currently is sync set in NULL state, for example we can postpone it as late as possible, just before rendering, when going from READY to PAUSED state:

diff --git a/gstdvbaudiosink.c b/gstdvbaudiosink.c
index 2b87caa..82d4167 100644
--- a/gstdvbaudiosink.c
+++ b/gstdvbaudiosink.c
@@ -314,7 +314,6 @@ static void gst_dvbaudiosink_init(GstDVBAudioSink *s
elf)
 	self->rate = 1.0;
 	self->timestamp = GST_CLOCK_TIME_NONE;
 
-	gst_base_sink_set_sync(GST_BASE_SINK(self), FALSE);
 	gst_base_sink_set_async_enabled(GST_BASE_SINK(self), TRUE);
 }
 
@@ -1515,6 +1514,7 @@ static GstStateChangeReturn gst_dvbaudiosink_chang
e_state(GstElement *element, G
 		break;
 	case GST_STATE_CHANGE_READY_TO_PAUSED:
 		GST_DEBUG_OBJECT(self,"GST_STATE_CHANGE_READY_TO_PAUSED");
+		gst_base_sink_set_sync(GST_BASE_SINK(self), FALSE);
 		self->paused = TRUE;
 
 		if (self->fd >= 0)

[mx3L]

Well like I said, so far only my Zgemma Star receiver seems to suffer from excessive pausing on hls streams.

Buffering, setting pipeline to PAUSED ...
Done buffering, setting pipeline to PLAYING ...
Buffering, setting pipeline to PAUSED ...
Done buffering, setting pipeline to PLAYING ...
Buffering, setting pipeline to PAUSED ...

This causes E2 to only show a single frame and no sound.

On gst-launch it will continue to try but I only get like 2 or 3 frames each second.

 

I haven't tested it on my dm800se yet, but on my sh4 receiver, everything seems to work fine with the same gstreamer 1.5.90 snapshot.

PAUSED to PLAYING, PLAYING to PAUSED happens because gst-launch is not ignoring buffering messages, so it will play when it reach 100% and pause when it reach 0% buffer level. By default we are ignoring buffering messages in enigma2.

 

Can you create log when playing this hls stream in enigma2?

GST_DEBUG_FILE=/tmp/hls.log GST_DEBUG_NO_COLOR=1 GST_DEBUG=dvbvideosink:5,dvbaudiosink:5,basesink:6 enigma2.sh

[christophecvr]

 

Well like I said, so far only my Zgemma Star receiver seems to suffer from excessive pausing on hls streams.

Buffering, setting pipeline to PAUSED ...
Done buffering, setting pipeline to PLAYING ...
Buffering, setting pipeline to PAUSED ...
Done buffering, setting pipeline to PLAYING ...
Buffering, setting pipeline to PAUSED ...

This causes E2 to only show a single frame and no sound.

On gst-launch it will continue to try but I only get like 2 or 3 frames each second.

 

I haven't tested it on my dm800se yet, but on my sh4 receiver, everything seems to work fine with the same gstreamer 1.5.90 snapshot.

PAUSED to PLAYING, PLAYING to PAUSED happens because gst-launch is not ignoring buffering messages, so it will play when it reach 100% and pause when it reach 0% buffer level. By default we are ignoring buffering messages in enigma2.

 

Can you create log when playing this hls stream in enigma2?

GST_DEBUG_FILE=/tmp/hls.log GST_DEBUG_NO_COLOR=1 GST_DEBUG=dvbvideosink:5,dvbaudiosink:5,basesink:6 enigma2.sh

That's what happens when the option flags=0x47  is not used. If flags=0x47 is used it works better.

 

Note from out off enigma the stream posted by mast works 100 % perfect on dm8000 and vuduo2 using gstreamer-1.5.9.

[mx3L]

Yes, I don't have problem too(gst 1.5.2), but @MastaG has problem on some receiver...

Edited by mx3L, 16 September 2015 - 08:25.

[christophecvr]

Yes, I don't have problem too(gst 1.5.2), but @MastaG has problem on some receiver...

Parhaps the change You proposed may improve it on that box ....

 

You're changege does perform well for physicall (togheter with the buffer change off me) audio cd's.

 

read :

http://forums.openpl...ndpost&p=505189

 

I now already have two cd's (which never played perfect from begin to end ) started and played 100 % from begin to end.

Currently the third cd is in (and that one has a big scratch on it and for example plays ok in my standard cd player but has problems in my standard dvd player).

It's now already more then half way whitout any hickup into the dvbwriter connected to dm8000 (sata) using mediaplayer.

[MastaG]

I applied mx3L's patch which moves gst_base_sink_set_sync as a seperate patch to your multibox sink last night to do some testing.

But I see you commited yourself now :-)

 

And with latest gstreamer git (1.5.90) as of yesterday night I still have the problem where it only displays the first frame on many HLS streams.

However I'm very limited in time these days.

I've only tested on my Zgemma Star receiver, I still need to compare with my dm800se.

 

But I think I'll revert back to 1.5.2 with all of the fixes provided throughout the forum (hls and mkv fixes etc...)

[athoik]

But I think I'll revert back to 1.5.2 with all of the fixes provided throughout the forum (hls and mkv fixes etc...)

And if there is an issue that didn't exist back to 1.5.2 then stable 1.6 will contain that issue.

I suggest to open a ticket on GStreamer bug tracker with the information you have already and if they can reproduce it, they might fix it too!

[MastaG]

Yes athoik, that's what I was planning to do.

I really hope to send in a bug report this weekend.

[christophecvr]

I applied mx3L's patch which moves gst_base_sink_set_sync as a seperate patch to your multibox sink last night to do some testing.

But I see you commited yourself now :-)

 

And with latest gstreamer git (1.5.90) as of yesterday night I still have the problem where it only displays the first frame on many HLS streams.

However I'm very limited in time these days.

I've only tested on my Zgemma Star receiver, I still need to compare with my dm800se.

 

But I think I'll revert back to 1.5.2 with all of the fixes provided throughout the forum (hls and mkv fixes etc...)

 

That's not a good idea , since after all it only worked with fixes (mostly more work arounds, eighter hack's) .

The base gst 1.5.9 does it on it very good and again better then 1.5.1 or 2. This for boxes which do not need a work-around or hack. Perhaps it's better to check why the hack is needed on those boxes to let it work (after all in 1.5.2 they where needed as well)

For 1.5.9 they most probably just need to be adapted ....... 

 

Gstreamer is not far from a new stable 1.6 version. This mean anyway that all the work arounds and or hacks needs to be adapted .....

 

Is it not better that the guys working on that try to trace the real cause instead of using work arounds and or hack's ? That's really not easy and a lot off work in bug tracing versus kernel driver and ....

[MastaG]

I'm not using dirty hacks, but simply the fixes which have already been accepted in git.

Like the fix for HLS streams, the one that takes care of mkv files etc...

There are no specific hacks or workarounds for any of my receivers.

 

But like I said, I'll create an 1.5.2 image for testing first and compare the results with 1.5.9 git.

If there's indeed a bug I'll post a report.

[olii]

Can you guys please tell me if gstreamer is capable of playing h.264 over rtsp from ip camera? I have dreambox 800sev2, gstreamer reports missing decoder for h264. Mkv from hdd plays fine, indeed.

[MastaG]

Alright, so I've made a test with enigma2 (no patches), gstreamer 1.5.90 and chris' multibox dvbmediasink.

I'm trying to play CNN: http://wpc.C1A9.edge...link/b_828.m3u8

# gst-launch-1.0 --gst-debug=dvbaudiosink:4,dvbvideosink:4 playbin uri=http://wpc.C1A9.edgecastcdn.net/hls-live/20C1A9/cnn/ls_satlink/b_828.m3u8 flags=0x47
Setting pipeline to PAUSED ...
Pipeline is PREROLLING ...
0:00:02.707971443   820 0x75106550 INFO            dvbaudiosink gstdvbaudiosink.c:1466:gst_dvbaudiosink_change_state:<dvbaudiosink0> GST_STATE_CHANGE_NULL_TO_READY
0:00:02.729118443   820 0x75106490 INFO            dvbvideosink gstdvbvideosink.c:1831:gst_dvbvideosink_change_state:<dvbvideosink0> GST_STATE_CHANGE_NULL_TO_READY
0:00:03.000674258   820 0x75106490 INFO            dvbvideosink gstdvbvideosink.c:1835:gst_dvbvideosink_change_state:<dvbvideosink0> GST_STATE_CHANGE_READY_TO_PAUSED
WARNING: from element /GstPlayBin:playbin0/GstPlaySink:playsink: No volume control found
Additional debug info:
/home/mastag/src/openpli-oe-core/build/tmp/work/mips32el-oe-linux/gstreamer1.0-plugins-base/1.5.90+gitAUTOINC+060f0c21f2-r0/git/gst/playback/gstplaysink.c(2852): gen_audio_chain (): /GstPlayBin:playbin0/GstPlaySink:playsink:
Volume/mute is not available
0:00:04.699812960   820 0x75106490 INFO            dvbaudiosink gstdvbaudiosink.c:1471:gst_dvbaudiosink_change_state:<dvbaudiosink0> GST_STATE_CHANGE_READY_TO_PAUSED
0:00:04.723052109   820   0x695860 INFO            dvbvideosink gstdvbvideosink.c:425:gst_dvbvideosink_event:<dvbvideosink0> EVENT stream-start
0:00:04.726891331   820 0x753c5a00 INFO            dvbaudiosink gstdvbaudiosink.c:735:gst_dvbaudiosink_event:<dvbaudiosink0> EVENT stream-start
0:00:04.735843220   820   0x695860 INFO            dvbvideosink gstdvbvideosink.c:425:gst_dvbvideosink_event:<dvbvideosink0> EVENT caps
0:00:04.737066738   820   0x695860 INFO            dvbvideosink gstdvbvideosink.c:1290:gst_dvbvideosink_set_caps:<dvbvideosink0> caps = video/x-h264, width=(int)16, height=(int)16, parsed=(boolean)true, stream-format=(string)byte-stream, alignment=(string)nal
0:00:04.740670590   820   0x695860 INFO            dvbvideosink gstdvbvideosink.c:1460:gst_dvbvideosink_set_caps:<dvbvideosink0> MIMETYPE video/x-h264 -> STREAMTYPE_MPEG4_H264
0:00:04.754733146   820   0x695860 INFO            dvbvideosink gstdvbvideosink.c:425:gst_dvbvideosink_event:<dvbvideosink0> EVENT segment
0:00:04.755095294   820   0x695860 INFO            dvbvideosink gstdvbvideosink.c:519:gst_dvbvideosink_event:<dvbvideosink0> SEGMENT rate=1.000000 format=3 start=0 pos=0
0:00:04.756878294   820   0x695860 INFO            dvbvideosink gstdvbvideosink.c:520:gst_dvbvideosink_event:<dvbvideosink0> SEGMENT DVB TIMESTAMP=0 HEXFORMAT 0x0
0:00:04.759460923   820   0x695860 INFO            dvbvideosink gstdvbvideosink.c:425:gst_dvbvideosink_event:<dvbvideosink0> EVENT tag
0:00:04.760450405   820   0x695860 INFO            dvbvideosink gstdvbvideosink.c:548:gst_dvbvideosink_event:<dvbvideosink0> TAG taglist, video-codec=(string)H.264;
0:00:04.797140405   820 0x753c5a00 INFO            dvbaudiosink gstdvbaudiosink.c:735:gst_dvbaudiosink_event:<dvbaudiosink0> EVENT caps
0:00:04.800063220   820 0x753c5a00 INFO            dvbaudiosink gstdvbaudiosink.c:462:gst_dvbaudiosink_set_caps:<dvbaudiosink0> MIMETYPE audio/mpeg version 4(AAC-ADTS)
0:00:04.801605442   820 0x753c5a00 INFO            dvbaudiosink gstdvbaudiosink.c:713:gst_dvbaudiosink_set_caps:<dvbaudiosink0> setting dvb mode 0x0b

0:00:04.835846997   820 0x753c5a00 INFO            dvbaudiosink gstdvbaudiosink.c:735:gst_dvbaudiosink_event:<dvbaudiosink0> EVENT segment
0:00:04.836916516   820 0x753c5a00 INFO            dvbaudiosink gstdvbaudiosink.c:834:gst_dvbaudiosink_event:<dvbaudiosink0> GST_EVENT_SEGMENT rate=1.000000 format=3 start=0 position=0
0:00:04.837849183   820 0x753c5a00 INFO            dvbaudiosink gstdvbaudiosink.c:835:gst_dvbaudiosink_event:<dvbaudiosink0> SEGMENT DVB TIMESTAMP=0 HEX=0x0
0:00:04.840459294   820 0x753c5a00 INFO            dvbaudiosink gstdvbaudiosink.c:735:gst_dvbaudiosink_event:<dvbaudiosink0> EVENT tag
0:00:04.841636590   820 0x753c5a00 INFO            dvbaudiosink gstdvbaudiosink.c:879:gst_dvbaudiosink_event:<dvbaudiosink0> TAG taglist, audio-codec=(string)"MPEG-2\ AAC";
Pipeline is PREROLLED ...
Setting pipeline to PLAYING ...
0:00:04.879094257   820   0x506920 INFO            dvbaudiosink gstdvbaudiosink.c:1482:gst_dvbaudiosink_change_state:<dvbaudiosink0> GST_STATE_CHANGE_PAUSED_TO_PLAYING
0:00:04.886220923   820 0x753c5a00 INFO            dvbaudiosink gstdvbaudiosink.c:735:gst_dvbaudiosink_event:<dvbaudiosink0> EVENT tag
0:00:04.886679331   820 0x753c5a00 INFO            dvbaudiosink gstdvbaudiosink.c:879:gst_dvbaudiosink_event:<dvbaudiosink0> TAG taglist, audio-codec=(string)"MPEG-4\ AAC", bitrate=(uint)125409;
0:00:04.904220812   820   0x506920 INFO            dvbvideosink gstdvbvideosink.c:1846:gst_dvbvideosink_change_state:<dvbvideosink0> GST_STATE_CHANGE_PAUSED_TO_PLAYING
0:00:04.910912997   820   0x695860 INFO            dvbvideosink gstdvbvideosink.c:425:gst_dvbvideosink_event:<dvbvideosink0> EVENT tag
0:00:04.913824923   820   0x695860 INFO            dvbvideosink gstdvbvideosink.c:548:gst_dvbvideosink_event:<dvbvideosink0> TAG taglist, video-codec=(string)H.264;
0:00:04.927832812   820 0x753c5a00 INFO            dvbaudiosink gstdvbaudiosink.c:735:gst_dvbaudiosink_event:<dvbaudiosink0> EVENT tag
0:00:04.929258405   820 0x753c5a00 INFO            dvbaudiosink gstdvbaudiosink.c:879:gst_dvbaudiosink_event:<dvbaudiosink0> TAG taglist, audio-codec=(string)"MPEG-4\ AAC", minimum-bitrate=(uint)134022, maximum-bitrate=(uint)134022, bitrate=(uint)124995;
0:00:04.943527294   820 0x753c5a00 INFO            dvbaudiosink gstdvbaudiosink.c:735:gst_dvbaudiosink_event:<dvbaudiosink0> EVENT tag
0:00:04.959558145   820 0x753c5a00 INFO            dvbaudiosink gstdvbaudiosink.c:879:gst_dvbaudiosink_event:<dvbaudiosink0> TAG taglist, audio-codec=(string)"MPEG-4\ AAC", minimum-bitrate=(uint)126787, maximum-bitrate=(uint)134022, bitrate=(uint)125158;
0:00:04.979830405   820 0x753c5a00 INFO            dvbaudiosink gstdvbaudiosink.c:735:gst_dvbaudiosink_event:<dvbaudiosink0> EVENT tag
0:00:04.980920553   820 0x753c5a00 INFO            dvbaudiosink gstdvbaudiosink.c:879:gst_dvbaudiosink_event:<dvbaudiosink0> TAG taglist, audio-codec=(string)"MPEG-4\ AAC", minimum-bitrate=(uint)124031, maximum-bitrate=(uint)134022, bitrate=(uint)125621;
0:00:04.991438071   820 0x753c5a00 INFO            dvbaudiosink gstdvbaudiosink.c:735:gst_dvbaudiosink_event:<dvbaudiosink0> EVENT tag
New clock: GstSystemClock
0:00:04.999565812   820 0x753c5a00 INFO            dvbaudiosink gstdvbaudiosink.c:879:gst_dvbaudiosink_event:<dvbaudiosink0> TAG taglist, audio-codec=(string)"MPEG-4\ AAC", minimum-bitrate=(uint)115073, maximum-bitrate=(uint)134022, bitrate=(uint)124867;
0:00:05.039207294   820 0x753c5a00 INFO            dvbaudiosink gstdvbaudiosink.c:735:gst_dvbaudiosink_event:<dvbaudiosink0> EVENT tag
0:00:05.043690405   820 0x753c5a00 INFO            dvbaudiosink gstdvbaudiosink.c:879:gst_dvbaudiosink_event:<dvbaudiosink0> TAG taglist, audio-codec=(string)"MPEG-4\ AAC", minimum-bitrate=(uint)114728, maximum-bitrate=(uint)134022, bitrate=(uint)125064;
0:00:05.081829331   820 0x753c5a00 INFO            dvbaudiosink gstdvbaudiosink.c:735:gst_dvbaudiosink_event:<dvbaudiosink0> EVENT tag
0:00:05.087071368   820 0x753c5a00 INFO            dvbaudiosink gstdvbaudiosink.c:879:gst_dvbaudiosink_event:<dvbaudiosink0> TAG taglist, audio-codec=(string)"MPEG-4\ AAC", minimum-bitrate=(uint)110250, maximum-bitrate=(uint)134022, bitrate=(uint)125002;
0:00:05.100883331   820 0x753c5a00 INFO            dvbaudiosink gstdvbaudiosink.c:735:gst_dvbaudiosink_event:<dvbaudiosink0> EVENT tag
0:00:05.103696701   820 0x753c5a00 INFO            dvbaudiosink gstdvbaudiosink.c:879:gst_dvbaudiosink_event:<dvbaudiosink0> TAG taglist, audio-codec=(string)"MPEG-4\ AAC", minimum-bitrate=(uint)110250, maximum-bitrate=(uint)136434, bitrate=(uint)125499;
0:00:05.170660405   820 0x753c5a00 INFO            dvbaudiosink gstdvbaudiosink.c:735:gst_dvbaudiosink_event:<dvbaudiosink0> EVENT tag
0:00:05.176898479   820 0x753c5a00 INFO            dvbaudiosink gstdvbaudiosink.c:879:gst_dvbaudiosink_event:<dvbaudiosink0> TAG taglist, audio-codec=(string)"MPEG-4\ AAC", minimum-bitrate=(uint)110250, maximum-bitrate=(uint)137123, bitrate=(uint)125672;
0:00:05.225601219   820 0x753c5a00 INFO            dvbaudiosink gstdvbaudiosink.c:735:gst_dvbaudiosink_event:<dvbaudiosink0> EVENT tag
0:00:05.231573738   820 0x753c5a00 INFO            dvbaudiosink gstdvbaudiosink.c:879:gst_dvbaudiosink_event:<dvbaudiosink0> TAG taglist, audio-codec=(string)"MPEG-4\ AAC", minimum-bitrate=(uint)110250, maximum-bitrate=(uint)138501, bitrate=(uint)125625;
0:00:05.260841664   820 0x753c5a00 INFO            dvbaudiosink gstdvbaudiosink.c:735:gst_dvbaudiosink_event:<dvbaudiosink0> EVENT tag
0:00:05.261923145   820 0x753c5a00 INFO            dvbaudiosink gstdvbaudiosink.c:879:gst_dvbaudiosink_event:<dvbaudiosink0> TAG taglist, audio-codec=(string)"MPEG-4\ AAC", minimum-bitrate=(uint)110250, maximum-bitrate=(uint)142635, bitrate=(uint)125709;
0:00:05.687903034   820 0x753c5a00 INFO            dvbaudiosink gstdvbaudiosink.c:735:gst_dvbaudiosink_event:<dvbaudiosink0> EVENT tag
0:00:05.690597367   820 0x753c5a00 INFO            dvbaudiosink gstdvbaudiosink.c:879:gst_dvbaudiosink_event:<dvbaudiosink0> TAG taglist, audio-codec=(string)"MPEG-4\ AAC", minimum-bitrate=(uint)110250, maximum-bitrate=(uint)144358, bitrate=(uint)125665;
0:00:06.269612552   820   0x695860 INFO            dvbvideosink gstdvbvideosink.c:425:gst_dvbvideosink_event:<dvbvideosink0> EVENT caps
0:00:06.270014108   820   0x695860 INFO            dvbvideosink gstdvbvideosink.c:1290:gst_dvbvideosink_set_caps:<dvbvideosink0> caps = video/x-h264, stream-format=(string)byte-stream, alignment=(string)nal, pixel-aspect-ratio=(fraction)404/405, width=(int)720, height=(int)404, framerate=(fraction)25/1, parsed=(boolean)true, profile=(string)constrained-baseline, level=(string)3
0:00:06.272836034   820   0x695860 INFO            dvbvideosink gstdvbvideosink.c:1460:gst_dvbvideosink_set_caps:<dvbvideosink0> MIMETYPE video/x-h264 -> STREAMTYPE_MPEG4_H264
0:00:06.344840182   820   0x695860 INFO            dvbvideosink gstdvbvideosink.c:425:gst_dvbvideosink_event:<dvbvideosink0> EVENT tag
0:00:06.345202959   820   0x695860 INFO            dvbvideosink gstdvbvideosink.c:548:gst_dvbvideosink_event:<dvbvideosink0> TAG taglist, video-codec=(string)H.264, minimum-bitrate=(uint)5387000, maximum-bitrate=(uint)5387000, bitrate=(uint)5516400;
0:00:06.439686811   820   0x695860 INFO            dvbvideosink gstdvbvideosink.c:658:video_write:<dvbvideosink0> VIDEO_EVENT 2
0:00:06.442669811   820   0x695860 INFO            dvbvideosink gstdvbvideosink.c:658:video_write:<dvbvideosink0> VIDEO_EVENT 1
0:00:06.456796330   820   0x695860 INFO            dvbvideosink gstdvbvideosink.c:658:video_write:<dvbvideosink0> VIDEO_EVENT 16
Buffering, setting pipeline to PAUSED ...
0:00:07.977707144   820   0x506920 INFO            dvbaudiosink gstdvbaudiosink.c:1504:gst_dvbaudiosink_change_state:<dvbaudiosink0> GST_STATE_CHANGE_PLAYING_TO_PAUSED
0:00:08.015783514   820   0x506920 INFO            dvbvideosink gstdvbvideosink.c:1859:gst_dvbvideosink_change_state:<dvbvideosink0> GST_STATE_CHANGE_PLAYING_TO_PAUSED
Done buffering, setting pipeline to PLAYING ...
0:00:08.687051810   820   0x506920 INFO            dvbaudiosink gstdvbaudiosink.c:1482:gst_dvbaudiosink_change_state:<dvbaudiosink0> GST_STATE_CHANGE_PAUSED_TO_PLAYING
0:00:08.720225402   820   0x506920 INFO            dvbvideosink gstdvbvideosink.c:1846:gst_dvbvideosink_change_state:<dvbvideosink0> GST_STATE_CHANGE_PAUSED_TO_PLAYING
0:00:09.557670772   820 0x753c5a00 INFO            dvbaudiosink gstdvbaudiosink.c:735:gst_dvbaudiosink_event:<dvbaudiosink0> EVENT tag
0:00:09.564463402   820 0x753c5a00 INFO            dvbaudiosink gstdvbaudiosink.c:879:gst_dvbaudiosink_event:<dvbaudiosink0> TAG taglist, audio-codec=(string)"MPEG-4\ AAC", minimum-bitrate=(uint)109905, maximum-bitrate=(uint)144358, bitrate=(uint)125641;
0:00:09.778714365   820 0x753c5a00 INFO            dvbaudiosink gstdvbaudiosink.c:735:gst_dvbaudiosink_event:<dvbaudiosink0> EVENT tag
0:00:09.784425439   820 0x753c5a00 INFO            dvbaudiosink gstdvbaudiosink.c:879:gst_dvbaudiosink_event:<dvbaudiosink0> TAG taglist, audio-codec=(string)"MPEG-4\ AAC", minimum-bitrate=(uint)109905, maximum-bitrate=(uint)149871, bitrate=(uint)125670;
Buffering, setting pipeline to PAUSED ...
0:00:10.022456809   820   0x506920 INFO            dvbaudiosink gstdvbaudiosink.c:1504:gst_dvbaudiosink_change_state:<dvbaudiosink0> GST_STATE_CHANGE_PLAYING_TO_PAUSED
0:00:10.103740550   820   0x506920 INFO            dvbvideosink gstdvbvideosink.c:1859:gst_dvbvideosink_change_state:<dvbvideosink0> GST_STATE_CHANGE_PLAYING_TO_PAUSED
Done buffering, setting pipeline to PLAYING ...
0:00:10.248248809   820   0x506920 INFO            dvbaudiosink gstdvbaudiosink.c:1482:gst_dvbaudiosink_change_state:<dvbaudiosink0> GST_STATE_CHANGE_PAUSED_TO_PLAYING
0:00:10.310220142   820   0x506920 INFO            dvbvideosink gstdvbvideosink.c:1846:gst_dvbvideosink_change_state:<dvbvideosink0> GST_STATE_CHANGE_PAUSED_TO_PLAYING
Buffering, setting pipeline to PAUSED ...
0:00:11.075035883   820   0x506920 INFO            dvbaudiosink gstdvbaudiosink.c:1504:gst_dvbaudiosink_change_state:<dvbaudiosink0> GST_STATE_CHANGE_PLAYING_TO_PAUSED
0:00:11.141269216   820   0x506920 INFO            dvbvideosink gstdvbvideosink.c:1859:gst_dvbvideosink_change_state:<dvbvideosink0> GST_STATE_CHANGE_PLAYING_TO_PAUSED
Done buffering, setting pipeline to PLAYING ...
0:00:11.226952956   820   0x506920 INFO            dvbaudiosink gstdvbaudiosink.c:1482:gst_dvbaudiosink_change_state:<dvbaudiosink0> GST_STATE_CHANGE_PAUSED_TO_PLAYING
0:00:11.307049734   820   0x506920 INFO            dvbvideosink gstdvbvideosink.c:1846:gst_dvbvideosink_change_state:<dvbvideosink0> GST_STATE_CHANGE_PAUSED_TO_PLAYING
0:00:11.797662141   820 0x753c5a00 INFO            dvbaudiosink gstdvbaudiosink.c:735:gst_dvbaudiosink_event:<dvbaudiosink0> EVENT tag
0:00:11.798792845   820 0x753c5a00 INFO            dvbaudiosink gstdvbaudiosink.c:879:gst_dvbaudiosink_event:<dvbaudiosink0> TAG taglist, audio-codec=(string)"MPEG-4\ AAC", minimum-bitrate=(uint)108182, maximum-bitrate=(uint)149871, bitrate=(uint)125647;
0:00:11.879756364   820 0x753c5a00 INFO            dvbaudiosink gstdvbaudiosink.c:735:gst_dvbaudiosink_event:<dvbaudiosink0> EVENT tag
0:00:11.886721438   820 0x753c5a00 INFO            dvbaudiosink gstdvbaudiosink.c:879:gst_dvbaudiosink_event:<dvbaudiosink0> TAG taglist, audio-codec=(string)"MPEG-4\ AAC", minimum-bitrate=(uint)107838, maximum-bitrate=(uint)149871, bitrate=(uint)125644;
Buffering, setting pipeline to PAUSED ...
0:00:12.265086178   820   0x506920 INFO            dvbaudiosink gstdvbaudiosink.c:1504:gst_dvbaudiosink_change_state:<dvbaudiosink0> GST_STATE_CHANGE_PLAYING_TO_PAUSED
0:00:12.336136697   820   0x506920 INFO            dvbvideosink gstdvbvideosink.c:1859:gst_dvbvideosink_change_state:<dvbvideosink0> GST_STATE_CHANGE_PLAYING_TO_PAUSED
Done buffering, setting pipeline to PLAYING ...
0:00:12.401293548   820   0x506920 INFO            dvbaudiosink gstdvbaudiosink.c:1482:gst_dvbaudiosink_change_state:<dvbaudiosink0> GST_STATE_CHANGE_PAUSED_TO_PLAYING
0:00:12.468058067   820   0x506920 INFO            dvbvideosink gstdvbvideosink.c:1846:gst_dvbvideosink_change_state:<dvbvideosink0> GST_STATE_CHANGE_PAUSED_TO_PLAYING
Buffering, setting pipeline to PAUSED ...
0:00:12.567227178   820   0x506920 INFO            dvbaudiosink gstdvbaudiosink.c:1504:gst_dvbaudiosink_change_state:<dvbaudiosink0> GST_STATE_CHANGE_PLAYING_TO_PAUSED
0:00:12.634906956   820   0x506920 INFO            dvbvideosink gstdvbvideosink.c:1859:gst_dvbvideosink_change_state:<dvbvideosink0> GST_STATE_CHANGE_PLAYING_TO_PAUSED
Done buffering, setting pipeline to PLAYING ...
Buffering, setting pipeline to PAUSED ...
Done buffering, setting pipeline to PLAYING ...

When it starts it will stutter a bit and show a few frames for one or two seconds, then it freezes.

As you can see the last line says "playing" but it's frozen (also no sound).

 

The same happens when playing the stream from Enigma2.

 

 

 

Now here comes the strange part:

With gstreamer 1.5.2 I get the same behaviour using gst-launch:

# gst-launch-1.0 --gst-debug=dvbaudiosink:4,dvbvideosink:4 playbin uri=http://wpc.C1A9.edgecastcdn.net/hls-live/20C1A9/cnn/ls_satlink/b_828.m3u8 flags=0x47
Setting pipeline to PAUSED ...
Pipeline is PREROLLING ...
0:00:02.685781146   846 0x75208490 INFO            dvbvideosink gstdvbvideosink.c:1831:gst_dvbvideosink_change_state:<dvbvideosink0> GST_STATE_CHANGE_NULL_TO_READY
0:00:02.799959035   846 0x752085b0 INFO            dvbaudiosink gstdvbaudiosink.c:1466:gst_dvbaudiosink_change_state:<dvbaudiosink0> GST_STATE_CHANGE_NULL_TO_READY
0:00:03.245912664   846 0x75208490 INFO            dvbvideosink gstdvbvideosink.c:1835:gst_dvbvideosink_change_state:<dvbvideosink0> GST_STATE_CHANGE_READY_TO_PAUSED
WARNING: from element /GstPlayBin:playbin0/GstPlaySink:playsink: No volume control found
Additional debug info:
/home/mastag/src/openpli-oe-core/build/tmp/work/mips32el-oe-linux/gstreamer1.0-plugins-base/1.5.2-r0/gst-plugins-base-1.5.2/gst/playback/gstplaysink.c(2875): gen_audio_chain (): /GstPlayBin:playbin0/GstPlaySink:playsink:
Volume/mute is not available
0:00:04.709291552   846 0x75208490 INFO            dvbaudiosink gstdvbaudiosink.c:1471:gst_dvbaudiosink_change_state:<dvbaudiosink0> GST_STATE_CHANGE_READY_TO_PAUSED
0:00:04.737659775   846 0x754b3c90 INFO            dvbaudiosink gstdvbaudiosink.c:735:gst_dvbaudiosink_event:<dvbaudiosink0> EVENT stream-start
0:00:04.740034812   846   0x681260 INFO            dvbvideosink gstdvbvideosink.c:425:gst_dvbvideosink_event:<dvbvideosink0> EVENT stream-start
0:00:04.752845775   846   0x681260 INFO            dvbvideosink gstdvbvideosink.c:425:gst_dvbvideosink_event:<dvbvideosink0> EVENT caps
0:00:04.753319404   846   0x681260 INFO            dvbvideosink gstdvbvideosink.c:1290:gst_dvbvideosink_set_caps:<dvbvideosink0> caps = video/x-h264, stream-format=(string)byte-stream, alignment=(string)nal, pixel-aspect-ratio=(fraction)404/405, width=(int)720, height=(int)404, framerate=(fraction)25/1, parsed=(boolean)true, profile=(string)constrained-baseline, level=(string)3
0:00:04.753909478   846   0x681260 INFO            dvbvideosink gstdvbvideosink.c:1460:gst_dvbvideosink_set_caps:<dvbvideosink0> MIMETYPE video/x-h264 -> STREAMTYPE_MPEG4_H264
0:00:04.765489812   846   0x681260 INFO            dvbvideosink gstdvbvideosink.c:425:gst_dvbvideosink_event:<dvbvideosink0> EVENT segment
0:00:04.765848404   846   0x681260 INFO            dvbvideosink gstdvbvideosink.c:519:gst_dvbvideosink_event:<dvbvideosink0> SEGMENT rate=1.000000 format=3 start=0 pos=0
0:00:04.770308960   846   0x681260 INFO            dvbvideosink gstdvbvideosink.c:520:gst_dvbvideosink_event:<dvbvideosink0> SEGMENT DVB TIMESTAMP=0 HEXFORMAT 0x0
0:00:04.771527886   846   0x681260 INFO            dvbvideosink gstdvbvideosink.c:425:gst_dvbvideosink_event:<dvbvideosink0> EVENT tag
0:00:04.772480404   846   0x681260 INFO            dvbvideosink gstdvbvideosink.c:548:gst_dvbvideosink_event:<dvbvideosink0> TAG taglist, video-codec=(string)H.264;
0:00:04.778478886   846   0x681260 INFO            dvbvideosink gstdvbvideosink.c:425:gst_dvbvideosink_event:<dvbvideosink0> EVENT tag
0:00:04.778804293   846   0x681260 INFO            dvbvideosink gstdvbvideosink.c:548:gst_dvbvideosink_event:<dvbvideosink0> TAG taglist, video-codec=(string)"H.264\ \(Constrained\ Baseline\ Profile\)";
0:00:04.820776330   846 0x754b3c90 INFO            dvbaudiosink gstdvbaudiosink.c:735:gst_dvbaudiosink_event:<dvbaudiosink0> EVENT caps
0:00:04.822192182   846 0x754b3c90 INFO            dvbaudiosink gstdvbaudiosink.c:462:gst_dvbaudiosink_set_caps:<dvbaudiosink0> MIMETYPE audio/mpeg version 4(AAC-ADTS)
0:00:04.824591515   846 0x754b3c90 INFO            dvbaudiosink gstdvbaudiosink.c:713:gst_dvbaudiosink_set_caps:<dvbaudiosink0> setting dvb mode 0x0b

0:00:04.858648478   846 0x754b3c90 INFO            dvbaudiosink gstdvbaudiosink.c:735:gst_dvbaudiosink_event:<dvbaudiosink0> EVENT segment
0:00:04.859929886   846 0x754b3c90 INFO            dvbaudiosink gstdvbaudiosink.c:834:gst_dvbaudiosink_event:<dvbaudiosink0> GST_EVENT_SEGMENT rate=1.000000 format=3 start=0 position=0
0:00:04.868523960   846 0x754b3c90 INFO            dvbaudiosink gstdvbaudiosink.c:835:gst_dvbaudiosink_event:<dvbaudiosink0> SEGMENT DVB TIMESTAMP=0 HEX=0x0
0:00:04.870012145   846 0x754b3c90 INFO            dvbaudiosink gstdvbaudiosink.c:735:gst_dvbaudiosink_event:<dvbaudiosink0> EVENT tag
0:00:04.871040626   846 0x754b3c90 INFO            dvbaudiosink gstdvbaudiosink.c:879:gst_dvbaudiosink_event:<dvbaudiosink0> TAG taglist, audio-codec=(string)"MPEG-2\ AAC";
0:00:04.886221552   846 0x754b3c90 INFO            dvbaudiosink gstdvbaudiosink.c:735:gst_dvbaudiosink_event:<dvbaudiosink0> EVENT tag
0:00:04.889997404   846 0x754b3c90 INFO            dvbaudiosink gstdvbaudiosink.c:879:gst_dvbaudiosink_event:<dvbaudiosink0> TAG taglist, audio-codec=(string)"MPEG-4\ AAC";
Pipeline is PREROLLED ...
Setting pipeline to PLAYING ...
0:00:04.955852515   846   0x503ec0 INFO            dvbaudiosink gstdvbaudiosink.c:1482:gst_dvbaudiosink_change_state:<dvbaudiosink0> GST_STATE_CHANGE_PAUSED_TO_PLAYING
0:00:04.973445515   846   0x503ec0 INFO            dvbvideosink gstdvbvideosink.c:1846:gst_dvbvideosink_change_state:<dvbvideosink0> GST_STATE_CHANGE_PAUSED_TO_PLAYING
0:00:05.020939885   846 0x754b3c90 INFO            dvbaudiosink gstdvbaudiosink.c:735:gst_dvbaudiosink_event:<dvbaudiosink0> EVENT tag
0:00:05.025251293   846 0x754b3c90 INFO            dvbaudiosink gstdvbaudiosink.c:879:gst_dvbaudiosink_event:<dvbaudiosink0> TAG taglist, minimum-bitrate=(uint)128854, bitrate=(uint)126477, maximum-bitrate=(uint)128854;
0:00:05.047390441   846 0x754b3c90 INFO            dvbaudiosink gstdvbaudiosink.c:735:gst_dvbaudiosink_event:<dvbaudiosink0> EVENT tag
0:00:05.060269626   846 0x754b3c90 INFO            dvbaudiosink gstdvbaudiosink.c:879:gst_dvbaudiosink_event:<dvbaudiosink0> TAG taglist, minimum-bitrate=(uint)128510;
0:00:05.070800108   846   0x681260 INFO            dvbvideosink gstdvbvideosink.c:658:video_write:<dvbvideosink0> VIDEO_EVENT 2
0:00:05.075825922   846 0x754b3c90 INFO            dvbaudiosink gstdvbaudiosink.c:735:gst_dvbaudiosink_event:<dvbaudiosink0> EVENT tag
0:00:05.077318663   846 0x754b3c90 INFO            dvbaudiosink gstdvbaudiosink.c:879:gst_dvbaudiosink_event:<dvbaudiosink0> TAG taglist, minimum-bitrate=(uint)120241;
0:00:05.076869737   846   0x681260 INFO            dvbvideosink gstdvbvideosink.c:658:video_write:<dvbvideosink0> VIDEO_EVENT 1
0:00:05.087304404   846   0x681260 INFO            dvbvideosink gstdvbvideosink.c:658:video_write:<dvbvideosink0> VIDEO_EVENT 16
New clock: GstSystemClock
0:00:05.118904922   846 0x754b3c90 INFO            dvbaudiosink gstdvbaudiosink.c:735:gst_dvbaudiosink_event:<dvbaudiosink0> EVENT tag
0:00:05.128586404   846 0x754b3c90 INFO            dvbaudiosink gstdvbaudiosink.c:879:gst_dvbaudiosink_event:<dvbaudiosink0> TAG taglist, maximum-bitrate=(uint)132644;
0:00:05.142882108   846 0x754b3c90 INFO            dvbaudiosink gstdvbaudiosink.c:735:gst_dvbaudiosink_event:<dvbaudiosink0> EVENT tag
0:00:05.146228959   846 0x754b3c90 INFO            dvbaudiosink gstdvbaudiosink.c:879:gst_dvbaudiosink_event:<dvbaudiosink0> TAG taglist, minimum-bitrate=(uint)116796;
0:00:05.241654330   846 0x754b3c90 INFO            dvbaudiosink gstdvbaudiosink.c:735:gst_dvbaudiosink_event:<dvbaudiosink0> EVENT tag
0:00:05.243445700   846 0x754b3c90 INFO            dvbaudiosink gstdvbaudiosink.c:879:gst_dvbaudiosink_event:<dvbaudiosink0> TAG taglist, minimum-bitrate=(uint)113695;
0:00:05.254499922   846 0x754b3c90 INFO            dvbaudiosink gstdvbaudiosink.c:735:gst_dvbaudiosink_event:<dvbaudiosink0> EVENT tag
0:00:05.260318922   846 0x754b3c90 INFO            dvbaudiosink gstdvbaudiosink.c:879:gst_dvbaudiosink_event:<dvbaudiosink0> TAG taglist, maximum-bitrate=(uint)134367;
0:00:05.317279441   846 0x754b3c90 INFO            dvbaudiosink gstdvbaudiosink.c:735:gst_dvbaudiosink_event:<dvbaudiosink0> EVENT tag
0:00:05.320859478   846 0x754b3c90 INFO            dvbaudiosink gstdvbaudiosink.c:879:gst_dvbaudiosink_event:<dvbaudiosink0> TAG taglist, minimum-bitrate=(uint)111283;
0:00:05.350022219   846 0x754b3c90 INFO            dvbaudiosink gstdvbaudiosink.c:735:gst_dvbaudiosink_event:<dvbaudiosink0> EVENT tag
0:00:05.351883589   846 0x754b3c90 INFO            dvbaudiosink gstdvbaudiosink.c:879:gst_dvbaudiosink_event:<dvbaudiosink0> TAG taglist, maximum-bitrate=(uint)137812;
0:00:05.496268515   846 0x754b3c90 INFO            dvbaudiosink gstdvbaudiosink.c:735:gst_dvbaudiosink_event:<dvbaudiosink0> EVENT tag
0:00:05.499235367   846 0x754b3c90 INFO            dvbaudiosink gstdvbaudiosink.c:879:gst_dvbaudiosink_event:<dvbaudiosink0> TAG taglist, maximum-bitrate=(uint)142635;
0:00:06.139703700   846 0x754b3c90 INFO            dvbaudiosink gstdvbaudiosink.c:735:gst_dvbaudiosink_event:<dvbaudiosink0> EVENT tag
0:00:06.144379996   846 0x754b3c90 INFO            dvbaudiosink gstdvbaudiosink.c:879:gst_dvbaudiosink_event:<dvbaudiosink0> TAG taglist, minimum-bitrate=(uint)110594;
0:00:06.160178774   846 0x754b3c90 INFO            dvbaudiosink gstdvbaudiosink.c:735:gst_dvbaudiosink_event:<dvbaudiosink0> EVENT tag
0:00:06.162860514   846 0x754b3c90 INFO            dvbaudiosink gstdvbaudiosink.c:879:gst_dvbaudiosink_event:<dvbaudiosink0> TAG taglist, maximum-bitrate=(uint)143669;
0:00:06.527447996   846 0x754b3c90 INFO            dvbaudiosink gstdvbaudiosink.c:735:gst_dvbaudiosink_event:<dvbaudiosink0> EVENT tag
0:00:06.529702551   846 0x754b3c90 INFO            dvbaudiosink gstdvbaudiosink.c:879:gst_dvbaudiosink_event:<dvbaudiosink0> TAG taglist, minimum-bitrate=(uint)108871;
Buffering, setting pipeline to PAUSED ...
0:00:06.642605329   846   0x503ec0 INFO            dvbaudiosink gstdvbaudiosink.c:1504:gst_dvbaudiosink_change_state:<dvbaudiosink0> GST_STATE_CHANGE_PLAYING_TO_PAUSED
0:00:06.715627773   846   0x503ec0 INFO            dvbvideosink gstdvbvideosink.c:1859:gst_dvbvideosink_change_state:<dvbvideosink0> GST_STATE_CHANGE_PLAYING_TO_PAUSED
Done buffering, setting pipeline to PLAYING ...
0:00:06.882623292   846   0x503ec0 INFO            dvbaudiosink gstdvbaudiosink.c:1482:gst_dvbaudiosink_change_state:<dvbaudiosink0> GST_STATE_CHANGE_PAUSED_TO_PLAYING
0:00:06.978328884   846   0x503ec0 INFO            dvbvideosink gstdvbvideosink.c:1846:gst_dvbvideosink_change_state:<dvbvideosink0> GST_STATE_CHANGE_PAUSED_TO_PLAYING
Buffering, setting pipeline to PAUSED ...
0:00:07.606575810   846   0x503ec0 INFO            dvbaudiosink gstdvbaudiosink.c:1504:gst_dvbaudiosink_change_state:<dvbaudiosink0> GST_STATE_CHANGE_PLAYING_TO_PAUSED
0:00:07.674646217   846   0x503ec0 INFO            dvbvideosink gstdvbvideosink.c:1859:gst_dvbvideosink_change_state:<dvbvideosink0> GST_STATE_CHANGE_PLAYING_TO_PAUSED
Done buffering, setting pipeline to PLAYING ...
0:00:07.712773995   846   0x503ec0 INFO            dvbaudiosink gstdvbaudiosink.c:1482:gst_dvbaudiosink_change_state:<dvbaudiosink0> GST_STATE_CHANGE_PAUSED_TO_PLAYING
0:00:07.790812847   846   0x503ec0 INFO            dvbvideosink gstdvbvideosink.c:1846:gst_dvbvideosink_change_state:<dvbvideosink0> GST_STATE_CHANGE_PAUSED_TO_PLAYING
Buffering, setting pipeline to PAUSED ...
0:00:08.425287143   846   0x503ec0 INFO            dvbaudiosink gstdvbaudiosink.c:1504:gst_dvbaudiosink_change_state:<dvbaudiosink0> GST_STATE_CHANGE_PLAYING_TO_PAUSED
0:00:08.506447143   846   0x503ec0 INFO            dvbvideosink gstdvbvideosink.c:1859:gst_dvbvideosink_change_state:<dvbvideosink0> GST_STATE_CHANGE_PLAYING_TO_PAUSED
Done buffering, setting pipeline to PLAYING ...
Buffering, setting pipeline to PAUSED ...
Done buffering, setting pipeline to PLAYING ...

Exactly the same last line saying it's playing, but it's frozen.

 

However, when I play from Enigma2, everything seems to be OK !

[OpenWebif] started on 80
<   568.941633> [eMainloop::processOneEvent] unhandled POLLERR/HUP/NVAL for fd 33(16)
[VLC] Checking for buildin servicets ...  no
[VLC] Checking for existing and usable servicets.so ...  No module named servicets
[VLC] Checking for usable gstreamer service ...  yes
[EMCMS] python-mutagen is not available: No module named mutagen.mp3
EMC: Next trashcan cleanup in 121 minutes
<   570.889139> [eServiceMP3] Buffering 18 percent done
<   570.895657> [eServiceMP3] Buffering 19 percent done
<   570.898155> [eServiceMP3] Buffering 20 percent done
<   570.902486> [eServiceMP3] Buffering 21 percent done
<   570.904775> [eServiceMP3] Buffering 22 percent done
<   570.909552> [eServiceMP3] Buffering 23 percent done
<   570.911873> [eServiceMP3] Buffering 24 percent done
<   570.916514> [eServiceMP3] Buffering 25 percent done
<   570.918807> [eServiceMP3] Buffering 26 percent done
<   570.923504> [eServiceMP3] Buffering 27 percent done
<   570.926196> [eServiceMP3] Buffering 28 percent done
<   570.931545> [eServiceMP3] Buffering 29 percent done
<   570.933841> [eServiceMP3] Buffering 30 percent done
<   570.938513> [eServiceMP3] Buffering 31 percent done
<   570.940815> [eServiceMP3] Buffering 32 percent done
<   570.945491> [eServiceMP3] Buffering 33 percent done
<   570.948752> [eServiceMP3] Buffering 34 percent done
<   570.951185> [eServiceMP3] Buffering 35 percent done
<   570.955503> [eServiceMP3] Buffering 36 percent done
<   570.957819> [eServiceMP3] Buffering 37 percent done
<   570.962485> [eServiceMP3] Buffering 38 percent done
<   570.964769> [eServiceMP3] Buffering 39 percent done
<   570.969551> [eServiceMP3] Buffering 40 percent done
<   570.971869> [eServiceMP3] Buffering 41 percent done
<   570.976476> [eServiceMP3] Buffering 42 percent done
<   570.978745> [eServiceMP3] Buffering 43 percent done
<   570.981151> [eServiceMP3] Buffering 44 percent done
<   570.985505> [eServiceMP3] Buffering 45 percent done
<   570.988706> [eServiceMP3] Buffering 46 percent done
<   570.993483> [eServiceMP3] Buffering 47 percent done
<   570.995798> [eServiceMP3] Buffering 48 percent done
<   571.000488> [eServiceMP3] Buffering 49 percent done
<   571.002793> [eServiceMP3] Buffering 50 percent done
<   571.008411> [eServiceMP3] Buffering 51 percent done
<   571.010703> [eServiceMP3] Buffering 52 percent done
<   571.015482> [eServiceMP3] Buffering 53 percent done
<   571.017833> [eServiceMP3] Buffering 54 percent done
<   571.022484> [eServiceMP3] Buffering 55 percent done
<   571.025114> [eServiceMP3] Buffering 56 percent done
<   571.030556> [eServiceMP3] Buffering 57 percent done
<   571.032867> [eServiceMP3] Buffering 58 percent done
<   571.037503> [eServiceMP3] Buffering 59 percent done
<   571.039795> [eServiceMP3] Buffering 60 percent done
<   571.044495> [eServiceMP3] Buffering 61 percent done
<   571.047812> [eServiceMP3] Buffering 62 percent done
<   571.052508> [eServiceMP3] Buffering 63 percent done
<   571.057494> [eServiceMP3] Buffering 64 percent done
<   571.059790> [eServiceMP3] Buffering 65 percent done
<   571.062193> [eServiceMP3] Buffering 66 percent done
<   571.067464> [eServiceMP3] Buffering 67 percent done
<   571.072500> [eServiceMP3] Buffering 68 percent done
<   571.074797> [eServiceMP3] Buffering 69 percent done
<   571.079483> [eServiceMP3] Buffering 70 percent done
<   571.081817> [eServiceMP3] Buffering 71 percent done
<   571.087411> [eServiceMP3] Buffering 72 percent done
<   571.089750> [eServiceMP3] Buffering 73 percent done
<   571.094490> [eServiceMP3] Buffering 74 percent done
<   571.096794> [eServiceMP3] Buffering 75 percent done
<   571.101481> [eServiceMP3] Buffering 76 percent done
<   571.103757> [eServiceMP3] Buffering 77 percent done
<   571.108643> [eServiceMP3] Buffering 78 percent done
<   571.110968> [eServiceMP3] Buffering 79 percent done
<   571.115495> [eServiceMP3] Buffering 80 percent done
<   571.117809> [eServiceMP3] Buffering 81 percent done
<   571.122477> [eServiceMP3] Buffering 82 percent done
<   571.124755> [eServiceMP3] Buffering 83 percent done
<   571.131077> [eServiceMP3] Buffering 84 percent done
<   571.133405> [eServiceMP3] Buffering 85 percent done
<   571.137494> [eServiceMP3] Buffering 86 percent done
<   571.139793> [eServiceMP3] Buffering 87 percent done
<   571.144468> [eServiceMP3] Buffering 88 percent done
<   571.147816> [eServiceMP3] Buffering 89 percent done
<   571.152500> [eServiceMP3] Buffering 90 percent done
<   571.157493> [eServiceMP3] Buffering 91 percent done
<   571.159816> [eServiceMP3] Buffering 92 percent done
<   571.164480> [eServiceMP3] Buffering 93 percent done
<   571.167701> [eServiceMP3] Buffering 94 percent done
<   571.172501> [eServiceMP3] Buffering 95 percent done
<   571.174790> [eServiceMP3] Buffering 96 percent done
<   571.177194> [eServiceMP3] Buffering 97 percent done
<   571.181515> [eServiceMP3] Buffering 98 percent done
<   571.183825> [eServiceMP3] Buffering 100 percent done
<   572.300883> [eServiceMP3] state transition READY -> PAUSED
<   572.321849> [eServiceMP3] loading cuesheet
<   572.322913> [eServiceMP3] cutfile not found!
<   572.349301> [eServiceMP3] async-done - 1 video, 1 audio, 0 subtitle
<   572.350500> [eServiceMP3] AUDIO STRUCT=audio/mpeg
<   572.351833> [eServiceMP3] audio stream=0 codec=MPEG-4 AAC language=und
<   573.171532> [eServiceMP3] state transition PAUSED -> PLAYING
EMC: [EMCMS] trashcan cleanup: no trashcan...
<   574.861978> [eServiceMP3] Buffering 9 percent done
<   574.879205> [eServiceMP3] Buffering 90 percent done

So to sum things up when trying to play the CNN hls stream.

 

gstreamer 1.5.90 (yesterdays git):

gst-launch-1.0 playbin: FROZEN

Enigma2: FROZEN

 

gstreamer 1.5.2:

gst-launch-1.0 playbin: FROZEN

Enigma2: Working perfectly (I've tried multiple times)

 

Since it freezes with gst-launch on both 1.5.2 and 1.5.90 I think it's simply a driver issue of this receiver Zgemma Star (which is unsupported here anyways).

So I doubt that sending in a bug-report would be useful for the gstreamer developers.

However I find it strange that Enigma2 plays the streams perfectly fine when built with gstreamer 1.5.2.

Edited by MastaG, 17 September 2015 - 22:09.

[mx3L]

@MastaG

It looks to be the same problem as here: http://forums.openpl...e-improvements/

When one of the sinks returning ASYNC state change when going to PAUSED. But I'm not sure, can you provide also "basesink:5" log?

 

If that's the problem, then this patch should fix it: https://github.com/m...990da56931b70a6

Edited by mx3L, 17 September 2015 - 22:25.

[MastaG]

Thank you mx3L

I did try the servicemp3 patch which improves paused/unpaused performance before but that didn't make a difference.

 

I'm now building with your patch 2 and 3 combined against chris' multibox dvbmediasink.

I've attached it here.

 

It's late now, so I'll try the image tomorrow

 

btw here's a basesink:5 log with the current image (1.5.2) and chris' sink (no patches yet): http://pastebin.com/TTLNtwTQ

Attached Files

•  0002-mx3l_mediasink.patch   3.36KB   26 downloads

Edited by MastaG, 17 September 2015 - 23:22.

[mx3L]

@MastaG

Thanks for the log, but I ment something like this:

gst-launch-1.0 --gst-debug=dvbaudiosink:4,dvbvideosink:4,basesink:6 playbin uri=http://wpc.C1A9.edgecastcdn.net/hls-live/20C1A9/cnn/ls_satlink/b_828.m3u8 flags=0x47

or you can run enigma2 this way and log will be created:

GST_DEBUG_FILE=/tmp/hls.log GST_DEBUG_NO_COLOR=1 GST_DEBUG=dvbvideosink:4,dvbaudiosink:4,basesink:6 enigma2.sh

3rd patch is not necessary, but it will do no harm.

[christophecvr]

@MastaG

 

Best to log is really run enigma2 gst-launch-1.0 is a nice tool but there are good handling routines into servicemp3.c done by athoik. For them to work ok they are required. With gst-launch they are not used the flags=0x47 helps but still not 100 % same.

 

Best use like mx3L told :

GST_DEBUG_FILE=/tmp/hls.log GST_DEBUG_NO_COLOR=1 GST_DEBUG=dvbvideosink:4,dvbaudiosink:4,basesink:6 enigma2.sh 3

The 3 behind will take all you're setiings like you're running enigma2 with init 3.

 

 

The asyn sync issue is already solved in master sink now.

Edited by christophecvr, 18 September 2015 - 06:46.

[christophecvr]

a small note the basesink:6 is most probably to heavy on a stb and just the debug setting will bug gstreamer (processors stb's are to slow).

[MastaG]

Ah thanks for explaining.
The async issue was indeed fixed in your master git.
So it was already part of my image last night when I was testing.
But that didn't fix the freezing.

However I haven't tried patch 2 from mx3L yet.
This one: https://github.com/m...990da56931b70a6
Which I attached in my previous post, it's not committed yet.
I'll test this tonight.


Also I noticed that logging with basesink:5 causes some lag which makes the hls streams work.


So I guess my receiver doesn't like the mediasink to do pause -> playing -> pause -> playing too fast.
Then it simply freezes in paused state.

The debugging delays it a bit so it picks up the playing state properly.

Just an uneducated guess.

[mx3L]

This is hard to debug, since as @christophecvr said basesink:5 has negative impact on performance, which changes conditions.

Can you try to create debug with just "GST_STATES:5"?

 

Let us now how you fare with 2. patch.

[MastaG]

Yes, your patch shows improvement.

So for the record, I'm still on gstreamer 1.5.2 with christophecvr's multibox sink and your patch 2 and 3 on top of it.

(the 0002-mx3l_mediasink.patch from a few posts back).

 

From enigma2 it's still playing perfectly fine (also without the patch as long as I'm using gstreamer 1.5.2).

 

From the playbin it will now constantly freeze and play for a few seconds.

So no permanent freezing anymore.

Why does the damn playbin behave so badly?

Pause, playing, pause, playiing etc...

It's like the buffer size is much smaller when playing from the playbin compared to E2...

 

So anyways here's the log from the playbin where it freezes (however it freezes much less with debugging enabled).

And also a log from from enigma2 where it's playing fine.

 

I think a small sleep somewhere in the code would fix it for me receiver

 

 

Attached Files

•  hls_enigma2.log.zip   353.99KB   8 downloads
•  hls_playbin.log.zip   490.64KB   3 downloads