Video freezing with no obvious issues in logs
Locked
Video freezing with no obvious issues in logs
 
|
Hello,
I'm working with gstreamer for the first time with a pipeline that has been setup by someone else. The system is supposed to take the incoming video for an openwebrtc call and draw it on the lcd screen for the raspberry pie 3 gstreamer is running on. So far, the video will display on the screen for several minutes before freezing. I've been digging through the logs for several days now and am completely out of ideas. I'm also coming up to speed on the machinery of gstreamer, but am sadly very unfamiliar and could really use some help. In particular, I have about 500MB of logs (that top logging level is insane), but I'm not sure what the important pieces are or where to start poking around. The following link is to the last 10000 lines of one of my log files (DEBUG setting). I tried to kill execution as soon as I noticed the freezing occur. https://www.dropbox.com/s/f9fnjzhf1uq92mr/very_short_cerbero_log.log?dl=0 Could you please help me understand what is important in this log file for writing the video to the screen and any good places to start poking around more deeply? Respectfully, Blake Chambers -- Robotics Software Engineer [hidden email] http://vecna.com mobile: (719) 210-7341 Cambridge Research Laboratory Vecna Technologies, Inc. 36 Cambridgepark Drive Cambridge, MA 02140 Phone: (617) 864-0636 Fax: (617) 864-0638 Better Technology, Better World (TM) The contents of this message may be privileged and confidential. Therefore, if this message has been received in error, Please delete in without reading it. Your receipt of this message is not intended to waive any applicable privilege. Please do not disseminate this message without the permission of the author. _______________________________________________ gstreamer-devel mailing list [hidden email] https://lists.freedesktop.org/mailman/listinfo/gstreamer-devel |
Re: Video freezing with no obvious issues in logs
|
|
Hello again, I have been continuing to dig into this freezing issue I'm experiencing and found the pattern below in the log files. I noticed the video repair messages being sent as well as the "Picture Loss Indication" which sound like they are connected to handling the video when it begins to freeze. How might I start digging into the code at this point and seeing what's going on? I'm not certain if looking at the files mentioned are the best place to start as I'm guessing they are responding to something going wrong somewhere else. Also, are there any tutorials or documentation on the pieces I'm
seeing here, videorepair and owrsession? Respectfully, Blake On 10/26/2016 06:02 PM, Blake Chambers
wrote:
Hello, _______________________________________________ gstreamer-devel mailing list [hidden email] https://lists.freedesktop.org/mailman/listinfo/gstreamer-devel |
Re: Video freezing with no obvious issues in logs
|
|
Hello, I'm continuing to investigate this issue and have come across this openwebrtc issue: https://github.com/EricssonResearch/bowser/issues/93 The symptoms described in the issue are very similar to mine. How can I check to see if gstreamer is receiving a keyframe or not when I experience the freezing? And how can I better debug whether or not something is failing during the RTCP operations in the owrsession? Respectfully,Blake P.S. I noticed that there is a forum that also send emails to this email list. Would it be better if I posted my questions on the forum instead of the mailing list? On 11/01/2016 07:04 PM, Blake Chambers
wrote:
-- Robotics Software Engineer [hidden email] http://vecna.com mobile: (719) 210-7341 Cambridge Research Laboratory Vecna Technologies, Inc. 36 Cambridgepark Drive Cambridge, MA 02140 Phone: (617) 864-0636 Fax: (617) 864-0638 Better Technology, Better World (TM) The contents of this message may be privileged and confidential. Therefore, if this message has been received in error, Please delete in without reading it. Your receipt of this message is not intended to waive any applicable privilege. Please do not disseminate this message without the permission of the author. _______________________________________________ gstreamer-devel mailing list [hidden email] https://lists.freedesktop.org/mailman/listinfo/gstreamer-devel |
Re: Video freezing with no obvious issues in logs
|
|
On Thu, 2016-11-03 at 12:46 -0400, Blake Chambers wrote: Hi Blake, You could check the GStreamer rtp video depayloader, video parser or video decoder's debug log to see if keyframes are being received or not, or data is received in general. What these elements are called exactly depends on the video format used. If it's h264 that would be rtph264depay, h264parse and decoder depends on your OS. You could also check the owr log category mentioned in the bug report you linked. Cheers -Tim -- Tim Müller, Centricular Ltd - http://www.centricular.com
_______________________________________________ gstreamer-devel mailing list [hidden email] https://lists.freedesktop.org/mailman/listinfo/gstreamer-devel |
Re: Video freezing with no obvious issues in logs
|
|
In reply to this post by Blake Chambers
On 02 Nov 2016, at 1:04 AM, Blake Chambers <[hidden email]> wrote:
I have been continuing to dig into this freezing issue I'm experiencing and found the pattern below in the log files. I am wondering if you’re seeing the same freeze that I am. Are you using omxvideoenc or omxvideodec? I am seeing a freeze when omxvideodec receives an out-of-order packet from an rtp source, I get "no valid PTS, using oldest DTS” from videodecoder followed by "decreasing timestamp”. Do you see anything like that your side? I also stumbled on this freeze being reported from (what I believe is) the same GPU hardware that’s in the PI, not had a chance to work out if this is related: Regards, Graham — _______________________________________________ gstreamer-devel mailing list [hidden email] https://lists.freedesktop.org/mailman/listinfo/gstreamer-devel |
smime.p7s (4K)
Re: Video freezing with no obvious issues in logs
|
|
On 11/16/2016 09:04 AM, Graham Leggett
wrote:
On 02 Nov 2016, at 1:04 AM, Blake Chambers <[hidden email]> wrote:I am using the omxvideodec. When I saw your email, I started looking through my logs and found this section related to the omxvideodec: 0:00:55.240848526 15523 0x74805fb0 DEBUG omxvideodec gstomxvideodec.c 1370 gst_omx_video_dec_loop <decoder_omxh264dec_4> Handling buffer: 0x00000010 536905200:00:55.241279669 15523 0x4cbcc0 DEBUG omxvideodec gstomxvideodec.c 2377 gst_omx_video_dec_handle_frame <decoder_omxh264dec_4> Passed frame to component0:00:55.258857323 15523 0x74805fb0 DEBUG omx gstomx.c 1431 gst_omx_port_release_buffer <decoder_omxh264dec_4> Released buffer 0x73e23c90 to video_decode port 131: None (0x00000000)0:00:55.258909719 15523 0x74805fb0 LOG omx gstomx.c 377 gst_omx_component_handle_messages <decoder_omxh264dec_4> video_decode port 131 filled buffer 0x73e23c90 (0x6203c020)0:00:55.274637228 15523 0x74805fb0 DEBUG videodecoder gstvideodecoder.c 1643 gst_video_decoder_src_event_default <decoder_omxh264dec_4> t QoS 0:00:54.638918279, +0:00:00.000000000, 0.9917140:00:55.296277774 15523 0x4cbcc0 DEBUG GST_CAPS gstpad.c 2644 gst_pad_has_current_caps <parser_h264parse_3:src> check current pad caps video/x-h264, stream-format=(string)byte-stream, alignment=(string)au, level=(string)3.1, profile=(string)constrained-baseline, width=(int)640, height=(int)480, framerate=(fraction)0/1, parsed=(boolean)true0:00:55.297977295 15523 0x4cbcc0 DEBUG GST_CAPS gstpad.c 2644 gst_pad_has_current_caps <parser_h264parse_3:src> check current pad caps video/x-h264, stream-format=(string)byte-stream, alignment=(string)au, level=(string)3.1, profile=(string)constrained-baseline, width=(int)640, height=(int)480, framerate=(fraction)0/1, parsed=(boolean)true0:00:55.298390626 15523 0x4cbcc0 LOG videodecoder gstvideodecoder.c 2498 gst_video_decoder_chain <decoder_omxh264dec_4> chain PTS 0:00:54.738874800, DTS 0:00:54.785062370 duration 99:99:99.999999999 size 71290:00:55.306178444 15523 0x74805fb0 LOG GST_PADS gstpad.c 5259 gst_pad_push_event_unchecked <parser_h264parse_3:sink> sent event 0x7120b2a8 (qos) to peerpad <sink:proxypad35> , ret ok0:00:55.306229537 15523 0x74805fb0 DEBUG GST_PADS gstpad.c 5610 gst_pad_send_event_unchecked <parser_h264parse_3:src> nt event, ret ok0:00:55.306264902 15523 0x74805fb0 LOG GST_PADS gstpad.c 5259 gst_pad_push_event_unchecked <decoder_omxh264dec_4:sink> sent event 0x7120b2a8 (qos) to peerpad <parser_h264parse_3:src> , ret ok0:00:55.306309849 15523 0x74805fb0 DEBUG GST_PADS gstpad.c 5610 gst_pad_send_event_unchecked <decoder_omxh264dec_4:src> nt event, ret ok0:00:55.306387088 15523 0x74805fb0 LOG GST_PADS gstpad.c 5259 gst_pad_push_event_unchecked <video-renderer-upload:sink> sent event 0x7120b2a8 (qos) to peerpad <decoder_omxh264dec_4:src> , ret ok0:00:55.306433703 15523 0x74805fb0 DEBUG GST_PADS gstpad.c 5610 gst_pad_send_event_unchecked <video-renderer-upload:src> nt event, ret ok0:00:55.306468338 15523 0x74805fb0 LOG GST_PADS gstpad.c 5259 gst_pad_push_event_unchecked <video-renderer-convert:sink> sent event 0x7120b2a8 (qos) to peerpad <video-renderer-upload:src> , ret ok0:00:55.306516150 15523 0x74805fb0 DEBUG GST_PADS gstpad.c 5610 gst_pad_send_event_unchecked <video-renderer-convert:src> nt event, ret ok0:00:55.308211192 15523 0x74805fb0 DEBUG omxvideodec gstomxvideodec.c 1506 gst_omx_video_dec_loop <decoder_omxh264dec_4> Read frame from component0:00:55.308238015 15523 0x74805fb0 DEBUG omxvideodec gstomxvideodec.c 1508 gst_omx_video_dec_loop <decoder_omxh264dec_4> Finished frame: ok0:00:55.308292754 15523 0x4cbcc0 LOG videodecoder gstvideodecoder.c 2655 gst_video_decoder_new_frame <decoder_omxh264dec_4> Created new frame 0x622b89f8 (sfn:107)0:00:55.308335879 15523 0x4cbcc0 LOG videodecoder gstvideodecoder.c 3454 gst_video_decoder_decode_frame <decoder_omxh264dec_4> PTS 0:00:54.738874800, DTS 0:00:54.785062370, dist 1070:00:55.308391503 15523 0x4cbcc0 DEBUG omxvideodec gstomxvideodec.c 2178 gst_omx_video_dec_handle_frame <decoder_omxh264dec_4> Handling frame0:00:55.308422076 15523 0x4cbcc0 DEBUG omx gstomx.c 1249 gst_omx_port_acquire_buffer <decoder_omxh264dec_4> Acquiring video_decode buffer from port 1300:00:55.308456868 15523 0x4cbcc0 DEBUG omx gstomx.c 1349 gst_omx_port_acquire_buffer <decoder_omxh264dec_4> video_decode port 130 has pending buffers0:00:55.308489784 15523 0x4cbcc0 DEBUG omx gstomx.c 1363 gst_omx_port_acquire_buffer <decoder_omxh264dec_4> Acquired buffer 0x7251ca78 (0x725ac200) from video_decode port 130: 00:00:55.308528690 15523 0x4cbcc0 DEBUG omxvideodec gstomxvideodec.c 2330 gst_omx_video_dec_handle_frame <decoder_omxh264dec_4> Passing frame offset 0 to the component0:00:55.308692595 15523 0x4cbcc0 DEBUG omx gstomx.c 1385 gst_omx_port_release_buffer <decoder_omxh264dec_4> Releasing buffer 0x7251ca78 (0x725ac200) to video_decode port 1300:00:55.308928323 15523 0x4cbcc0 DEBUG omx gstomx.c 1431 gst_omx_port_release_buffer <decoder_omxh264dec_4> Released buffer 0x7251ca78 to video_decode port 130: None (0x00000000)0:00:55.308984625 15523 0x4cbcc0 DEBUG omxvideodec gstomxvideodec.c 2377 gst_omx_video_dec_handle_frame <decoder_omxh264dec_4> Passed frame to component0:00:55.309487278 15523 0x7251e020 LOG omx gstomx.c 615 EmptyBufferDone <decoder_omxh264dec_4> video_decode port 130 emptied buffer 0x7251ca78 (0x725ac200)0:00:55.309540299 15523 0x74805fb0 DEBUG omx gstomx.c 1249 gst_omx_port_acquire_buffer <decoder_omxh264dec_4> Acquiring video_decode buffer from port 1310:00:55.309576132 15523 0x74805fb0 LOG omx gstomx.c 361 gst_omx_component_handle_messages <decoder_omxh264dec_4> video_decode port 130 emptied buffer 0x7251ca78 (0x725ac200)0:00:55.309614725 15523 0x74805fb0 DEBUG omx gstomx.c 1349 gst_omx_port_acquire_buffer <decoder_omxh264dec_4> video_decode port 131 has pending buffers0:00:55.309648006 15523 0x74805fb0 DEBUG omx gstomx.c 1363 gst_omx_port_acquire_buffer <decoder_omxh264dec_4> Acquired buffer 0x73e23c48 (0x6218f020) from video_decode port 131: 00:00:55.309692381 15523 0x74805fb0 DEBUG GST_CAPS gstpad.c 2644 gst_pad_has_current_caps <decoder_omxh264dec_4:src> check current pad caps video/x-raw, format=(string)I420, width=(int)640, height=(int)480, interlace-mode=(string)progressive, pixel-aspect-ratio=(fraction)1/1, chroma-site=(string)jpeg, colorimetry=(string)bt601, framerate=(fraction)0/10:00:55.309776078 15523 0x74805fb0 DEBUG omx gstomx.c 1576 gst_omx_port_is_flushing <decoder_omxh264dec_4> video_decode port 131 is flushing: 00:00:55.309810089 15523 0x74805fb0 DEBUG omxvideodec gstomxvideodec.c 1370 gst_omx_video_dec_loop <decoder_omxh264dec_4> Handling buffer: 0x00000010 537734580:00:55.309871911 15523 0x74805fb0 LOG videodecoder gstvideodecoder.c 4109 gst_video_decoder_get_max_decode_time <decoder_omxh264dec_4> rliest 0:00:54.638918279, frame deadline 0:00:54.738874800, deadline +0:00:00.0999565210:00:55.309929567 15523 0x74805fb0 LOG videodecoder gstvideodecoder.c 3045 gst_video_decoder_finish_frame <decoder_omxh264dec_4> finish frame 0x622b89f80:00:55.309962900 15523 0x74805fb0 LOG videodecoder gstvideodecoder.c 2685 gst_video_decoder_prepare_finish_frame <decoder_omxh264dec_4> n 1 in 0 out 00:00:55.309996650 15523 0x74805fb0 LOG videodecoder gstvideodecoder.c 2694 gst_video_decoder_prepare_finish_frame <decoder_omxh264dec_4> finish frame 0x622b89f8 (#107) sync:0 PTS:0:00:54.738874800 DTS:0:00:54.7850623700:00:55.310046754 15523 0x74805fb0 DEBUG videodecoder gstvideodecoder.c 2736 gst_video_decoder_prepare_finish_frame <decoder_omxh264dec_4> ync timestamp 0:00:54.738874800 diff -0:00:54.7388748000:00:55.310089879 15523 0x74805fb0 LOG videodecoder gstvideodecoder.c 2746 gst_video_decoder_prepare_finish_frame <decoder_omxh264dec_4> Guessing duration 99:99:99.999999999 for frame...0:00:55.310227013 15523 0x74805fb0 LOG videodecoder gstvideodecoder.c 3189 gst_video_decoder_clip_and_push_buf <decoder_omxh264dec_4> ccepting buffer inside segment: 0:00:54.738874800 0:00:54.778874800 seg 0:00:00.000000000 to 99:99:99.999999999 time 0:00:00.0000000000:00:55.310319721 15523 0x74805fb0 DEBUG videodecoder gstvideodecoder.c 3254 gst_video_decoder_clip_and_push_buf <decoder_omxh264dec_4> pushing buffer 0x712053c8 of size 460800, PTS 0:00:54.738874800, dur 99:99:99.9999999990:00:55.324252554 15523 0x74805fb0 DEBUG omx gstomx.c 1385 gst_omx_port_release_buffer <decoder_omxh264dec_4> Releasing buffer 0x73e23c48 (0x6218f020) to video_decode port 1310:00:55.326068584 15523 0x7251e020 LOG omx gstomx.c 653 FillBufferDone <decoder_omxh264dec_4> video_decode port 131 filled buffer 0x73e23c48 (0x6218f020)0:00:55.326132438 15523 0x74805fb0 DEBUG omx gstomx.c 1431 gst_omx_port_release_buffer <decoder_omxh264dec_4> Released buffer 0x73e23c48 to video_decode port 131: None (0x00000000)0:00:55.326176031 15523 0x74805fb0 LOG omx gstomx.c 377 gst_omx_component_handle_messages <decoder_omxh264dec_4> video_decode port 131 filled buffer 0x73e23c48 (0x6218f020)0:00:55.333503123 15523 0x74805fb0 LOG GST_PADS gstpad.c 5251 gst_pad_push_event_unchecked <video-renderer-balance:sink> nding event 0x7120b260 (qos) to peerpad <video-renderer-convert:src>0:00:55.333545987 15523 0x74805fb0 DEBUG GST_EVENT gstpad.c 5537 gst_pad_send_event_unchecked <video-renderer-convert:src> have event type qos event: 0x7120b260, time 99:99:99.999999999, seq-num 850, GstEventQOS, type=(GstQOSType)GST_QOS_TYPE_OVERFLOW, proportion=(double)1.002632671077905, diff=(gint64)0, timestamp=(guint64)54738874800;0:00:55.333726767 15523 0x74805fb0 LOG GST_PADS gstpad.c 5251 gst_pad_push_event_unchecked <video-renderer-convert:sink> nding event 0x7120b260 (qos) to peerpad <video-renderer-upload:src>0:00:55.333769371 15523 0x74805fb0 DEBUG GST_EVENT gstpad.c 5537 gst_pad_send_event_unchecked <video-renderer-upload:src> have event type qos event: 0x7120b260, time 99:99:99.999999999, seq-num 850, GstEventQOS, type=(GstQOSType)GST_QOS_TYPE_OVERFLOW, proportion=(double)1.002632671077905, diff=(gint64)0, timestamp=(guint64)54738874800;0:00:55.333964422 15523 0x74805fb0 LOG GST_PADS gstpad.c 5251 gst_pad_push_event_unchecked <video-renderer-upload:sink> nding event 0x7120b260 (qos) to peerpad <decoder_omxh264dec_4:src>0:00:55.334006557 15523 0x74805fb0 DEBUG GST_EVENT gstpad.c 5537 gst_pad_send_event_unchecked <decoder_omxh264dec_4:src> have event type qos event: 0x7120b260, time 99:99:99.999999999, seq-num 850, GstEventQOS, type=(GstQOSType)GST_QOS_TYPE_OVERFLOW, proportion=(double)1.002632671077905, diff=(gint64)0, timestamp=(guint64)54738874800;0:00:55.334076505 15523 0x74805fb0 DEBUG videodecoder gstvideodecoder.c 1671 gst_video_decoder_src_event <decoder_omxh264dec_4> received event 48641, qos0:00:55.334109004 15523 0x74805fb0 DEBUG videodecoder gstvideodecoder.c 1572 gst_video_decoder_src_event_default <decoder_omxh264dec_4> received event 48641, qos0:00:55.334146504 15523 0x74805fb0 DEBUG videodecoder gstvideodecoder.c 1643 gst_video_decoder_src_event_default <decoder_omxh264dec_4> t QoS 0:00:54.738874800, +0:00:00.000000000, 1.002630:00:55.334201556 15523 0x74805fb0 LOG GST_PADS gstpad.c 5251 gst_pad_push_event_unchecked <decoder_omxh264dec_4:sink> nding event 0x7120b260 (qos) to peerpad <parser_h264parse_3:src>0:00:55.334245514 15523 0x74805fb0 DEBUG GST_EVENT gstpad.c 5537 gst_pad_send_event_unchecked <parser_h264parse_3:src> have event type qos event: 0x7120b260, time 99:99:99.999999999, seq-num 850, GstEventQOS, type=(GstQOSType)GST_QOS_TYPE_OVERFLOW, proportion=(double)1.002632671077905, diff=(gint64)0, timestamp=(guint64)54738874800;0:00:55.334354888 15523 0x74805fb0 LOG GST_PADS gstpad.c 3017 gst_pad_event_default <parser_h264parse_3:src> default event handler for event qos event: 0x7120b260, time 99:99:99.999999999, seq-num 850, GstEventQOS, type=(GstQOSType)GST_QOS_TYPE_OVERFLOW, proportion=(double)1.002632671077905, diff=(gint64)0, timestamp=(guint64)54738874800;0:00:55.334427128 15523 0x74805fb0 DEBUG GST_PADS gstpad.c 2827 gst_pad_iterate_internal_links_default <parser_h264parse_3:src> Making iterator0:00:55.334463377 15523 0x74805fb0 LOG GST_PADS gstpad.c 2937 gst_pad_forward <parser_h264parse_3:src> calling forward function on pad parser_h264parse_3:sink0:00:55.334585981 15523 0x74805fb0 DEBUG GST_EVENT gstpad.c 5537 gst_pad_send_event_unchecked <sink:proxypad35> have event type qos event: 0x7120b260, time 99:99:99.999999999, seq-num 850, GstEventQOS, type=(GstQOSType)GST_QOS_TYPE_OVERFLOW, proportion=(double)1.002632671077905, diff=(gint64)0, timestamp=(guint64)54738874800;0:00:55.334894937 15523 0x74805fb0 DEBUG GST_EVENT gstpad.c 5537 gst_pad_send_event_unchecked <source-bin-1:src> have event type qos event: 0x7120b260, time 99:99:99.999999999, seq-num 850, GstEventQOS, type=(GstQOSType)GST_QOS_TYPE_OVERFLOW, proportion=(double)1.002632671077905, diff=(gint64)0, timestamp=(guint64)54738874800;0:00:55.339130380 15523 0x38a690 DEBUG GST_CAPS gstpad.c 2644 gst_pad_has_current_caps <rtpsession0:sync_src> check current pad caps application/x-rtcp0:00:55.346560648 15523 0x74805fb0 LOG GST_PADS gstpad.c 5259 gst_pad_push_event_unchecked <parser_h264parse_3:sink> sent event 0x7120b260 (qos) to peerpad <sink:proxypad35> , ret ok0:00:55.346608929 15523 0x74805fb0 DEBUG GST_PADS gstpad.c 5610 gst_pad_send_event_unchecked <parser_h264parse_3:src> nt event, ret ok0:00:55.346643825 15523 0x74805fb0 LOG GST_PADS gstpad.c 5259 gst_pad_push_event_unchecked <decoder_omxh264dec_4:sink> sent event 0x7120b260 (qos) to peerpad <parser_h264parse_3:src> , ret ok0:00:55.346688251 15523 0x74805fb0 DEBUG GST_PADS gstpad.c 5610 gst_pad_send_event_unchecked <decoder_omxh264dec_4:src> nt event, ret ok0:00:55.346738459 15523 0x74805fb0 LOG GST_PADS gstpad.c 5259 gst_pad_push_event_unchecked <video-renderer-upload:sink> sent event 0x7120b260 (qos) to peerpad <decoder_omxh264dec_4:src> , ret ok0:00:55.346783459 15523 0x74805fb0 DEBUG GST_PADS gstpad.c 5610 gst_pad_send_event_unchecked <video-renderer-upload:src> nt event, ret ok0:00:55.346816688 15523 0x74805fb0 LOG GST_PADS gstpad.c 5259 gst_pad_push_event_unchecked <video-renderer-convert:sink> sent event 0x7120b260 (qos) to peerpad <video-renderer-upload:src> , ret ok0:00:55.346860230 15523 0x74805fb0 DEBUG GST_PADS gstpad.c 5610 gst_pad_send_event_unchecked <video-renderer-convert:src> nt event, ret ok0:00:55.352678476 15523 0x74805fb0 DEBUG omxvideodec gstomxvideodec.c 1506 gst_omx_video_dec_loop <decoder_omxh264dec_4> Read frame from component0:00:55.352708476 15523 0x74805fb0 DEBUG omxvideodec gstomxvideodec.c 1508 gst_omx_video_dec_loop <decoder_omxh264dec_4> Finished frame: ok0:00:55.352743475 15523 0x74805fb0 DEBUG omx gstomx.c 1249 gst_omx_port_acquire_buffer <decoder_omxh264dec_4> Acquiring video_decode buffer from port 1310:00:55.352781027 15523 0x74805fb0 DEBUG omx gstomx.c 1349 gst_omx_port_acquire_buffer <decoder_omxh264dec_4> video_decode port 131 has pending buffers0:00:55.352814985 15523 0x74805fb0 DEBUG omx gstomx.c 1363 gst_omx_port_acquire_buffer <decoder_omxh264dec_4> Acquired buffer 0x73e23c60 (0x6211e020) from video_decode port 131: 00:00:55.352868787 15523 0x74805fb0 DEBUG GST_CAPS gstpad.c 2644 gst_pad_has_current_caps <decoder_omxh264dec_4:src> check current pad caps video/x-raw, format=(string)I420, width=(int)640, height=(int)480, interlace-mode=(string)progressive, pixel-aspect-ratio=(fraction)1/1, chroma-site=(string)jpeg, colorimetry=(string)bt601, framerate=(fraction)0/10:00:55.352961495 15523 0x74805fb0 DEBUG omx gstomx.c 1576 gst_omx_port_is_flushing <decoder_omxh264dec_4> video_decode port 131 is flushing: 00:00:55.353011807 15523 0x74805fb0 DEBUG omxvideodec gstomxvideodec.c 1370 gst_omx_video_dec_loop <decoder_omxh264dec_4> Handling buffer: 0x00000010 538573960:00:55.353060192 15523 0x74805fb0 ERROR omxvideodec gstomxvideodec.c 1401 gst_omx_video_dec_loop <decoder_omxh264dec_4> No corresponding frame found0:00:55.371180968 15523 0x74801f80 DEBUG GST_CAPS gstpad.c 2644 gst_pad_has_current_caps <parser_h264parse_2:src> check current pad caps video/x-h264, stream-format=(string)avc, alignment=(string)au, codec_data=(buffer)0142c01fffe1000e6742c01f8c8d40501e900f08846a01000468ce3c80, level=(string)3.1, profile=(string)constrained-baseline, width=(int)640, height=(int)480, framerate=(fraction)0/1, parsed=(boolean)true0:00:55.371913360 15523 0x74801f80 DEBUG GST_CAPS gstpad.c 2644 gst_pad_has_current_caps <parser_h264parse_2:src> check current pad caps video/x-h264, stream-format=(string)avc, alignment=(string)au, codec_data=(buffer)0142c01fffe1000e6742c01f8c8d40501e900f08846a01000468ce3c80, level=(string)3.1, profile=(string)constrained-baseline, width=(int)640, height=(int)480, framerate=(fraction)0/1, parsed=(boolean)true0:00:55.377444732 15523 0x4cbcc0 DEBUG GST_CAPS gstpad.c 2644 gst_pad_has_current_caps <parser_h264parse_3:src> check current pad caps video/x-h264, stream-format=(string)byte-stream, alignment=(string)au, level=(string)3.1, profile=(string)constrained-baseline, width=(int)640, height=(int)480, framerate=(fraction)0/1, parsed=(boolean)true0:00:55.378083062 15523 0x4cbcc0 DEBUG GST_CAPS gstpad.c 2644 gst_pad_has_current_caps <parser_h264parse_3:src> check current pad caps video/x-h264, stream-format=(string)byte-stream, alignment=(string)au, level=(string)3.1, profile=(string)constrained-baseline, width=(int)640, height=(int)480, framerate=(fraction)0/1, parsed=(boolean)true0:00:55.378280405 15523 0x4cbcc0 LOG videodecoder gstvideodecoder.c 2498 gst_video_decoder_chain <decoder_omxh264dec_4> chain PTS 0:00:54.838831669, DTS 0:00:54.871522474 duration 99:99:99.999999999 size 61640:00:55.379087327 15523 0x74805fb0 DEBUG omx gstomx.c 1385 gst_omx_port_release_buffer <decoder_omxh264dec_4> Releasing buffer 0x73e23c60 (0x6211e020) to video_decode port 1310:00:55.385116770 15523 0x7251e020 LOG omx gstomx.c 653 FillBufferDone <decoder_omxh264dec_4> video_decode port 131 filled buffer 0x73e23c60 (0x6211e020)0:00:55.385200988 15523 0x74805fb0 DEBUG omx gstomx.c 1431 gst_omx_port_release_buffer <decoder_omxh264dec_4> Released buffer 0x73e23c60 to video_decode port 131: None (0x00000000)0:00:55.385351872 15523 0x74805fb0 LOG omx gstomx.c 377 gst_omx_component_handle_messages <decoder_omxh264dec_4> video_decode port 131 filled buffer 0x73e23c60 (0x6211e020)0:00:55.390880016 15523 0x38a720 DEBUG GST_CAPS gstpad.c 2644 gst_pad_has_current_caps <pay_rtph264pay_0:src> check current pad caps application/x-rtp, media=(string)video, clock-rate=(int)90000, encoding-name=(string)H264, packetization-mode=(string)1, sprop-parameter-sets=(string)"J0KAKJWgKA9oB4kTUA\\=\\=\\,KM4BDyA\\=", payload=(int)107, seqnum-offset=(uint)5701, timestamp-offset=(uint)2087699638, rtcp-fb-ccm-fir=(boolean)true, rtcp-fb-nack-pli=(boolean)true, ssrc=(uint)305722899, a-framerate=(string)100:00:55.396571648 15523 0x74805fb0 DEBUG omxvideodec gstomxvideodec.c 1506 gst_omx_video_dec_loop <decoder_omxh264dec_4> Read frame from component0:00:55.396645346 15523 0x74805fb0 DEBUG omxvideodec gstomxvideodec.c 1508 gst_omx_video_dec_loop <decoder_omxh264dec_4> Finished frame: ok0:00:55.396712689 15523 0x4cbcc0 LOG videodecoder gstvideodecoder.c 2655 gst_video_decoder_new_frame <decoder_omxh264dec_4> Created new frame 0x622b8e90 (sfn:108)0:00:55.396758991 15523 0x4cbcc0 LOG videodecoder gstvideodecoder.c 3454 gst_video_decoder_decode_frame <decoder_omxh264dec_4> PTS 0:00:54.838831669, DTS 0:00:54.871522474, dist 1080:00:55.396814772 15523 0x4cbcc0 DEBUG omxvideodec gstomxvideodec.c 2178 gst_omx_video_dec_handle_frame <decoder_omxh264dec_4> Handling frame0:00:55.396865969 15523 0x4cbcc0 DEBUG omx gstomx.c 1249 gst_omx_port_acquire_buffer <decoder_omxh264dec_4> Acquiring video_decode buffer from port 1300:00:55.396905761 15523 0x4cbcc0 DEBUG omx gstomx.c 1349 gst_omx_port_acquire_buffer <decoder_omxh264dec_4> video_decode port 130 has pending buffers0:00:55.396941386 15523 0x4cbcc0 DEBUG omx gstomx.c 1363 gst_omx_port_acquire_buffer <decoder_omxh264dec_4> Acquired buffer 0x7251ca90 (0x725c0220) from video_decode port 130: 00:00:55.396982896 15523 0x4cbcc0 DEBUG omxvideodec gstomxvideodec.c 2330 gst_omx_video_dec_handle_frame <decoder_omxh264dec_4> Passing frame offset 0 to the component0:00:55.397075083 15523 0x74805fb0 DEBUG omx gstomx.c 1249 gst_omx_port_acquire_buffer <decoder_omxh264dec_4> Acquiring video_decode buffer from port 1310:00:55.397144874 15523 0x74805fb0 DEBUG omx gstomx.c 1349 gst_omx_port_acquire_buffer <decoder_omxh264dec_4> video_decode port 131 has pending buffers0:00:55.397191540 15523 0x4cbcc0 DEBUG omx gstomx.c 1385 gst_omx_port_release_buffer <decoder_omxh264dec_4> Releasing buffer 0x7251ca90 (0x725c0220) to video_decode port 1300:00:55.397369716 15523 0x74805fb0 DEBUG omx gstomx.c 1363 gst_omx_port_acquire_buffer <decoder_omxh264dec_4> Acquired buffer 0x73e23c78 (0x620ad020) from video_decode port 131: 00:00:55.398961061 15523 0x7251e020 LOG omx gstomx.c 615 EmptyBufferDone <decoder_omxh264dec_4> video_decode port 130 emptied buffer 0x7251ca90 (0x725c0220)0:00:55.399074810 15523 0x4cbcc0 DEBUG omx gstomx.c 1431 gst_omx_port_release_buffer <decoder_omxh264dec_4> Released buffer 0x7251ca90 to video_decode port 130: None (0x00000000)0:00:55.399123872 15523 0x4cbcc0 LOG omx gstomx.c 361 gst_omx_component_handle_messages <decoder_omxh264dec_4> video_decode port 130 emptied buffer 0x7251ca90 (0x725c0220)0:00:55.399168091 15523 0x4cbcc0 DEBUG omxvideodec gstomxvideodec.c 2377 gst_omx_video_dec_handle_frame <decoder_omxh264dec_4> Passed frame to component0:00:55.399231788 15523 0x74805fb0 DEBUG GST_CAPS gstpad.c 2644 gst_pad_has_current_caps <decoder_omxh264dec_4:src> check current pad caps video/x-raw, format=(string)I420, width=(int)640, height=(int)480, interlace-mode=(string)progressive, pixel-aspect-ratio=(fraction)1/1, chroma-site=(string)jpeg, colorimetry=(string)bt601, framerate=(fraction)0/10:00:55.399843347 15523 0x74805fb0 DEBUG omx gstomx.c 1576 gst_omx_port_is_flushing <decoder_omxh264dec_4> video_decode port 131 is flushing: 00:00:55.399886316 15523 0x74805fb0 DEBUG omxvideodec gstomxvideodec.c 1370 gst_omx_video_dec_loop <decoder_omxh264dec_4> Handling buffer: 0x00000010 539403350:00:55.399941576 15523 0x74805fb0 LOG videodecoder gstvideodecoder.c 4109 gst_video_decoder_get_max_decode_time <decoder_omxh264dec_4> rliest 0:00:54.738874800, frame deadline 0:00:54.838831669, deadline +0:00:00.0999568690:00:55.400007305 15523 0x74805fb0 LOG videodecoder gstvideodecoder.c 3045 gst_video_decoder_finish_frame <decoder_omxh264dec_4> finish frame 0x622b8e900:00:55.400495739 15523 0x74805fb0 LOG videodecoder gstvideodecoder.c 2685 gst_video_decoder_prepare_finish_frame <decoder_omxh264dec_4> n 1 in 0 out 00:00:55.400533968 15523 0x74805fb0 LOG videodecoder gstvideodecoder.c 2694 gst_video_decoder_prepare_finish_frame <decoder_omxh264dec_4> finish frame 0x622b8e90 (#108) sync:0 PTS:0:00:54.838831669 DTS:0:00:54.8715224740:00:55.413720764 15523 0x74805fb0 DEBUG omx gstomx.c 1385 gst_omx_port_release_buffer <decoder_omxh264dec_4> Releasing buffer 0x73e23c78 (0x620ad020) to video_decode port 1310:00:55.415462211 15523 0x7251e020 LOG omx gstomx.c 653 FillBufferDone <decoder_omxh264dec_4> video_decode port 131 filled buffer 0x73e23c78 (0x620ad020)0:00:55.415527784 15523 0x74805fb0 DEBUG omx gstomx.c 1431 gst_omx_port_release_buffer <decoder_omxh264dec_4> Released buffer 0x73e23c78 to video_decode port 131: None (0x00000000)0:00:55.438817331 15523 0x74805fb0 DEBUG omxvideodec gstomxvideodec.c 1506 gst_omx_video_dec_loop <decoder_omxh264dec_4> Read frame from component0:00:55.438844935 15523 0x74805fb0 DEBUG omxvideodec gstomxvideodec.c 1508 gst_omx_video_dec_loop <decoder_omxh264dec_4> Finished frame: ok0:00:55.438987278 15523 0x74805fb0 DEBUG GST_CAPS gstpad.c 2644 gst_pad_has_current_caps <decoder_omxh264dec_4:src> check current pad caps video/x-raw, format=(string)I420, width=(int)640, height=(int)480, interlace-mode=(string)progressive, pixel-aspect-ratio=(fraction)1/1, chroma-site=(string)jpeg, colorimetry=(string)bt601, framerate=(fraction)0/10:00:55.439103058 15523 0x74805fb0 DEBUG omxvideodec gstomxvideodec.c 1370 gst_omx_video_dec_loop <decoder_omxh264dec_4> Handling buffer: 0x00000010 540232740:00:55.463904992 15523 0x74805fb0 DEBUG GST_CAPS gstpad.c 2644 gst_pad_has_current_caps <decoder_omxh264dec_4:src> check current pad caps video/x-raw, format=(string)I420, width=(int)640, height=(int)480, interlace-mode=(string)progressive, pixel-aspect-ratio=(fraction)1/1, chroma-site=(string)jpeg, colorimetry=(string)bt601, framerate=(fraction)0/10:00:55.479072400 15523 0x74801f80 DEBUG GST_CAPS gstpad.c 2644 gst_pad_has_current_caps <parser_h264parse_2:src> check current pad caps video/x-h264, stream-format=(string)avc, alignment=(string)au, codec_data=(buffer)0142c01fffe1000e6742c01f8c8d40501e900f08846a01000468ce3c80, level=(string)3.1, profile=(string)constrained-baseline, width=(int)640, height=(int)480, framerate=(fraction)0/1, parsed=(boolean)true If you look at 0:00:55.353060192, there is an ERROR in the omxvideodec "No corresponding frame found". This error happens several times around the freezing issue, then it stops appearing and the video remains frozen. Unfortunately I'm not seeing the "no valid PTS" from videodecoder. I was wondering, could I could get the TS file you mentioned and any other test files you've been using from you? I'd like to try and reproduce you issue on my machine. Respectfully,Blake _______________________________________________ gstreamer-devel mailing list [hidden email] https://lists.freedesktop.org/mailman/listinfo/gstreamer-devel |
Re: Video freezing with no obvious issues in logs
|
|
On 17 Nov 2016, at 12:11 AM, Blake Chambers <[hidden email]> wrote:
This duration looks odd. In my streams I have a duration of approximately 40ms (1/25). I see you also don’t yet have a framerate, I’m not sure if that’s significant.
I have seen a number of “No corresponding frame found” appear in my streams, they seem to show up throughout the stream in my case, but I suspect this is because the glitches are occurring quite often, they’re not always fatal.
The file that’s causing me all the trouble is this one: It fails at around the 1:35-1:38 mark, it fails at a different place on each attempt to decode, but it does always fail. Regards, Graham — _______________________________________________ gstreamer-devel mailing list [hidden email] https://lists.freedesktop.org/mailman/listinfo/gstreamer-devel |
Re: Video freezing with no obvious issues in logs
|
|
On 11/16/2016 05:51 PM, Graham Leggett wrote:
> > The file that’s causing me all the trouble is this one: > > http://www.sharp.fm/glitch1.ts > > It fails at around the 1:35-1:38 mark, it fails at a different place > on each attempt to decode, but it does always fail. > I played through the file 3 times using this command: "gst-launch-1.0 -v filesrc location=glitch1.ts ! tsdemux ! queue ! h264parse ! omxh264dec ! videoconvert ! videoscale ! glimagesink" but I wasn't able to reproduce the bug, no freezing :/ What is the pipeline you are using? Do you have a different command I can try on my end? Respectfully, Blake _______________________________________________ gstreamer-devel mailing list [hidden email] https://lists.freedesktop.org/mailman/listinfo/gstreamer-devel |
Re: Video freezing with no obvious issues in logs
|
|
On 17 Nov 2016, at 9:01 PM, Blake Chambers <[hidden email]> wrote:
> I played through the file 3 times using this command: > "gst-launch-1.0 -v filesrc location=glitch1.ts ! tsdemux ! queue ! h264parse ! omxh264dec ! videoconvert ! videoscale ! glimagesink" > > but I wasn't able to reproduce the bug, no freezing :/ > > What is the pipeline you are using? Do you have a different command I can try on my end? The command I’m using is this one: GST_TRACE="live" G_DEBUG="fatal-warnings" LD_LIBRARY_PATH=/usr/local/lib gst-launch-1.0 --gst-debug=1,videotag:1,souphttpclientsink:2,pixelsample:1,mpegtsbase:0,tdttsparse:5,transcoder:5,omxvideodec:1,omxvideoenc:1,tsdemux:5,encodebin:1,videodecoder:5 filesrc location=/mnt/stream/raw.ts ! progressreport update-freq=5 ! tsdemux ! queue ! h264parse ! omxh264dec ! omxh264enc ! h264parse ! mpegtsmux ! hlssink target-duration=0 What I’m seeing is that the PTS values received by the videodecoder are suddenly no longer increasing after the glitch, but instead jump forwards and backwards. This happens for a period of time, before the videodecoder freezes up completely. Regards, Graham — _______________________________________________ gstreamer-devel mailing list [hidden email] https://lists.freedesktop.org/mailman/listinfo/gstreamer-devel |
Re: Video freezing with no obvious issues in logs
|
|
In reply to this post by Blake Chambers
Hello, I have an update on the issue I experiences between gstreamer and openwebrtc running on a pi 3. After upgrading to the stable 1.10.1 version, the issues seems to have gone away. However, there was one interesting issue: * using xterm (and other non-gnome-terminal terminals)* ssh'ing into the pi * using screen * setting the log level to 4 and above causes so much lag in the pipeline I was only getting 1 frame every 40 sec. But, this setup with gnome-terminal was completely fine. Thank you for all your help. Respectfully,Blake On 11/03/2016 12:46 PM, Blake Chambers
wrote:
-- Robotics Software Engineer [hidden email] http://vecna.com mobile: (719) 210-7341 Cambridge Research Laboratory Vecna Technologies, Inc. 36 Cambridgepark Drive Cambridge, MA 02140 Phone: (617) 864-0636 Fax: (617) 864-0638 Better Technology, Better World (TM) The contents of this message may be privileged and confidential. Therefore, if this message has been received in error, Please delete in without reading it. Your receipt of this message is not intended to waive any applicable privilege. Please do not disseminate this message without the permission of the author. _______________________________________________ gstreamer-devel mailing list [hidden email] https://lists.freedesktop.org/mailman/listinfo/gstreamer-devel |
| Free forum by Nabble | Edit this page |