Unexplained freeze/hang from gst-omx omxh264enc on Raspberry Pi 3
Locked
Unexplained freeze/hang from gst-omx omxh264enc on Raspberry Pi 3
 
|
Hi all,
I am having some strange behaviour from gst-omx and the omxh264dec/omxh264enc elements that I am trying to get to the bottom of, the pipeline seems to hang at random points and I am trying to get to the bottom of why. I have recorded an MPEG transport stream containing h264 video that originates from DVB-T2, and am trying to transcode this with an element that has the effect of “decodebin ! encodebin”. The stream is demuxed and decoded with omxh264dec, and then reencoded with omxh264enc and remuxed before being written to an HLS stream. My problem is that each time this recorded MPEG transport stream is transcoded, the pipeline freezes/hangs at a different point in time. I would expect the file to freeze/hang in the same place, but it doesn’t do so. When it freezes the pipeline, omxh264enc says the following and then goes silent: 0:05:26.921029963 2774 0x73101d50 DEBUG omxvideoenc gstomxvideoenc.c:1692:gst_omx_video_enc_drain:<omxh264enc-omxh264enc0> Draining component 0:05:26.921240325 2774 0x73101d50 DEBUG omxvideoenc gstomxvideoenc.c:1738:gst_omx_video_enc_drain:<omxh264enc-omxh264enc0> Waiting until component is drained 0:05:26.922070629 2774 0x75714ac0 DEBUG omxvideodec gstomxvideodec.c:2178:gst_omx_video_dec_handle_frame:<omxh264dec-omxh264dec0> Handling frame 0:05:26.924129253 2774 0x73145400 DEBUG omxvideoenc gstomxvideoenc.c:753:gst_omx_video_enc_loop:<omxh264enc-omxh264enc0> Handling buffer: 0x00000480 0 0:05:26.924239825 2774 0x75714ac0 DEBUG omxvideodec gstomxvideodec.c:2178:gst_omx_video_dec_handle_frame:<omxh264dec-omxh264dec0> Handling frame 0:05:26.924242950 2774 0x73145400 DEBUG omxvideoenc gstomxvideoenc.c:762:gst_omx_video_enc_loop:<omxh264enc-omxh264enc0> Finished frame: ok 0:05:26.924531385 2774 0x73145400 DEBUG omxvideoenc gstomxvideoenc.c:770:gst_omx_video_enc_loop:<omxh264enc-omxh264enc0> Read frame from component 0:05:26.924573780 2774 0x73145400 DEBUG omxvideoenc gstomxvideoenc.c:753:gst_omx_video_enc_loop:<omxh264enc-omxh264enc0> Handling buffer: 0x00000490 0 0:05:26.924627790 2774 0x73145400 DEBUG omxvideoenc gstomxvideoenc.c:762:gst_omx_video_enc_loop:<omxh264enc-omxh264enc0> Finished frame: ok 0:05:26.924861589 2774 0x73145400 DEBUG omxvideoenc gstomxvideoenc.c:770:gst_omx_video_enc_loop:<omxh264enc-omxh264enc0> Read frame from component 0:05:26.924899402 2774 0x73145400 DEBUG omxvideoenc gstomxvideoenc.c:753:gst_omx_video_enc_loop:<omxh264enc-omxh264enc0> Handling buffer: 0x00000430 1482599921 0:05:26.924961536 2774 0x73145400 DEBUG omxvideoenc gstomxvideoenc.c:586:gst_omx_video_enc_handle_output_frame:<omxh264enc-omxh264enc0> Handling output data 0:05:26.925675123 2774 0x73145400 DEBUG omxvideoenc gstomxvideoenc.c:762:gst_omx_video_enc_loop:<omxh264enc-omxh264enc0> Finished frame: ok 0:05:26.926104754 2774 0x73145400 DEBUG omxvideoenc gstomxvideoenc.c:770:gst_omx_video_enc_loop:<omxh264enc-omxh264enc0> Read frame from component 0:05:26.926179857 2774 0x73145400 DEBUG omxvideoenc gstomxvideoenc.c:753:gst_omx_video_enc_loop:<omxh264enc-omxh264enc0> Handling buffer: 0x00000001 1482639921 0:05:26.926242565 2774 0x73145400 DEBUG omxvideoenc gstomxvideoenc.c:762:gst_omx_video_enc_loop:<omxh264enc-omxh264enc0> Finished frame: ok 0:05:26.926448604 2774 0x73145400 DEBUG omxvideoenc gstomxvideoenc.c:770:gst_omx_video_enc_loop:<omxh264enc-omxh264enc0> Read frame from component 0:05:26.926489698 2774 0x73145400 DEBUG omxvideoenc gstomxvideoenc.c:810:gst_omx_video_enc_loop:<omxh264enc-omxh264enc0> Drained 0:05:26.926540010 2774 0x73101d50 DEBUG omxvideoenc gstomxvideoenc.c:1740:gst_omx_video_enc_drain:<omxh264enc-omxh264enc0> Drained component omxh264dec keeps running, until eventually, sometimes within a second, sometimes many seconds later, omxh264dec also freezes and goes silent as follows: 0:06:05.580576707 2581 0x75614ac0 DEBUG omxvideodec gstomxvideodec.c:2178:gst_omx_video_dec_handle_frame:<omxh264dec-omxh264dec0> Handling frame 0:06:05.583004391 2581 0x75614ac0 DEBUG omxvideodec gstomxvideodec.c:2178:gst_omx_video_dec_handle_frame:<omxh264dec-omxh264dec0> Handling frame 0:06:05.585423220 2581 0x75614ac0 DEBUG omxvideodec gstomxvideodec.c:2178:gst_omx_video_dec_handle_frame:<omxh264dec-omxh264dec0> Handling frame 0:06:05.587669864 2581 0x75614ac0 DEBUG omxvideodec gstomxvideodec.c:2178:gst_omx_video_dec_handle_frame:<omxh264dec-omxh264dec0> Handling frame 0:06:05.591000038 2581 0x75614ac0 DEBUG omxvideodec gstomxvideodec.c:2178:gst_omx_video_dec_handle_frame:<omxh264dec-omxh264dec0> Handling frame 0:06:05.591114776 2581 0x75614ac0 DEBUG omxvideodec gstomxvideodec.c:2185:gst_omx_video_dec_handle_frame:<omxh264dec-omxh264dec0> Starting task 0:06:05.591252691 2581 0x74d018f0 DEBUG omxvideodec gstomxvideodec.c:1570:gst_omx_video_dec_loop:<omxh264dec-omxh264dec0> Component signalled EOS 0:06:05.591313316 2581 0x74d018f0 DEBUG omxvideodec gstomxvideodec.c:1590:gst_omx_video_dec_loop:<omxh264dec-omxh264dec0> EOS 0:06:05.605895926 2581 0x75614ac0 DEBUG omxvideodec gstomxvideodec.c:2178:gst_omx_video_dec_handle_frame:<omxh264dec-omxh264dec0> Handling frame 0:06:05.606009936 2581 0x75614ac0 DEBUG omxvideodec gstomxvideodec.c:2185:gst_omx_video_dec_handle_frame:<omxh264dec-omxh264dec0> Starting task 0:06:05.606143997 2581 0x74d018f0 DEBUG omxvideodec gstomxvideodec.c:1570:gst_omx_video_dec_loop:<omxh264dec-omxh264dec0> Component signalled EOS 0:06:05.606203319 2581 0x74d018f0 DEBUG omxvideodec gstomxvideodec.c:1590:gst_omx_video_dec_loop:<omxh264dec-omxh264dec0> EOS 0:06:05.606916541 2581 0x75614ac0 DEBUG omxvideodec gstomxvideodec.c:2178:gst_omx_video_dec_handle_frame:<omxh264dec-omxh264dec0> Handling frame 0:06:05.609172247 2581 0x75614ac0 DEBUG omxvideodec gstomxvideodec.c:2457:gst_omx_video_dec_drain:<omxh264dec-omxh264dec0> Draining component 0:06:05.609289433 2581 0x75614ac0 DEBUG omxvideodec gstomxvideodec.c:2462:gst_omx_video_dec_drain:<omxh264dec-omxh264dec0> Component not started yet I have a number of questions: - Has anyone encountered inconsistent pipeline freezes with omxh264enc? - What does "Draining component” do? It appears to be called from gst_omx_video_enc_finish(), but I cannot figure out why finish is being called on the encoder or what triggered it. - Are there any known bugs in omxh264enc that would cause it to stop encoding for any reason (as opposed to being temporarily degraded but still running). Does anyone have a suggestion on what to try next? Regards, Graham — _______________________________________________ gstreamer-devel mailing list [hidden email] https://lists.freedesktop.org/mailman/listinfo/gstreamer-devel |
smime.p7s (4K)
Re: Unexplained freeze/hang from gst-omx omxh264enc on Raspberry Pi 3
|
|
On 15 Nov 2016, at 3:34 AM, Graham Leggett <[hidden email]> wrote:
> I am having some strange behaviour from gst-omx and the omxh264dec/omxh264enc elements that I am trying to get to the bottom of, the pipeline seems to hang at random points and I am trying to get to the bottom of why. > > I have recorded an MPEG transport stream containing h264 video that originates from DVB-T2, and am trying to transcode this with an element that has the effect of “decodebin ! encodebin”. The stream is demuxed and decoded with omxh264dec, and then reencoded with omxh264enc and remuxed before being written to an HLS stream. > > My problem is that each time this recorded MPEG transport stream is transcoded, the pipeline freezes/hangs at a different point in time. I would expect the file to freeze/hang in the same place, but it doesn’t do so. > > When it freezes the pipeline, omxh264enc says the following and then goes silent: Looking closer at the decoder part of the pipeline, I see frames being received by omxvideodec, decoded successfully and then pushed downstream like so: 0:01:35.176680217 14697 0x74301db0 DEBUG videodecoder gstvideodecoder.c:2654:gst_video_decoder_prepare_finish_frame:<omxh264dec-omxh264dec0> sync timestamp 0:07:15.432708481 diff -0:07:15.200555555 0:01:35.177353593 14697 0x74301db0 DEBUG videodecoder gstvideodecoder.c:3174:gst_video_decoder_clip_and_push_buf:<omxh264dec-omxh264dec0> pushing buffer 0x6c288550 of size 470016, PTS 0:07:15.432708481, dur 0:00:00.040000000 0:01:35.177826764 14697 0x74301db0 DEBUG omxvideodec gstomxvideodec.c:1506:gst_omx_video_dec_loop:<omxh264dec-omxh264dec0> Read frame from component 0:01:35.177896190 14697 0x74301db0 DEBUG omxvideodec gstomxvideodec.c:1508:gst_omx_video_dec_loop:<omxh264dec-omxh264dec0> Finished frame: ok 0:01:35.184288346 14697 0x74301db0 DEBUG omxvideodec gstomxvideodec.c:1370:gst_omx_video_dec_loop:<omxh264dec-omxh264dec0> Handling buffer: 0x00030010 435472708 0:01:35.184847193 14697 0x74301db0 DEBUG videodecoder gstvideodecoder.c:2654:gst_video_decoder_prepare_finish_frame:<omxh264dec-omxh264dec0> sync timestamp 0:07:15.472708481 diff -0:07:15.240555555 0:01:35.185655619 14697 0x74301db0 DEBUG videodecoder gstvideodecoder.c:3174:gst_video_decoder_clip_and_push_buf:<omxh264dec-omxh264dec0> pushing buffer 0x6c2885f0 of size 470016, PTS 0:07:15.472708481, dur 0:00:00.040000000 0:01:35.186402953 14697 0x74301db0 DEBUG omxvideodec gstomxvideodec.c:1506:gst_omx_video_dec_loop:<omxh264dec-omxh264dec0> Read frame from component 0:01:35.186516962 14697 0x74301db0 DEBUG omxvideodec gstomxvideodec.c:1508:gst_omx_video_dec_loop:<omxh264dec-omxh264dec0> Finished frame: ok 0:01:35.195746841 14697 0x74301db0 DEBUG omxvideodec gstomxvideodec.c:1370:gst_omx_video_dec_loop:<omxh264dec-omxh264dec0> Handling buffer: 0x00030010 435792708 0:01:35.196601882 14697 0x74301db0 DEBUG videodecoder gstvideodecoder.c:2654:gst_video_decoder_prepare_finish_frame:<omxh264dec-omxh264dec0> sync timestamp 0:07:15.792708481 diff -0:07:15.560555555 0:01:35.197258852 14697 0x74301db0 DEBUG videodecoder gstvideodecoder.c:3174:gst_video_decoder_clip_and_push_buf:<omxh264dec-omxh264dec0> pushing buffer 0x6c288690 of size 470016, PTS 0:07:15.792708481, dur 0:00:00.040000000 0:01:35.197735357 14697 0x74301db0 DEBUG omxvideodec gstomxvideodec.c:1506:gst_omx_video_dec_loop:<omxh264dec-omxh264dec0> Read frame from component 0:01:35.197983166 14697 0x74301db0 DEBUG omxvideodec gstomxvideodec.c:1508:gst_omx_video_dec_loop:<omxh264dec-omxh264dec0> Finished frame: ok 0:01:35.200984064 14697 0x74301db0 DEBUG omxvideodec gstomxvideodec.c:1370:gst_omx_video_dec_loop:<omxh264dec-omxh264dec0> Handling buffer: 0x00000001 435832708 Then suddenly, omxvideodec stops accepted frames, but carries on sending frames as the decoder buffer is emptied as follows: 0:01:35.201549213 14697 0x74301db0 DEBUG videodecoder gstvideodecoder.c:2703:gst_video_decoder_prepare_finish_frame:<omxh264dec-omxh264dec0> no valid PTS, using oldest DTS 0:07:14.952708481 0:01:35.202174569 14697 0x74301db0 WARN videodecoder gstvideodecoder.c:2767:gst_video_decoder_prepare_finish_frame:<omxh264dec-omxh264dec0> decreasing timestamp (0:07:14.952708481 < 0:07:15.792708481) 0:01:35.202333421 14697 0x74301db0 DEBUG videodecoder gstvideodecoder.c:2847:gst_video_decoder_drop_frame:<omxh264dec-omxh264dec0> dropping frame 0:07:15.792708481 0:01:35.203420490 14697 0x74301db0 DEBUG omxvideodec gstomxvideodec.c:1506:gst_omx_video_dec_loop:<omxh264dec-omxh264dec0> Read frame from component 0:01:35.203530749 14697 0x74301db0 DEBUG omxvideodec gstomxvideodec.c:1508:gst_omx_video_dec_loop:<omxh264dec-omxh264dec0> Finished frame: ok 0:01:35.240920831 14697 0x74301db0 DEBUG omxvideodec gstomxvideodec.c:1564:gst_omx_video_dec_loop:<omxh264dec-omxh264dec0> Drained 0:01:35.241111505 14697 0x75713bb0 DEBUG omxvideodec gstomxvideodec.c:2517:gst_omx_video_dec_drain:<omxh264dec-omxh264dec0> Drained component The omxvideodec codec receives an GST_EVENT_GAP event, not sure yet from where. The omxvideoenc element stops accepting frames, not sure why, and so omxvideodec seems to drop all remaining frames. 0:01:35.241288326 14697 0x75713bb0 DEBUG videodecoder gstvideodecoder.c:1220:gst_video_decoder_sink_event_default:<omxh264dec-omxh264dec0> Pushing all pending serialized events before the gap 0:01:35.241400043 14697 0x75713bb0 DEBUG videodecoder gstvideodecoder.c:869:gst_video_decoder_push_event:<omxh264dec-omxh264dec0> pushing event gap 0:01:35.242264980 14697 0x75713bb0 DEBUG videodecoder gstvideodecoder.c:3381:gst_video_decoder_decode_frame:<omxh264dec-omxh264dec0> decoder frame list getting long: 17 frames,possible internal leaking? progressreport0 (00:01:35): 85464800 / 91982760 bytes (92.9 %) 0:01:35.252898434 14697 0x75713bb0 DEBUG omxvideodec gstomxvideodec.c:2178:gst_omx_video_dec_handle_frame:<omxh264dec-omxh264dec0> Handling frame 0:01:35.253051349 14697 0x75713bb0 DEBUG videodecoder gstvideodecoder.c:2654:gst_video_decoder_prepare_finish_frame:<omxh264dec-omxh264dec0> sync timestamp 0:07:15.632708481 diff -0:07:15.400555555 0:01:35.253199888 14697 0x75713bb0 WARN videodecoder gstvideodecoder.c:2767:gst_video_decoder_prepare_finish_frame:<omxh264dec-omxh264dec0> decreasing timestamp (0:07:15.632708481 < 0:07:15.792708481) 0:01:35.253320876 14697 0x75713bb0 DEBUG videodecoder gstvideodecoder.c:2847:gst_video_decoder_drop_frame:<omxh264dec-omxh264dec0> dropping frame 0:07:15.792708481 0:01:35.254169146 14697 0x75713bb0 DEBUG videodecoder gstvideodecoder.c:3381:gst_video_decoder_decode_frame:<omxh264dec-omxh264dec0> decoder frame list getting long: 17 frames,possible internal leaking? 0:01:35.254307113 14697 0x75713bb0 DEBUG omxvideodec gstomxvideodec.c:2178:gst_omx_video_dec_handle_frame:<omxh264dec-omxh264dec0> Handling frame 0:01:35.254382112 14697 0x75713bb0 DEBUG videodecoder gstvideodecoder.c:2654:gst_video_decoder_prepare_finish_frame:<omxh264dec-omxh264dec0> sync timestamp 0:07:15.552708481 diff -0:07:15.320555555 0:01:35.254519194 14697 0x75713bb0 WARN videodecoder gstvideodecoder.c:2767:gst_video_decoder_prepare_finish_frame:<omxh264dec-omxh264dec0> decreasing timestamp (0:07:15.552708481 < 0:07:15.792708481) 0:01:35.254630703 14697 0x75713bb0 DEBUG videodecoder gstvideodecoder.c:2847:gst_video_decoder_drop_frame:<omxh264dec-omxh264dec0> dropping frame 0:07:15.792708481 0:01:35.255431994 14697 0x75713bb0 DEBUG videodecoder gstvideodecoder.c:3381:gst_video_decoder_decode_frame:<omxh264dec-omxh264dec0> decoder frame list getting long: 17 frames,possible internal leaking? 0:01:35.255566524 14697 0x75713bb0 DEBUG omxvideodec gstomxvideodec.c:2178:gst_omx_video_dec_handle_frame:<omxh264dec-omxh264dec0> Handling frame Eventually the decoder runs out of frames and we get this: 0:01:35.717327853 14697 0x75713bb0 DEBUG videodecoder gstvideodecoder.c:3381:gst_video_decoder_decode_frame:<omxh264dec-omxh264dec0> decoder frame list getting long: 44 frames,possible internal leaking? 0:01:35.717407279 14697 0x75713bb0 DEBUG omxvideodec gstomxvideodec.c:2178:gst_omx_video_dec_handle_frame:<omxh264dec-omxh264dec0> Handling frame 0:01:35.717455612 14697 0x75713bb0 DEBUG videodecoder gstvideodecoder.c:2654:gst_video_decoder_prepare_finish_frame:<omxh264dec-omxh264dec0> sync timestamp 0:08:27.712708481 diff -0:08:27.480555555 0:01:35.717524778 14697 0x75713bb0 WARN videodecoder gstvideodecoder.c:2767:gst_video_decoder_prepare_finish_frame:<omxh264dec-omxh264dec0> decreasing timestamp (0:08:27.712708481 < 0:08:27.752708481) 0:01:35.717578683 14697 0x75713bb0 DEBUG videodecoder gstvideodecoder.c:2847:gst_video_decoder_drop_frame:<omxh264dec-omxh264dec0> dropping frame 0:08:27.752708481 0:01:35.718894082 14697 0x75713bb0 DEBUG videodecoder gstvideodecoder.c:3366:gst_video_decoder_decode_frame:<omxh264dec-omxh264dec0> PTS delta 400 ms 0:01:35.718990279 14697 0x75713bb0 DEBUG videodecoder gstvideodecoder.c:3381:gst_video_decoder_decode_frame:<omxh264dec-omxh264dec0> decoder frame list getting long: 44 frames,possible internal leaking? 0:01:35.719030747 14697 0x75713bb0 DEBUG omxvideodec gstomxvideodec.c:2178:gst_omx_video_dec_handle_frame:<omxh264dec-omxh264dec0> Handling frame 0:01:35.719060434 14697 0x75713bb0 DEBUG omxvideodec gstomxvideodec.c:2185:gst_omx_video_dec_handle_frame:<omxh264dec-omxh264dec0> Starting task 0:01:35.719112413 14697 0x75713bb0 DEBUG videodecoder gstvideodecoder.c:3391:gst_video_decoder_decode_frame:<omxh264dec-omxh264dec0> flow error eos 0:01:35.719369024 14697 0x74301db0 DEBUG omxvideodec gstomxvideodec.c:1570:gst_omx_video_dec_loop:<omxh264dec-omxh264dec0> Component signalled EOS 0:01:35.719425638 14697 0x74301db0 DEBUG omxvideodec gstomxvideodec.c:1590:gst_omx_video_dec_loop:<omxh264dec-omxh264dec0> EOS 0:01:35.719957506 14697 0x75713bb0 DEBUG videodecoder gstvideodecoder.c:3381:gst_video_decoder_decode_frame:<omxh264dec-omxh264dec0> decoder frame list getting long: 45 frames,possible internal leaking? 0:01:35.720032088 14697 0x75713bb0 DEBUG omxvideodec gstomxvideodec.c:2178:gst_omx_video_dec_handle_frame:<omxh264dec-omxh264dec0> Handling frame 0:01:35.720079588 14697 0x75713bb0 DEBUG videodecoder gstvideodecoder.c:2654:gst_video_decoder_prepare_finish_frame:<omxh264dec-omxh264dec0> sync timestamp 0:08:27.912708481 diff -0:08:27.680555555 0:01:35.720149222 14697 0x75713bb0 DEBUG videodecoder gstvideodecoder.c:2847:gst_video_decoder_drop_frame:<omxh264dec-omxh264dec0> dropping frame 0:08:27.912708481 0:01:35.720464635 14697 0x75713bb0 DEBUG videodecoder gstvideodecoder.c:1396:gst_video_decoder_sink_event:<omxh264dec-omxh264dec0> received event 28174, eos 0:01:35.720536196 14697 0x75713bb0 DEBUG omxvideodec gstomxvideodec.c:2457:gst_omx_video_dec_drain:<omxh264dec-omxh264dec0> Draining component 0:01:35.720566769 14697 0x75713bb0 DEBUG omxvideodec gstomxvideodec.c:2462:gst_omx_video_dec_drain:<omxh264dec-omxh264dec0> Component not started yet 0:01:35.720596821 14697 0x75713bb0 DEBUG videodecoder gstvideodecoder.c:869:gst_video_decoder_push_event:<omxh264dec-omxh264dec0> pushing event eos At this point the pipeline hangs completely and is silent from this point on, until a CTL-C triggers a graceful shutdown. Some further questions: - Things seems to start going wrong when we see the following: "no valid PTS, using oldest DTS 0:07:14.952708481” and "decreasing timestamp (0:07:14.952708481 < 0:07:15.792708481)” followed by "dropping frame 0:07:15.792708481” - have we got frames out of order? - When things go wrong, either before or after we process the following: "Pushing all pending serialized events before the gap”. This is caused by us having received a GST_EVENT_GAP. What does this mean? Can anyone see anything in the logs above that would explain a hang? I have an example TS that shows the problem. Regards, Graham — _______________________________________________ gstreamer-devel mailing list [hidden email] https://lists.freedesktop.org/mailman/listinfo/gstreamer-devel |
Re: Unexplained freeze/hang from gst-omx omxh264enc on Raspberry Pi 3
|
|
On 16 Nov 2016, at 12:36 AM, Graham Leggett <[hidden email]> wrote:
> - Things seems to start going wrong when we see the following: "no valid PTS, using oldest DTS 0:07:14.952708481” and "decreasing timestamp (0:07:14.952708481 < 0:07:15.792708481)” followed by "dropping frame 0:07:15.792708481” - have we got frames out of order? On a separate run, I focused on the “dropping frames” messages that start when the stream falls off the rails. Weirdly, we seem to drop the same frame multiple times - that’s weird - and even stranger, we either drop that same frame 8 times, or 4 times, or 2 times, or once. Does this pattern seem familiar to anyone? 0:01:30.155517306 20046 0x74e01db0 DEBUG videodecoder gstvideodecoder.c:2847:gst_video_decoder_drop_frame:<omxh264dec-omxh264dec0> dropping frame 0:07:15.792708481 0:01:30.196811397 20046 0x75713bb0 DEBUG videodecoder gstvideodecoder.c:2847:gst_video_decoder_drop_frame:<omxh264dec-omxh264dec0> dropping frame 0:07:15.792708481 0:01:30.198273098 20046 0x75713bb0 DEBUG videodecoder gstvideodecoder.c:2847:gst_video_decoder_drop_frame:<omxh264dec-omxh264dec0> dropping frame 0:07:15.792708481 0:01:30.199666571 20046 0x75713bb0 DEBUG videodecoder gstvideodecoder.c:2847:gst_video_decoder_drop_frame:<omxh264dec-omxh264dec0> dropping frame 0:07:15.792708481 0:01:30.201234625 20046 0x75713bb0 DEBUG videodecoder gstvideodecoder.c:2847:gst_video_decoder_drop_frame:<omxh264dec-omxh264dec0> dropping frame 0:07:15.792708481 0:01:30.202890543 20046 0x75713bb0 DEBUG videodecoder gstvideodecoder.c:2847:gst_video_decoder_drop_frame:<omxh264dec-omxh264dec0> dropping frame 0:07:15.792708481 0:01:30.204412348 20046 0x75713bb0 DEBUG videodecoder gstvideodecoder.c:2847:gst_video_decoder_drop_frame:<omxh264dec-omxh264dec0> dropping frame 0:07:15.792708481 0:01:30.206683258 20046 0x75713bb0 DEBUG videodecoder gstvideodecoder.c:2847:gst_video_decoder_drop_frame:<omxh264dec-omxh264dec0> dropping frame 0:07:15.792708481 0:01:30.208471205 20046 0x75713bb0 DEBUG videodecoder gstvideodecoder.c:2847:gst_video_decoder_drop_frame:<omxh264dec-omxh264dec0> dropping frame 0:07:16.112708481 0:01:30.210226809 20046 0x75713bb0 DEBUG videodecoder gstvideodecoder.c:2847:gst_video_decoder_drop_frame:<omxh264dec-omxh264dec0> dropping frame 0:07:16.112708481 0:01:30.211906216 20046 0x75713bb0 DEBUG videodecoder gstvideodecoder.c:2847:gst_video_decoder_drop_frame:<omxh264dec-omxh264dec0> dropping frame 0:07:16.112708481 0:01:30.213384220 20046 0x75713bb0 DEBUG videodecoder gstvideodecoder.c:2847:gst_video_decoder_drop_frame:<omxh264dec-omxh264dec0> dropping frame 0:07:16.112708481 0:01:30.214855973 20046 0x75713bb0 DEBUG videodecoder gstvideodecoder.c:2847:gst_video_decoder_drop_frame:<omxh264dec-omxh264dec0> dropping frame 0:07:16.112708481 0:01:30.216387205 20046 0x75713bb0 DEBUG videodecoder gstvideodecoder.c:2847:gst_video_decoder_drop_frame:<omxh264dec-omxh264dec0> dropping frame 0:07:16.112708481 0:01:30.217909478 20046 0x75713bb0 DEBUG videodecoder gstvideodecoder.c:2847:gst_video_decoder_drop_frame:<omxh264dec-omxh264dec0> dropping frame 0:07:16.112708481 0:01:30.219489563 20046 0x75713bb0 DEBUG videodecoder gstvideodecoder.c:2847:gst_video_decoder_drop_frame:<omxh264dec-omxh264dec0> dropping frame 0:07:16.112708481 0:01:30.221330271 20046 0x75713bb0 DEBUG videodecoder gstvideodecoder.c:2847:gst_video_decoder_drop_frame:<omxh264dec-omxh264dec0> dropping frame 0:07:16.432708481 0:01:30.222995720 20046 0x75713bb0 DEBUG videodecoder gstvideodecoder.c:2847:gst_video_decoder_drop_frame:<omxh264dec-omxh264dec0> dropping frame 0:07:16.432708481 0:01:30.224915749 20046 0x75713bb0 DEBUG videodecoder gstvideodecoder.c:2847:gst_video_decoder_drop_frame:<omxh264dec-omxh264dec0> dropping frame 0:07:16.432708481 0:01:30.226420887 20046 0x75713bb0 DEBUG videodecoder gstvideodecoder.c:2847:gst_video_decoder_drop_frame:<omxh264dec-omxh264dec0> dropping frame 0:07:16.432708481 0:01:30.228092325 20046 0x75713bb0 DEBUG videodecoder gstvideodecoder.c:2847:gst_video_decoder_drop_frame:<omxh264dec-omxh264dec0> dropping frame 0:07:16.432708481 0:01:30.229669807 20046 0x75713bb0 DEBUG videodecoder gstvideodecoder.c:2847:gst_video_decoder_drop_frame:<omxh264dec-omxh264dec0> dropping frame 0:07:16.432708481 0:01:30.231222496 20046 0x75713bb0 DEBUG videodecoder gstvideodecoder.c:2847:gst_video_decoder_drop_frame:<omxh264dec-omxh264dec0> dropping frame 0:07:16.432708481 0:01:30.232794821 20046 0x75713bb0 DEBUG videodecoder gstvideodecoder.c:2847:gst_video_decoder_drop_frame:<omxh264dec-omxh264dec0> dropping frame 0:07:16.432708481 0:01:30.237690336 20046 0x75713bb0 DEBUG videodecoder gstvideodecoder.c:2847:gst_video_decoder_drop_frame:<omxh264dec-omxh264dec0> dropping frame 0:07:16.592708481 0:01:30.239337712 20046 0x75713bb0 DEBUG videodecoder gstvideodecoder.c:2847:gst_video_decoder_drop_frame:<omxh264dec-omxh264dec0> dropping frame 0:07:16.592708481 0:01:30.240950141 20046 0x75713bb0 DEBUG videodecoder gstvideodecoder.c:2847:gst_video_decoder_drop_frame:<omxh264dec-omxh264dec0> dropping frame 0:07:16.592708481 0:01:30.242706526 20046 0x75713bb0 DEBUG videodecoder gstvideodecoder.c:2847:gst_video_decoder_drop_frame:<omxh264dec-omxh264dec0> dropping frame 0:07:16.592708481 0:01:30.244132290 20046 0x75713bb0 DEBUG videodecoder gstvideodecoder.c:2847:gst_video_decoder_drop_frame:<omxh264dec-omxh264dec0> dropping frame 0:07:16.672708481 0:01:30.246324399 20046 0x75713bb0 DEBUG videodecoder gstvideodecoder.c:2847:gst_video_decoder_drop_frame:<omxh264dec-omxh264dec0> dropping frame 0:07:16.672708481 0:01:30.247834642 20046 0x75713bb0 DEBUG videodecoder gstvideodecoder.c:2847:gst_video_decoder_drop_frame:<omxh264dec-omxh264dec0> dropping frame 0:07:16.712708481 Regards, Graham — _______________________________________________ gstreamer-devel mailing list [hidden email] https://lists.freedesktop.org/mailman/listinfo/gstreamer-devel |
Re: Unexplained freeze/hang from gst-omx omxh264enc on Raspberry Pi 3
|
|
In reply to this post by Graham Leggett
On 16 Nov 2016, at 12:36 AM, Graham Leggett <[hidden email]> wrote:
> 0:01:35.201549213 14697 0x74301db0 DEBUG videodecoder gstvideodecoder.c:2703:gst_video_decoder_prepare_finish_frame:<omxh264dec-omxh264dec0> no valid PTS, using oldest DTS 0:07:14.952708481 Placing a breakpoint at this point and taking a look at the frame that triggered this message, we find this: 0:01:40.252680427 351 0x74e021b0 DEBUG videodecoder gstvideodecoder.c:2654:gst_video_decoder_prepare_finish_frame:<omxh264dec-omxh264dec0> sync timestamp 0:07:15.792708481 diff -0:07:15.792708481 0:01:40.253014642 351 0x74e021b0 DEBUG videodecoder gstvideodecoder.c:3174:gst_video_decoder_clip_and_push_buf:<omxh264dec-omxh264dec0> pushing buffer 0x6c7bb3e0 of size 470016, PTS 0:07:15.792708481, dur 0:00:00.040000000 0:01:40.254921651 351 0x73144ec0 DEBUG videodecoder gstvideodecoder.c:1728:gst_video_decoder_src_query:<omxh264dec-omxh264dec0> received query 5123, duration 0:01:40.255264043 351 0x73144ec0 DEBUG tsdemux tsdemux.c:516:gst_ts_demux_srcpad_query: query duration 0:01:40.255315657 351 0x73144ec0 DEBUG tsdemux tsdemux.c:527:gst_ts_demux_srcpad_query:<tsdemux0> only query duration on TIME is supported [Switching to Thread 0x6dfff460 (LWP 366)] Breakpoint 1, gst_video_decoder_prepare_finish_frame (decoder=0x74e28190, frame=0x7314e950, dropping=1) at gstvideodecoder.c:2700 2700 frame->pts = min_ts + priv->pts_delta; (gdb) print frame->pts $1 = 18446744073709551615 (gdb) print priv->reordered_output $2 = 0 (gdb) print *frame $3 = {ref_count = 2, flags = 0, system_frame_number = 3456, decode_frame_number = 3456, presentation_frame_number = 0, dts = 139992708481, pts = 18446744073709551615, duration = 40000000, distance_from_sync = 3456, input_buffer = 0x6e1d38d0, output_buffer = 0x0, deadline = 18446744073709551615, events = 0x0, user_data = 0x0, user_data_destroy_notify = 0x0, abidata = {ABI = { ts = 434912708481, ts2 = 18446744073709551615}, padding = {0x42d14781, 0x65, 0xffffffff, 0xffffffff, 0x0 <repeats 16 times>}}} (gdb) Specifically, the PTS on this frame is 18446744073709551615, as is the “deadline” and the “ts2”. This triggers the code that replaces the bogus PTS with DTS, which is in the future compared to the frames that follow, leading to this: > 0:01:35.202174569 14697 0x74301db0 WARN videodecoder gstvideodecoder.c:2767:gst_video_decoder_prepare_finish_frame:<omxh264dec-omxh264dec0> decreasing timestamp (0:07:14.952708481 < 0:07:15.792708481) > 0:01:35.202333421 14697 0x74301db0 DEBUG videodecoder gstvideodecoder.c:2847:gst_video_decoder_drop_frame:<omxh264dec-omxh264dec0> dropping frame 0:07:15.792708481 It looks like a single corrupt PTS will DoS the pipeline. Regards, Graham — _______________________________________________ gstreamer-devel mailing list [hidden email] https://lists.freedesktop.org/mailman/listinfo/gstreamer-devel |
Re: Unexplained freeze/hang from gst-omx omxh264enc on Raspberry Pi 3
|
|
In reply to this post by Graham Leggett
On 15 Nov 2016, at 3:34 AM, Graham Leggett <[hidden email]> wrote:
> - What does "Draining component” do? It appears to be called from gst_omx_video_enc_finish(), but I cannot figure out why finish is being called on the encoder or what triggered it. > > - Are there any known bugs in omxh264enc that would cause it to stop encoding for any reason (as opposed to being temporarily degraded but still running). Some progress. The hang turned out to be a patch I had added to stop gst-launch-1.0 from exiting without it being asked to. What was really happening was the pipeline was returning EOS on the live stream and exiting early before being asked to. When a stream comes to EOS, gst_omx_video_dec_drain() is called to request the graphics card empties all outstanding buffers. To drain the card, the OMX_BUFFERFLAG_EOS flag is set on the buffers entering the card. This in turn causes the GST_OMX_ACQUIRE_BUFFER_EOS status to be returned from gst_omx_port_acquire_buffer(), which causes the code to follow a path that on first invocation returns GST_FLOW_OK, but on subsequent invocations returns GST_FLOW_EOS. However, in the live streaming of unreliable streams case where a discontinuity is encountered, we also call gst_omx_video_dec_drain() to empty the graphics card before trying to start decoding from scratch after the discontinuity. On this code path there is obviously no intention to shut the stream down with EOS, but that’s ultimately what is happening. After a discontinuity, during gst_omx_video_dec_drain(), the code is returning GST_FLOW_EOS when it should not, causing the stream to be shut down prematurely. The workaround is this: diff --git a/omx/gstomxvideodec.c b/omx/gstomxvideodec.c index 6baaa48..5a5998c 100644 --- a/omx/gstomxvideodec.c +++ b/omx/gstomxvideodec.c @@ -1568,7 +1569,8 @@ eos: gst_pad_pause_task (GST_VIDEO_DECODER_SRC_PAD (self)); } else { GST_DEBUG_OBJECT (self, "Component signalled EOS"); - flow_ret = GST_FLOW_EOS; + flow_ret = GST_FLOW_OK; +// flow_ret = GST_FLOW_EOS; } g_mutex_unlock (&self->drain_lock); I am looking for some guidance on the real fix. Am I right in understand that GST_FLOW_EOS is the job of the parent video encoder class, and that gstomxvideodec.c has no business trying to return a GST_FLOW_EOS of it’s own? Regards, Graham — _______________________________________________ gstreamer-devel mailing list [hidden email] https://lists.freedesktop.org/mailman/listinfo/gstreamer-devel |
Re: Unexplained freeze/hang from gst-omx omxh264enc on Raspberry Pi 3
|
|
On Sun, 2016-11-20 at 16:20 +0200, Graham Leggett wrote:
> > I am looking for some guidance on the real fix. Am I right in > understand that GST_FLOW_EOS is the job of the parent video encoder > class, and that gstomxvideodec.c has no business trying to return a > GST_FLOW_EOS of it’s own? Please file a bug about this. The problem here seems to be that the draining does not work properly. When draining, the element remembers that it does that currently and is not supposed to send EOS downstream / return GST_FLOW_EOS. For some reason this part of the code did not work as expected for you though and that will have to be debugged and fixed. The intention here is to ignore EOS when draining (and otherwise not ignore it), and to signal the condition variable that is waiting for draining to finish. -- Sebastian Dröge, Centricular Ltd · http://www.centricular.com _______________________________________________ gstreamer-devel mailing list [hidden email] https://lists.freedesktop.org/mailman/listinfo/gstreamer-devel |
Re: Unexplained freeze/hang from gst-omx omxh264enc on Raspberry Pi 3
|
|
On 21 Nov 2016, at 10:27 AM, Sebastian Dröge <[hidden email]> wrote:
>> I am looking for some guidance on the real fix. Am I right in >> understand that GST_FLOW_EOS is the job of the parent video encoder >> class, and that gstomxvideodec.c has no business trying to return a >> GST_FLOW_EOS of it’s own? > > Please file a bug about this. https://bugzilla.gnome.org/show_bug.cgi?id=774600 > The problem here seems to be that the draining does not work properly. > When draining, the element remembers that it does that currently and is > not supposed to send EOS downstream / return GST_FLOW_EOS. For some > reason this part of the code did not work as expected for you though > and that will have to be debugged and fixed. The intention here is to > ignore EOS when draining (and otherwise not ignore it), and to signal > the condition variable that is waiting for draining to finish. From the comment https://bugzilla.gnome.org/show_bug.cgi?id=774600#c10 it appears draining only works properly once. port->eos is never set back to FALSE. Regards, Graham -- _______________________________________________ gstreamer-devel mailing list [hidden email] https://lists.freedesktop.org/mailman/listinfo/gstreamer-devel |
| Free forum by Nabble | Edit this page |