<div dir="ltr"><div><u><b>Attached debug log snippets at the end: of the <span style="background-color:rgb(255,0,255)">7</span> segments, problem is seen at <span style="background-color:rgb(255,0,255)">7</span>. </b></u></div><div><br></div>I have the following configuration:<div><br></div><div>souphttp --> hlsdemux --> appsink</div><div><br></div><div>Pretty much given the manifest URI, this pipeline send the samples to app and application uses the signal (new sample) to put the data in buffer.</div><div><br></div><div>hlsdemux has the property connection-speed using which one can control the choice of variant below a bitrate. Initial value of this is default which means it can choose dynamically based on the current bitrate that is calculated at the end of a fragment download.</div><div><br></div><div>While this pipeline is running and application is collecting the samples, a configuration thread with the application, upon getting input, changes connection-speed to a certain number. This means if fragments are being downloaded at highest possible rate, now the next fragment should be rate limited to the new value. This is working. BUT after the changes incorporated on the datapath (after a fragment download), there's a freeze which varies from 4-7mins during which nothing happens (there's a WAIT) and after that it continues to finish it.</div><div><br></div><div>Any clues? Thanks in advance for your help!</div><div><br></div><div><b>Application:(Config thread)</b></div><div><font face="arial, sans-serif">With or without changing pipeline status setting below, same effect: </font></div><div><font face="arial, sans-serif"><br></font></div><div><font face="monospace">ret = gst_element_set_state(
pAppHlsCtx
->pipeline, GST_STATE_PAUSED);<br></font></div><div><font face="monospace">g_object_set(pAppHlsCtx->hlsDemux, "connection-speed", value, NULL);</font></div><div><font face="monospace">ret = gst_element_set_state(
pAppHlsCtx
->pipeline, GST_STATE_PLAYING);</font><br></div><div><br></div><div><b>DEBUG LOG: This is where it waits everytime when config changed:</b></div><div><br></div><div><u><b>Connection-speed changed by config in the middle of fragment download<span style="background-color:rgb(255,0,255)"> (1)</span></b></u></div><div><b><u><br></u></b><span style="background-color:rgb(255,255,0)">0:00:10.797018357</span> [336m25649 [00m 0x7f6564086630 [37mDEBUG [00m [00m adaptivedemux gstadaptivedemux.c:360:gst_adaptive_demux_set_property:<hlsdemux> [00m <span style="background-color:rgb(255,255,0)">Connection speed set to 200000</span><br>0:00:10.797027416 [336m25649 [00m 0x7f6564086630 [37mTRACE [00m [00m adaptivedemux gstadaptivedemux.c:370:gst_adaptive_demux_set_property: [00m Unlocking from thread 0x7f6564086630<br>0:00:10.797044828 [336m25649 [00m 0x7f6564086630 [37mTRACE [00m [00;01;31;44m GST_REFCOUNTING gstobject.c:237:gst_object_ref:<test-pipeline> [00m 0x10ce1f0 ref 1->2<br><span style="background-color:rgb(255,255,0)">0:00:10.797058900</span> [336m25649 [00m 0x7f6564086630 [33;01mLOG [00m [00;01;37;44m GST_PROPERTIES gstobject.c:472:gst_object_dispatch_properties_changed:<test-pipeline> [00m <span style="background-color:rgb(255,255,0)">deep notification from hlsdemux (connection-speed)</span><br></div><div>.....</div><div>..... <b><u>Fragment download by a thread completed<span style="background-color:rgb(255,0,255)"> (2)</span> </u></b></div><div><br><span style="background-color:rgb(255,255,0)">0:00:11.059384719</span> [336m25649 [00m 0x7f656c004370 [37mDEBUG [00m [00;43m GST_BUS gstbus.c:316:gst_bus_post:<bus3> [00m [msg 0x10d29c0] posting on bus element message: 0x10d29c0, time 99:99:99.999999999, seq-num 639, element 'hlsdemux', adaptive-streaming-statistics, manifest-uri=(string)<a href="http://devimages.apple.com.edgekey.net/iphone/samples/bipbop/bipbopall.m3u8">http://devimages.apple.com.edgekey.net/iphone/samples/bipbop/bipbopall.m3u8</a>, uri=(string)<a href="http://devimages.apple.com.edgekey.net/iphone/samples/bipbop/">http://devimages.apple.com.edgekey.net/iphone/samples/bipbop/</a><span style="background-color:rgb(0,255,255)">gear4/fileSequence17.ts</span>, fragment-start-time=(guint64)527087377757, fragment-stop-time=(guint64)527087838938936, fragment-size=(guint64)17170792, fragment-download-time=(guint64)428503249;<br><span style="background-color:rgb(255,255,0)">0:00:11.059396707</span> [336m25649 [00m 0x7f656c004370 [37mDEBUG [00m [00;43m GST_BUS gstbus.c:355:gst_bus_post:<bus3> [00m [msg 0x10d29c0] pushing on async queue<br></div><div></div><div>....</div><div>.... <u><b>New next fragment getting chosen as per the new connection-speed <span style="background-color:rgb(255,0,255)">(3</span>) </b></u></div><div><br><span style="background-color:rgb(255,255,0)">0:00:11.059704628</span> [336m25649 [00m 0x7f656c004370 [33;01mLOG [00m [00m adaptivedemux gstadaptivedemux.c:2240:gst_adaptive_demux_stream_update_current_bitrate:<hlsdemux> [00m Connection-speed is set to 200 kbps, using it<br>0:00:11.059719002 [336m25649 [00m 0x7f656c004370 [37mDEBUG [00m [00m hlsdemux gsthlsdemux.c:579:gst_hls_demux_set_current_variant:<hlsdemux> [00m Switching Variant. Copying over sequence 18 and sequence_pos 0:03:00.000000000<br>0:00:11.059731534 [336m25649 [00m 0x7f656c004370 [36mINFO [00m [00m hlsdemux gsthlsdemux.c:1597:gst_hls_demux_change_playlist:<hlsdemux> [00m <span style="background-color:rgb(255,255,0)">Client was on 737777bps, max allowed is 200000bps, switching to bitrate 200000bps</span><br><span style="background-color:rgb(255,255,0)">0:00:11.059746954 </span> [336m25649 [00m 0x7f656c004370 [37mDEBUG [00m [00m uridownloader gsturidownloader.c:562:gst_uri_downloader_fetch_uri_with_range:<uridownloader0> [00m Fetching URI <a href="http://devimages.apple.com.edgekey.net/iphone/samples/bipbop/">http://devimages.apple.com.edgekey.net/iphone/samples/bipbop/</a><span style="background-color:rgb(0,255,255)">gear1/prog_index.m3u8</span><br></div><div>.....</div><div>.....<u><b>Previous fragment download completed<span style="background-color:rgb(255,0,255)"> (4)</span> Not sure what is the difference between <span style="background-color:rgb(255,0,255)">(2)</span> and this<span style="background-color:rgb(255,0,255)"> (4)</span> that happens </b></u></div><div>..... <u><b> after the media playlist for new connection limit downloaded!!</b></u></div><div><br><span style="background-color:rgb(255,255,0)">0:00:11.360280538</span> [336m25649 [00m 0x7f655c0034a0 [33;01mLOG [00m [00m adaptivedemux gstadaptivedemux.c:3583:gst_adaptive_demux_stream_download_loop:<'':src_1> [00m download loop start<br>0:00:11.360289875 [336m25649 [00m 0x7f655c0034a0 [37mTRACE [00m [00m adaptivedemux gstadaptivedemux.c:3585:gst_adaptive_demux_stream_download_loop: [00m Locking from thread 0x7f655c0034a0<br><span style="background-color:rgb(255,255,0)">0:00:11.360310544</span> [336m25649 [00m 0x1026d40 [37mDEBUG [00m [00m adaptivedemux gstadaptivedemux.c:3220:gst_adaptive_demux_stream_download_uri:<hlsdemux:src_0> [00m Finished Waiting for fragment download: <a href="http://devimages.apple.com.edgekey.net/iphone/samples/bipbop/gear4/fileSequence17.ts">http://devimages.apple.com.edgekey.net/iphone/samples/bipbop/gear4/fileSequence17.ts</a><br></div><div>....</div><div>.... <u><b>Chose new fragment as per the changed parameter <span style="background-color:rgb(255,0,255)">(5)</span> </b></u></div><div><br>0:00:11.360624748 [336m25649 [00m 0x7f655c0034a0 [37mDEBUG [00m [00m hls m3u8.c:862:gst_m3u8_get_next_fragment: [00m Got fragment with sequence 18 (current sequence 18)<br><span style="background-color:rgb(255,255,0)">0:00:11.360636604</span> [336m25649 [00m 0x7f655c0034a0 [37mDEBUG [00m [00m hlsdemux gsthlsdemux.c:1109:gst_hls_demux_update_fragment_info:<hlsdemux> [00m Stream 0x7f655c661540 URI now <a href="http://devimages.apple.com.edgekey.net/iphone/samples/bipbop/">http://devimages.apple.com.edgekey.net/iphone/samples/bipbop/</a><span style="background-color:rgb(0,255,255)">gear1/fileSequence18.ts</span><br></div><div>....</div><div>....</div><div>....<u><b>Between (5) and now new Pad created as bitrate changed.. BUT WATCH THE FOLLOWING IN RED.. NOT SURE WHAT THIS TELLS <span style="background-color:rgb(255,0,255)">(6)</span></b></u></div><div><br><span style="background-color:rgb(255,255,0)">0:00:11.926670203</span> [336m25649 [00m 0x7f655c0035e0 [37mDEBUG [00m [00;01;35m GST_SCHEDULING gstpad.c:4324:gst_pad_chain_data_unchecked:<appsink1:sink> [00m calling chainfunction &gst_base_sink_chain with buffer buffer: 0x7f655c2c2900, pts 0:03:00.000000000, dts 99:99:99.999999999, dur 99:99:99.999999999, size 7569, offset 0, offset_end 7569, flags 0x4040<br>0:00:11.926697905 [336m25649 [00m 0x7f655c0035e0 [37mDEBUG [00m [00m basesink gstbasesink.c:3524:gst_base_sink_chain_unlocked:<appsink1> [00m got times start: 0:03:00.000000000, end: 99:99:99.999999999<br>0:00:11.926716591 [336m25649 [00m 0x7f655c0035e0 [37mDEBUG [00m [00m basesink gstbasesink.c:2112:gst_base_sink_get_sync_times:<appsink1> [00m got times start: 0:03:00.000000000, stop: 99:99:99.999999999, do_sync 1<br>0:00:11.926725903 [336m25649 [00m 0x7f655c0035e0 [37mDEBUG [00m [00;04m default gstsegment.c:737:gst_segment_to_running_time_full: [00m invalid position (-1)<br>0:00:11.926740393 [336m25649 [00m 0x7f655c0035e0 [37mDEBUG [00m [00m basesink gstbasesink.c:2694:gst_base_sink_do_sync:<appsink1> [00m reset rc_time to time 0:03:00.000000000<br>0:00:11.926756101 [336m25649 [00m 0x7f655c0035e0 [37mDEBUG [00m [00m basesink gstbasesink.c:2706:gst_base_sink_do_sync:<appsink1> [00m <span style="background-color:rgb(255,0,0)">possibly waiting for clock to reach 0:03:00.000000000, adjusted 0:03:00.000000000</span><br><font style="background-color:rgb(255,255,0)" color="#000000">0:00:11.926771291</font> [336m25649 [00m 0x7f655c0035e0 [33;01mLOG [00m [00m basesink gstbasesink.c:2283:gst_base_sink_wait_clock:<appsink1> [00m time 0:03:00.000000000, base_time 146:24:39.092172263<br></div><div>.....</div><div>..... <u><b>THIS IS WHERE BIG WAIT HAPPENS!! Goes with redmarked info in previous section!!<span style="background-color:rgb(255,0,255)">(7)</span></b></u></div><div>.....</div><div><span style="background-color:rgb(255,255,0)">0:00:11.926813256</span> [336m25649 [00m 0x7f655c0035e0 [37mDEBUG [00m [00;01;33m GST_CLOCK gstclock.c:557:gst_clock_id_wait:<GstSystemClock> [00m waiting on clock entry 0x10cb130<br>0:00:11.926827290 [336m25649 [00m 0x7f655c0035e0 [37mDEBUG [00m [00;01;33m GST_CLOCK gstclock.c:1092:gst_clock_get_internal_time:<GstSystemClock> [00m internal time 146:24:48.706546242<br>0:00:11.926846159 [336m25649 [00m 0x7f655c0035e0 [37mDEBUG [00m [00;01;33m GST_CLOCK gstclock.c:1137:gst_clock_get_time:<GstSystemClock> [00m adjusted time 146:24:48.706546242<br>0:00:11.926863177 [336m25649 [00m 0x7f655c0035e0 [37mDEBUG [00m [00;01;33m GST_CLOCK gstsystemclock.c:714:gst_system_clock_id_wait_jitter_unlocked: [00m entry 0x10cb130 time 146:27:39.092172263 now 146:24:48.706546242 diff (time-now) 170385626021<br><span style="background-color:rgb(255,255,0)">0:00:11.926876486 </span> [336m25649 [00m 0x7f655c0035e0 [37mDEBUG [00m [00m GST_POLL gstpoll.c:1414:gst_poll_wait: [00m 0x10268a0: timeout :0:02:50.385626021<br><span style="background-color:rgb(255,0,0)">0:03:02.328324076</span> [336m25649 [00m 0x7f655c0035e0 [37mDEBUG [00m [00;01;33m GST_CLOCK gstsystemclock.c:742:gst_system_clock_id_wait_jitter_unlocked: [00m entry 0x10cb130 unlocked, status 3, ret 0<br><span style="background-color:rgb(255,0,0)">0:03:02.328372880</span> [336m25649 [00m 0x7f655c0035e0 [37mDEBUG [00m [00;01;33m GST_CLOCK gstsystemclock.c:766:gst_system_clock_id_wait_jitter_unlocked: [00m entry 0x10cb130 unlocked after timeout<br><span style="background-color:rgb(255,0,0)">0:03:02.328393387</span> [336m25649 [00m 0x7f655c0035e0 [37mDEBUG [00m [00;01;33m GST_CLOCK gstclock.c:1092:gst_clock_get_internal_time:<GstSystemClock> [00m internal time 146:27:39.108108927<br></div><div><br></div><div><br></div><div><br></div></div>