Perf turns to 0 when it hits a scrambled frame

Hi,

I was running the deepstream-test5-app in docker (image: nvcr.io/nvidia/deepstream:5.1-21.02-iot). It runs well at the start of the video and shows ~250FPS in performance monitoring. But it suddenly turns to 0FPS and keep printing 0FPS in log (fig1). I checked the source video file and found when it happened, there is a scrambled frame (fig2). Is there any guideline about how this is happening and what particular issue I should look into in source video? Any ideas would be a great help!

Thanks,
Jane

fig1
Screenshot from 2022-04-19 21-32-59

fig2

Can you provide some gstreamer debug log? You can run your code by setting GST_DEBUG=3 or GST_DEBUG=4 and attach the logs here.
I’ve faced something similar but for me it was a problem at the muxer. Got fixed when I switched from qtmux to matroskamux.

1 please provide the full terminal log, for example: execute export GST_DEBUG=4, then execute app >1.log 2>1.log
2 do you mean source video have some scrambled frames ? is there any issue using deepstream 's file? like /opt/nvidia/deepstream/deepstream/samples/streams/sample_720p.mp4

Thank you for your input. I have tried the debug mode and here is the partial log around where the issue happened. Please advice if this is similar to what you have seen before. Thanks!

Wed Apr 20 22:47:23 2022
**PERF:  255.75 (249.62)	
0:00:50.150737734 28353 0x7f5cc4003540 INFO               baseparse gstbaseparse.c:4004:gst_base_parse_set_latency:<h264-parser> min/max latency 0:00:00.033613445, 0:00:00.033613445
0:00:50.184398345 28353 0x7f5c5c168630 INFO               baseparse gstbaseparse.c:4004:gst_base_parse_set_latency:<h264parse0> min/max latency 0:00:00.033613445, 0:00:00.033613445
0:00:50.266635363 28353 0x7f5cc4003540 INFO               baseparse gstbaseparse.c:4004:gst_base_parse_set_latency:<h264-parser> min/max latency 0:00:00.033613445, 0:00:00.033613445
0:00:50.383745467 28353 0x7f5cc4003540 INFO               baseparse gstbaseparse.c:4004:gst_base_parse_set_latency:<h264-parser> min/max latency 0:00:00.033613445, 0:00:00.033613445
0:00:50.385404972 28353 0x7f5c5c168630 INFO               baseparse gstbaseparse.c:4004:gst_base_parse_set_latency:<h264parse0> min/max latency 0:00:00.033613445, 0:00:00.033613445
0:00:50.499462979 28353 0x7f5cc4003540 INFO               baseparse gstbaseparse.c:4004:gst_base_parse_set_latency:<h264-parser> min/max latency 0:00:00.033613445, 0:00:00.033613445
0:00:50.606433560 28353 0x7f5cc4003540 INFO               baseparse gstbaseparse.c:4004:gst_base_parse_set_latency:<h264-parser> min/max latency 0:00:00.033613445, 0:00:00.033613445
0:00:50.645535671 28353 0x7f5c5c168630 INFO               baseparse gstbaseparse.c:4004:gst_base_parse_set_latency:<h264parse0> min/max latency 0:00:00.033613445, 0:00:00.033613445
0:00:50.725636614 28353 0x7f5cc4003540 INFO               baseparse gstbaseparse.c:4004:gst_base_parse_set_latency:<h264-parser> min/max latency 0:00:00.033613445, 0:00:00.033613445
0:00:50.849298437 28353 0x7f5cc4003540 INFO               baseparse gstbaseparse.c:4004:gst_base_parse_set_latency:<h264-parser> min/max latency 0:00:00.033613445, 0:00:00.033613445
0:00:50.850906483 28353 0x7f5c5c168630 INFO               baseparse gstbaseparse.c:4004:gst_base_parse_set_latency:<h264parse0> min/max latency 0:00:00.033613445, 0:00:00.033613445
0:00:50.971806070 28353 0x7f5cc4003540 INFO               baseparse gstbaseparse.c:4004:gst_base_parse_set_latency:<h264-parser> min/max latency 0:00:00.033613445, 0:00:00.033613445
0:00:51.052220489 28353 0x7f5c5c168630 INFO               baseparse gstbaseparse.c:4004:gst_base_parse_set_latency:<h264parse0> min/max latency 0:00:00.033613445, 0:00:00.033613445
0:00:51.091534506 28353 0x7f5cc4003540 INFO               baseparse gstbaseparse.c:4004:gst_base_parse_set_latency:<h264-parser> min/max latency 0:00:00.033613445, 0:00:00.033613445
0:00:51.209487913 28353 0x7f5cc4003540 INFO               baseparse gstbaseparse.c:4004:gst_base_parse_set_latency:<h264-parser> min/max latency 0:00:00.033613445, 0:00:00.033613445
0:00:51.250634261 28353 0x7f5c5c168630 INFO               baseparse gstbaseparse.c:4004:gst_base_parse_set_latency:<h264parse0> min/max latency 0:00:00.033613445, 0:00:00.033613445
0:00:51.329841634 28353 0x7f5cc4003540 INFO               baseparse gstbaseparse.c:4004:gst_base_parse_set_latency:<h264-parser> min/max latency 0:00:00.033613445, 0:00:00.033613445
0:00:51.452637190 28353 0x7f5cc4003540 INFO               baseparse gstbaseparse.c:4004:gst_base_parse_set_latency:<h264-parser> min/max latency 0:00:00.033613445, 0:00:00.033613445
0:00:51.453645529 28353 0x7f5c5c168630 WARN       codecparsers_h264 gsth264parser.c:1188:gst_h264_parser_parse_sei_message: Bit non equal to one.
0:00:51.453736890 28353 0x7f5c5c168630 WARN       codecparsers_h264 gsth264parser.c:1194:gst_h264_parser_parse_sei_message: Bit non equal to zero.
0:00:51.453762723 28353 0x7f5c5c168630 WARN       codecparsers_h264 gsth264parser.c:1194:gst_h264_parser_parse_sei_message: Bit non equal to zero.
0:00:51.453868338 28353 0x7f5c5c168630 WARN       codecparsers_h264 gsth264parser.c:852:gst_h264_parser_parse_buffering_period: couldn't find associated sequence parameter set with id: 1
0:00:51.453884901 28353 0x7f5c5c168630 WARN       codecparsers_h264 gsth264parser.c:1194:gst_h264_parser_parse_sei_message: Bit non equal to zero.
0:00:51.453897471 28353 0x7f5c5c168630 WARN       codecparsers_h264 gsth264parser.c:1194:gst_h264_parser_parse_sei_message: Bit non equal to zero.
0:00:51.453918332 28353 0x7f5c5c168630 WARN               h264parse gsth264parse.c:531:gst_h264_parse_process_sei:<h264parse0> failed to parse one or more SEI message
0:00:51.453999195 28353 0x7f5c5c168630 INFO               baseparse gstbaseparse.c:4004:gst_base_parse_set_latency:<h264parse0> min/max latency 0:00:00.033613445, 0:00:00.033613445
0:00:51.454094678 28353 0x7f5c5c168630 INFO               GST_EVENT gstevent.c:814:gst_event_new_caps: creating caps event video/x-h264, stream-format=(string)byte-stream, alignment=(string)au, level=(string)4.2, profile=(string)high, width=(int)1920, height=(int)1080, framerate=(fraction)119/4, pixel-aspect-ratio=(fraction)1/1, multiview-mode=(string)frame-by-frame, multiview-flags=(GstVideoMultiviewFlagsSet)1:ffffffff:+right-view-first/left-flipped/left-flopped/right-flipped/right-flopped/half-aspect/mixed-mono, interlace-mode=(string)progressive, chroma-format=(string)4:2:0, bit-depth-luma=(uint)8, bit-depth-chroma=(uint)8, parsed=(boolean)true
0:00:51.454661544 28353 0x7f5c5c168630 INFO           basetransform gstbasetransform.c:1308:gst_base_transform_setcaps:<capsfilter0> reuse caps
0:00:51.454722019 28353 0x7f5c5c168630 INFO               GST_EVENT gstevent.c:814:gst_event_new_caps: creating caps event video/x-h264, stream-format=(string)byte-stream, alignment=(string)au, level=(string)4.2, profile=(string)high, width=(int)1920, height=(int)1080, framerate=(fraction)119/4, pixel-aspect-ratio=(fraction)1/1, multiview-mode=(string)frame-by-frame, multiview-flags=(GstVideoMultiviewFlagsSet)1:ffffffff:+right-view-first/left-flipped/left-flopped/right-flipped/right-flopped/half-aspect/mixed-mono, interlace-mode=(string)progressive, chroma-format=(string)4:2:0, bit-depth-luma=(uint)8, bit-depth-chroma=(uint)8, parsed=(boolean)true
0:00:51.464962632 28353 0x7f5bf4004000 INFO                    task gsttask.c:316:gst_task_func:<nvv4l2decoder0:src> Task going to paused
0:00:51.465093249 28353 0x7f5bf4004000 INFO                    task gsttask.c:318:gst_task_func:<nvv4l2decoder0:src> Task resume from paused
Wed Apr 20 22:47:28 2022
**PERF:  252.28 (231.53)	
Wed Apr 20 22:47:33 2022
**PERF:  0.00 (210.56)	
Wed Apr 20 22:47:38 2022
**PERF:  0.00 (193.07)	
Wed Apr 20 22:47:43 2022
**PERF:  0.00 (178.27)	
Wed Apr 20 22:47:48 2022
**PERF:  0.00 (165.57)	
Wed Apr 20 22:47:53 2022
**PERF:  0.00 (154.56)	
Wed Apr 20 22:47:58 2022
**PERF:  0.00 (144.92)	
Wed Apr 20 22:48:03 2022
**PERF:  0.00 (136.42)	
Wed Apr 20 22:48:08 2022
**PERF:  0.00 (128.86)	
Wed Apr 20 22:48:13 2022
**PERF:  0.00 (122.09)	

Hi fanzh,

I tried your suggestion and attached is the log file. I did terminate the process myself because it seems to be running endlessly. Please let me know if it is good enough for debugging.

To your second question, yes, I mean my own video has some scramble frames, not any other files in deepstream container itself. I’ve been using this docker image for a lot of other videos with no error and this is the first time I run into this problem.

Thanks.

1.log (882.4 KB)

0:00:42.064344911 e[336m 7463e[00m 0x7f2ac0004000 e[36mINFO e[00m e[00m task gsttask.c:316:gst_task_func:nvv4l2decoder0:srce[00m Task going to paused

sometimes hardware decoder paused, I suppose it was caused by bad h264 frames, could you share your video file, I will reproduce this issue, thanks!

Thanks. Here is the raw file: 2022-04-18-17-54-34-UTC.mp4 - Google Drive

1 I tested the mp4 in dgpu docker, the app paused by mp4 demux error, demux plugin is a Gstreamer open source plugin, we can’t change this demux code, so this file 's mp4 encapsulation is abnormal, here is the log:
/GstPipeline:pipeline/GstBin:multi_src_bin/GstBin:src_sub_bin0/GstURIDecodeBin:src_elem/GstDecodeBin:decodebin0/GstQTDemux:qtdemux0:
streaming stopped, reason not-negotiated (-4)

2 what is your device model? please make sure input file is normal, you can transcode this file to a normal file.

This topic was automatically closed 14 days after the last reply. New replies are no longer allowed.