Help!!! Pipe Stalling with No Error
Nicolas Dufresne
nicolas at ndufresne.ca
Fri May 29 01:23:00 UTC 2020
Le jeudi 28 mai 2020 à 13:21 +0000, Dass, Reena A Collins a écrit :
> I added a couple of queues but it did not help. And you are right it is a
> demuxer.
> I've added another picture with the additional queues which has the levels
> etc. if that helps.
As that graph is from a pipleine in NULL state, it does not bring much
information to the issue. Maybe you could share a trace with
GST_DEBUG="*SCHED*:5", this way we could see the buffer flowing through each
elements, and see which sink does not receices any data.
Another useful point of information is a backtrace of all threads at the moment
of a stall. Studying were each threads are block can greatly improve the
understanding of the problem. If you cannot share that I would understand, so
let's hope this suggestion can help you.
>
>
> -----Original Message-----
> From: gstreamer-devel [mailto:gstreamer-devel-bounces at lists.freedesktop.org]
> On Behalf Of Nicolas Dufresne
> Sent: Wednesday, May 27, 2020 8:59 PM
> To: Discussion of the development of and with GStreamer
> Subject: [External] Re: Help!!! Pipe Stalling with No Error
>
> Le mercredi 27 mai 2020 à 18:45 +0000, Dass, Reena A Collins a
> écrit :
> > I have pipeline with a muxer, it stalls before running the BaseSink on
> > either
> > sub-pipe.
> > I’ve attached the picture of the chain and section of tje log is below.
>
> We might have a different definition of muxer, from your graph, your "custom
> muxer" receives 1 stream and produces 2, that would be called a demuxer in
> GStreamer.
>
> You have erased some information in the graph, notably the queue level, the
> caps, and pretty much every possible hints that may help finding the root
> cause.
> Maybe your queues are not large enough for the shift between streams in your
> custom muxed format ? It's hard to guess, as there is so many unknown and
> custom
> element in there.
>
> >
> > 0:00:09.627700605[331m12198[00m 0x193d6d0 [37mDEBUG [00m [00m
> > basetransform
> > gstbasetransform.c:2359:gst_base_transform_chain:<MultiSame>[00m
> > we have a pending DISCONT
> > 0:00:09.627848840[331m12198[00m 0x193d6d0[37mDEBUG [00m[00m
> > basetransform
> > gstbasetransform.c:2361:gst_base_transform_chain:<MultiSame>[00m
> > marking DISCONT on output buffer
> > 0:00:09.627975932[331m12198[00m 0x193d6d0[37mDEBUG [00m[00;01;35m
> > GST_SCHEDULING
> > gstpad.c:4084:gst_pad_chain_data_unchecked:<sinkMultiSame:sink>[00m calling
> > chainfunction &gst_base_sink_chain with buffer buffer: 0x7ffdfc003340, pts
> > 99:99:99.999999999, dts 99:99:99.999999999, dur 99:99:99.999999999, size 8,
> > offset none, offset_end none, flags 0x40
> > 0:00:09.628112604[331m12198[00m 0x193d6d0[37mDEBUG [00m[00m
> > basesink gstbasesink.c:3401:gst_base_sink_chain_unlocked:<sinkMultiSame>[00m
> > got times start: 99:99:99.999999999, end: 99:99:99.999999999
> > 0:00:09.628246338[331m12198[00m 0x193d6d0[37mDEBUG [00m[00m
> > basesink gstbasesink.c:1950:gst_base_sink_get_sync_times:<sinkMultiSame>[00m
> > got times start: 99:99:99.999999999, stop: 99:99:99.999999999, do_sync 0
> > 0:00:09.628381580[331m12198[00m 0x193d6d0[37mDEBUG
> > [00m[00;04m default
> > gstsegment.c:494:gst_segment_to_running_time_full:[00m invalid position (-1)
> > 0:00:09.628500510[331m12198[00m 0x193d6d0[37mDEBUG
> > [00m[00;04m default
> > gstsegment.c:494:gst_segment_to_running_time_full:[00m invalid position (-1)
> > 0:00:09.628623187[331m12198[00m 0x193d6d0[37mDEBUG [00m[00m
> > basesink gstbasesink.c:2249:gst_base_sink_do_preroll:<sinkMultiSame>[00m
> > prerolling object 0x7ffdfc003340
> > 0:00:09.628769760[331m12198[00m 0x193d6d0[37mDEBUG [00m[00m
> > basesink
> > gstbasesink.c:946:gst_base_sink_set_last_buffer_unlocked:<sinkMultiSame>[00m
> > setting last buffer to 0x7ffdfc003340
> > 0:00:09.628925395[331m12198[00m 0x193d6d0[37mDEBUG [00m[00m
> > basesink gstbasesink.c:2272:gst_base_sink_do_preroll:<sinkMultiSame>[00m
> > preroll buffer 99:99:99.999999999
> > 0:00:09.629064935[331m12198[00m 0x193d6d0[37mDEBUG [00m[00m
> > basesink gstbasesink.c:1503:gst_base_sink_commit_state:<sinkMultiSame>[00m
> > commiting state to PAUSED
> > 0:00:09.629205967[331m12198[00m 0x193d6d0[37mDEBUG [00m[00m
> > basesink gstbasesink.c:1528:gst_base_sink_commit_state:<sinkMultiSame>[00m
> > posting PAUSED state change message
> > 0:00:09.629334473[331m12198[00m 0x193d6d0[33;01mLOG
> > [00m[00;01;37;41m GST_MESSAGE
> > gstmessage.c:292:gst_message_new_custom:[00m source sinkMultiSame: creating
> > new message 0x7ffdfc002080 state-changed
> > 0:00:09.629464272[331m12198[00m 0x193d6d0[37mDEBUG
> > [00m[00;43m GST_BUS gstbus.c:309:gst_bus_post:<bus0>[00m [msg
> > 0x7ffdfc002080] posting on bus state-changed message: 0x7ffdfc002080, time
> > 99:99:99.999999999, seq-num 154, element 'sinkMultiSame',
> > GstMessageStateChanged, old-state=(GstState)GST_STATE_READY, new-
> > state=(GstState)GST_STATE_PAUSED, pending-
> > state=(GstState)GST_STATE_VOID_PENDING;
> > 0:00:09.629616527[331m12198[00m 0x193d6d0[37mDEBUG
> > [00m[00;01m bin
> > gstbin.c:3461:gst_bin_handle_message_func:<Pipeline>[00m [msg
> > 0x7ffdfc002080]
> > handling child sinkMultiSame message of type state-changed
> > 0:00:09.629746812[331m12198[00m 0x193d6d0[37mDEBUG
> > [00m[00;01m bin
> > gstbin.c:3796:gst_bin_handle_message_func:<Pipeline>[00m posting message
> > upward
> > 0:00:09.629870025[331m12198[00m 0x193d6d0[37mDEBUG
> > [00m[00;43m GST_BUS gstbus.c:309:gst_bus_post:<bus1>[00m [msg
> > 0x7ffdfc002080] posting on bus state-changed message: 0x7ffdfc002080, time
> > 99:99:99.999999999, seq-num 154, element 'sinkMultiSame',
> > GstMessageStateChanged, old-state=(GstState)GST_STATE_READY, new-
> > state=(GstState)GST_STATE_PAUSED, pending-
> > state=(GstState)GST_STATE_VOID_PENDING;
> > 0:00:09.630013713[331m12198[00m 0x193d6d0[37mDEBUG
> > [00m[00;43m GST_BUS gstbus.c:348:gst_bus_post:<bus1>[00m [msg
> > 0x7ffdfc002080] pushing on async queue
> > 0:00:09.630134542[331m12198[00m 0x193d6d0[33;01mLOG [00m[00m
> >
> > GST_POLL gstpoll.c:186:raise_wakeup:[00m 0x193d2d0: raise
> > 0:00:09.630278210[331m12198[00m 0x1941400[36mINFO
> > [00m[00;43m GST_BUS
> > gstbus.c:565:gst_bus_timed_pop_filtered:<bus1>[00m we got woken up, recheck
> > for message
> > 0:00:09.630401173[331m12198[00m 0x1941400[33;01mLOG
> > [00m[00;43m GST_BUS
> > gstbus.c:513:gst_bus_timed_pop_filtered:<bus1>[00m have 1 messages
> > 0:00:09.630513936[331m12198[00m 0x1941400[33;01mLOG [00m[00m
> >
> > GST_POLL gstpoll.c:201:release_wakeup:[00m 0x193d2d0: release
> > 0:00:09.630657366[331m12198[00m 0x1941400[37mDEBUG
> > [00m[00;43m GST_BUS
> > gstbus.c:521:gst_bus_timed_pop_filtered:<bus1>[00m got message
> > 0x7ffdfc002080,
> > state-changed from sinkMultiSame, type mask is 67
> > 0:00:09.630829835[331m12198[00m 0x1941400[33;01mLOG
> > [00m[00;43m GST_BUS
> > gstbus.c:513:gst_bus_timed_pop_filtered:<bus1>[00m have 0 messages
> > 0:00:09.630990372[331m12198[00m 0x1941400[37mDEBUG [00m[00m
> > GST_POLL gstpoll.c:1195:gst_poll_wait:[00m 0x193d2d0: timeout
> > :99:99:99.999999999
> > 0:00:09.630312767[331m12198[00m 0x193d6d0[37mDEBUG
> > [00m[00;43m GST_BUS gstbus.c:351:gst_bus_post:<bus1>[00m [msg
> > 0x7ffdfc002080] pushed on async queue
> > 0:00:09.631230709[331m12198[00m 0x193d6d0[33;01mLOG
> > [00m[00;01;37;41m GST_MESSAGE
> > gstmessage.c:199:_gst_message_free:[00m
> > finalize message 0x7ffdfc002080, state-changed from sinkMultiSame
> > 0:00:09.631372442[331m12198[00m 0x193d6d0[37mDEBUG
> > [00m[00;43m GST_BUS gstbus.c:344:gst_bus_post:<bus0>[00m [msg
> > 0x7ffdfc002080] dropped
> > 0:00:09.631508238[331m12198[00m 0x193d6d0[37mDEBUG [00m[00m
> > basesink gstbasesink.c:1534:gst_base_sink_commit_state:<sinkMultiSame>[00m
> > posting async-done message
> > 0:00:09.631654022[331m12198[00m 0x193d6d0[33;01mLOG
> > [00m[00;01;37;41m GST_MESSAGE
> > gstmessage.c:292:gst_message_new_custom:[00m source sinkMultiSame: creating
> > new message 0x7ffdfc002100 async-done
> > 0:00:09.631798702[331m12198[00m 0x193d6d0[37mDEBUG
> > [00m[00;43m GST_BUS gstbus.c:309:gst_bus_post:<bus0>[00m [msg
> > 0x7ffdfc002100] posting on bus async-done message: 0x7ffdfc002100, time
> > 99:99:99.999999999, seq-num 155, element 'sinkMultiSame',
> > GstMessageAsyncDone,
> > running-time=(guint64)18446744073709551615;
> > 0:00:09.631949644[331m12198[00m 0x193d6d0[37mDEBUG
> > [00m[00;01m bin
> > gstbin.c:3461:gst_bin_handle_message_func:<Pipeline>[00m [msg
> > 0x7ffdfc002100]
> > handling child sinkMultiSame message of type async-done
> > 0:00:09.632087116[331m12198[00m 0x193d6d0[37mDEBUG
> > [00m[00;01m bin
> > gstbin.c:3682:gst_bin_handle_message_func:<Pipeline>[00m ASYNC_DONE message
> > 0x7ffdfc002100, sinkMultiSame
> > 0:00:09.632213858[331m12198[00m 0x193d6d0[33;01mLOG
> > [00m[00;01m bin gstbin.c:861:message_check:[00m looking at
> > message 0x19f44a0: 0
> > 0:00:09.632342045[331m12198[00m 0x193d6d0[33;01mLOG
> > [00m[00;01m bin gstbin.c:861:message_check:[00m looking at
> > message 0x19f4420: 1
> > 0:00:09.632473790[331m12198[00m 0x193d6d0[37mDEBUG
> > [00m[00;01m bin gstbin.c:881:find_message:<Pipeline>[00m we
> > found a message 0x19f4420 from sinkMultiSame matching types 00100000
> > 0:00:09.632604942[331m12198[00m 0x193d6d0[37mDEBUG
> > [00m[00;01m bin
> > gstbin.c:922:bin_replace_message:<Pipeline>[00m replace old message async-
> > start from sinkMultiSame with async-done message
> > 0:00:09.632726992[331m12198[00m 0x193d6d0[33;01mLOG
> > [00m[00;01;37;41m GST_MESSAGE
> > gstmessage.c:199:_gst_message_free:[00m
> > finalize message 0x19f4420, async-start from sinkMultiSame
> > 0:00:09.632848827[331m12198[00m 0x193d6d0[33;01mLOG
> > [00m[00;01m bin gstbin.c:861:message_check:[00m looking at
> > message 0x19f44a0: 1
> > 0:00:09.632966023[331m12198[00m 0x193d6d0[37mDEBUG
> > [00m[00;01m bin gstbin.c:881:find_message:<Pipeline>[00m we
> > found a message 0x19f44a0 from sinkSingle matching types 00100000
> > 0:00:09.633094291[331m12198[00m 0x193d6d0[37mDEBUG
> > [00m[00;01m bin
> > gstbin.c:3709:gst_bin_handle_message_func:<Pipeline>[00m there are more
> > async
> > elements pending
> > 0:00:09.633221186[331m12198[00m 0x193d6d0[37mDEBUG
> > [00m[00;43m GST_BUS gstbus.c:344:gst_bus_post:<bus0>[00m [msg
> > 0x7ffdfc002100] dropped
> > 0:00:09.633341421[331m12198[00m 0x193d6d0[37mDEBUG [00m[00m
> > basesink gstbasesink.c:2202:gst_base_sink_wait_preroll:<sinkMultiSame>[00m
> > waiting in preroll for flush or PLAYING
> >
> >
> > _______________________________________________
> > gstreamer-devel mailing list
> > gstreamer-devel at lists.freedesktop.org
> > https://urldefense.proofpoint.com/v2/url?u=https-3A__lists.freedesktop.org_mailman_listinfo_gstreamer-2Ddevel&d=DwIGaQ&c=ilBQI1lupc9Y65XwNblLtw&r=HQWJANUP83Z9FphYCG_LvTtNzX_hmziQ8C-qpehNFEA&m=whUcNzSKeh3eBkPmFW5gGKehVDdiGEVoysjmriXLGvo&s=MGHOKlRVPBBCszvXWXpbb5XIAGhbhhMlpB15kCOPuSI&e=
>
> _______________________________________________
> gstreamer-devel mailing list
> gstreamer-devel at lists.freedesktop.org
> https://urldefense.proofpoint.com/v2/url?u=https-3A__lists.freedesktop.org_mailman_listinfo_gstreamer-2Ddevel&d=DwIGaQ&c=ilBQI1lupc9Y65XwNblLtw&r=HQWJANUP83Z9FphYCG_LvTtNzX_hmziQ8C-qpehNFEA&m=whUcNzSKeh3eBkPmFW5gGKehVDdiGEVoysjmriXLGvo&s=MGHOKlRVPBBCszvXWXpbb5XIAGhbhhMlpB15kCOPuSI&e=
> _______________________________________________
> gstreamer-devel mailing list
> gstreamer-devel at lists.freedesktop.org
> https://lists.freedesktop.org/mailman/listinfo/gstreamer-devel
More information about the gstreamer-devel
mailing list