Nvv4l2h264enc returns frames in wrong order when PTS doesn't align with framerate

tomskih_pa · June 21, 2023, 7:54am

Please provide complete information as applicable to your setup.

• Hardware Platform (Jetson / GPU)
NVIDIA Jetson Xavier NX (Developer kit)

• DeepStream Version
6.2

• JetPack Version (valid for Jetson only)
5.0.2 GA [L4T 35.1.0]

Full info

$ jetson_release 
Software part of jetson-stats 4.2.1 - (c) 2023, Raffaello Bonghi
Model: NVIDIA Jetson Xavier NX Developer Kit - Jetpack 5.0.2 GA [L4T 35.1.0]
NV Power Mode[8]: MODE_20W_6CORE
Serial Number: [XXX Show with: jetson_release -s XXX]
Hardware:
 - P-Number: p3668-0000
 - Module: NVIDIA Jetson Xavier NX (Developer kit)
Platform:
 - Distribution: Ubuntu 20.04 focal
 - Release: 5.10.104-tegra
jtop:
 - Version: 4.2.1
 - Service: Active
Libraries:
 - CUDA: 11.4.239
 - cuDNN: 8.4.1.50
 - TensorRT: 8.4.1.5
 - VPI: 2.1.6
 - Vulkan: 1.3.203
 - OpenCV: 4.5.4 - with CUDA: NO

• TensorRT Version
8.4.1.5

• Issue Type( questions, new requirements, bugs)
bug

• How to reproduce the issue ? (This is for bugs. Including which sample app is using, the configuration files content, the command line used and other details for reproducing)

nvv4l2h264enc returns frames in wrong order when PTS doesn’t align with framerate.
To reproduce the issue I’m using a pipeline with capssetter to change framerate. But this also can be reproduced by passing video file with PTS that doesn’t align with framerate to uridecodebin. E.g. a video captured from RTSP camera.
There’s no issue on dGPU.

The pipeline to reproduce the issue:

GST_TRACERS=stats \
GST_DEBUG=v4l2videoenc:7,videoencoder:7,GST_TRACER:7 \
GST_DEBUG_NO_COLOR=1 \
gst-launch-1.0 \
    videotestsrc pattern=ball num-buffers=20 ! \
    video/x-raw,format=RGBA,width=1280,height=720,framerate=25/1 ! \
    capssetter caps=video/x-raw,format=RGBA,width=1280,height=720,framerate=20/1 ! \
    queue ! \
    nvvideoconvert ! \
    queue ! \
    nvv4l2h264enc name=encoder ! \
    fakesink enable-last-sample=false sync=false qos=false

Command to run in docker

docker run \
    --rm \
    --name test \
    --entrypoint gst-launch-1.0 \
    --gpus all \
    -e GST_TRACERS=stats \
    -e GST_DEBUG=v4l2videoenc:7,videoencoder:7,GST_TRACER:7 \
    -e GST_DEBUG_NO_COLOR=1 \
    nvcr.io/nvidia/deepstream-l4t:6.2-base \
    videotestsrc pattern=ball num-buffers=20 ! \
    video/x-raw,format=RGBA,width=1280,height=720,framerate=25/1 ! \
    capssetter caps=video/x-raw,format=RGBA,width=1280,height=720,framerate=20/1 ! \
    queue ! \
    nvvideoconvert ! \
    queue ! \
    nvv4l2h264enc name=encoder ! \
    fakesink enable-last-sample=false sync=false qos=false

test.log (353.8 KB)

Encoder finishes frames in the wrong order:

finish frame fpn 0
finish frame fpn 1
finish frame fpn 2
finish frame fpn 4
finish frame fpn 5
finish frame fpn 6
finish frame fpn 3

See logs from encoder

$ grep -P 'Handling frame|finish frame fpn' test.log
0:00:02.158001929     1 0xaaaafadaaaa0 DEBUG           v4l2videoenc gstv4l2videoenc.c:1277:gst_v4l2_video_enc_handle_frame:<encoder> Handling frame 0
0:00:02.162098192     1 0xaaaafadaaaa0 DEBUG           v4l2videoenc gstv4l2videoenc.c:1277:gst_v4l2_video_enc_handle_frame:<encoder> Handling frame 1
0:00:02.166014935     1 0xaaaafadaaaa0 DEBUG           v4l2videoenc gstv4l2videoenc.c:1277:gst_v4l2_video_enc_handle_frame:<encoder> Handling frame 2
0:00:02.170873407     1 0xaaaafadaaaa0 DEBUG           v4l2videoenc gstv4l2videoenc.c:1277:gst_v4l2_video_enc_handle_frame:<encoder> Handling frame 3
0:00:02.187296251     1 0xaaaafb147d80 LOG             videoencoder gstvideoencoder.c:2094:gst_video_encoder_finish_frame:<encoder> finish frame fpn 0
0:00:02.227253920     1 0xaaaafadaaaa0 DEBUG           v4l2videoenc gstv4l2videoenc.c:1277:gst_v4l2_video_enc_handle_frame:<encoder> Handling frame 4
0:00:02.232206953     1 0xaaaafb147d80 LOG             videoencoder gstvideoencoder.c:2094:gst_video_encoder_finish_frame:<encoder> finish frame fpn 1
0:00:02.237703634     1 0xaaaafb147d80 LOG             videoencoder gstvideoencoder.c:2094:gst_video_encoder_finish_frame:<encoder> finish frame fpn 2
0:00:02.239353973     1 0xaaaafadaaaa0 DEBUG           v4l2videoenc gstv4l2videoenc.c:1277:gst_v4l2_video_enc_handle_frame:<encoder> Handling frame 5
0:00:02.242092570     1 0xaaaafb147d80 LOG             videoencoder gstvideoencoder.c:2094:gst_video_encoder_finish_frame:<encoder> finish frame fpn 4
0:00:02.245022847     1 0xaaaafadaaaa0 DEBUG           v4l2videoenc gstv4l2videoenc.c:1277:gst_v4l2_video_enc_handle_frame:<encoder> Handling frame 6
0:00:02.246944738     1 0xaaaafb147d80 LOG             videoencoder gstvideoencoder.c:2094:gst_video_encoder_finish_frame:<encoder> finish frame fpn 5
0:00:02.251862954     1 0xaaaafb147d80 LOG             videoencoder gstvideoencoder.c:2094:gst_video_encoder_finish_frame:<encoder> finish frame fpn 6
0:00:02.256076946     1 0xaaaafb147d80 LOG             videoencoder gstvideoencoder.c:2094:gst_video_encoder_finish_frame:<encoder> finish frame fpn 3
0:00:02.262300924     1 0xaaaafadaaaa0 DEBUG           v4l2videoenc gstv4l2videoenc.c:1277:gst_v4l2_video_enc_handle_frame:<encoder> Handling frame 7
0:00:02.269828713     1 0xaaaafadaaaa0 DEBUG           v4l2videoenc gstv4l2videoenc.c:1277:gst_v4l2_video_enc_handle_frame:<encoder> Handling frame 8
0:00:02.270747691     1 0xaaaafb147d80 LOG             videoencoder gstvideoencoder.c:2094:gst_video_encoder_finish_frame:<encoder> finish frame fpn 8
0:00:02.276297493     1 0xaaaafadaaaa0 DEBUG           v4l2videoenc gstv4l2videoenc.c:1277:gst_v4l2_video_enc_handle_frame:<encoder> Handling frame 9
0:00:02.277852599     1 0xaaaafb147d80 LOG             videoencoder gstvideoencoder.c:2094:gst_video_encoder_finish_frame:<encoder> finish frame fpn 9
0:00:02.282817312     1 0xaaaafadaaaa0 DEBUG           v4l2videoenc gstv4l2videoenc.c:1277:gst_v4l2_video_enc_handle_frame:<encoder> Handling frame 10
0:00:02.284311682     1 0xaaaafb147d80 LOG             videoencoder gstvideoencoder.c:2094:gst_video_encoder_finish_frame:<encoder> finish frame fpn 10
0:00:02.291174766     1 0xaaaafb147d80 LOG             videoencoder gstvideoencoder.c:2094:gst_video_encoder_finish_frame:<encoder> finish frame fpn 7
0:00:02.296334263     1 0xaaaafadaaaa0 DEBUG           v4l2videoenc gstv4l2videoenc.c:1277:gst_v4l2_video_enc_handle_frame:<encoder> Handling frame 11
0:00:02.302721634     1 0xaaaafadaaaa0 DEBUG           v4l2videoenc gstv4l2videoenc.c:1277:gst_v4l2_video_enc_handle_frame:<encoder> Handling frame 12
0:00:02.304665957     1 0xaaaafb147d80 LOG             videoencoder gstvideoencoder.c:2094:gst_video_encoder_finish_frame:<encoder> finish frame fpn 12
0:00:02.309529102     1 0xaaaafadaaaa0 DEBUG           v4l2videoenc gstv4l2videoenc.c:1277:gst_v4l2_video_enc_handle_frame:<encoder> Handling frame 13
0:00:02.312048690     1 0xaaaafb147d80 LOG             videoencoder gstvideoencoder.c:2094:gst_video_encoder_finish_frame:<encoder> finish frame fpn 13
0:00:02.315543832     1 0xaaaafadaaaa0 DEBUG           v4l2videoenc gstv4l2videoenc.c:1277:gst_v4l2_video_enc_handle_frame:<encoder> Handling frame 14
0:00:02.318851838     1 0xaaaafb147d80 LOG             videoencoder gstvideoencoder.c:2094:gst_video_encoder_finish_frame:<encoder> finish frame fpn 14
0:00:02.325387657     1 0xaaaafb147d80 LOG             videoencoder gstvideoencoder.c:2094:gst_video_encoder_finish_frame:<encoder> finish frame fpn 11
0:00:02.330813490     1 0xaaaafadaaaa0 DEBUG           v4l2videoenc gstv4l2videoenc.c:1277:gst_v4l2_video_enc_handle_frame:<encoder> Handling frame 15
0:00:02.337208829     1 0xaaaafadaaaa0 DEBUG           v4l2videoenc gstv4l2videoenc.c:1277:gst_v4l2_video_enc_handle_frame:<encoder> Handling frame 16
0:00:02.340952324     1 0xaaaafb147d80 LOG             videoencoder gstvideoencoder.c:2094:gst_video_encoder_finish_frame:<encoder> finish frame fpn 16
0:00:02.343819721     1 0xaaaafadaaaa0 DEBUG           v4l2videoenc gstv4l2videoenc.c:1277:gst_v4l2_video_enc_handle_frame:<encoder> Handling frame 17
0:00:02.347409679     1 0xaaaafb147d80 LOG             videoencoder gstvideoencoder.c:2094:gst_video_encoder_finish_frame:<encoder> finish frame fpn 17
0:00:02.349762003     1 0xaaaafadaaaa0 DEBUG           v4l2videoenc gstv4l2videoenc.c:1277:gst_v4l2_video_enc_handle_frame:<encoder> Handling frame 18
0:00:02.354417371     1 0xaaaafb147d80 LOG             videoencoder gstvideoencoder.c:2094:gst_video_encoder_finish_frame:<encoder> finish frame fpn 18
0:00:02.362244521     1 0xaaaafb147d80 LOG             videoencoder gstvideoencoder.c:2094:gst_video_encoder_finish_frame:<encoder> finish frame fpn 15
0:00:02.367514386     1 0xaaaafadaaaa0 DEBUG           v4l2videoenc gstv4l2videoenc.c:1277:gst_v4l2_video_enc_handle_frame:<encoder> Handling frame 19
0:00:02.379449254     1 0xaaaafb147d80 LOG             videoencoder gstvideoencoder.c:2094:gst_video_encoder_finish_frame:<encoder> finish frame fpn 19

PTS on the sinkpad of fakesink are also in the wrong order:

See PTS and DTS on the sinkpad of fakesink

$ grep "GST_TRACER :0:: buffer.*peer-element-ix=(uint)$(grep 'new-element.*fakesink' test.log | sed -re 's/.*, ix=\(uint\)([0-9]+),.*/\1/')" test.log | sed -re 's/.*pts=\(guint64\)([0-9]+),.*dts=\(guint64\)([0-9]+),.*/\1\t\2/'
0	0
40000000	40000000
80000000	80000000
160000000	120000000
200000000	160000000
240000000	200000000
120000000	240000000
320000000	280000000
360000000	320000000
400000000	360000000
280000000	400000000
480000000	440000000
520000000	480000000
560000000	520000000
440000000	560000000
640000000	600000000
680000000	640000000
720000000	680000000
600000000	720000000
760000000	760000000

Fiona.Chen · June 23, 2023, 9:32am

I’ve tried to recorded the video with the following pipeline:
gst-launch-1.0 videotestsrc pattern=18 num-buffers=120 ! video/x-raw,format=RGBA,width=1280,height=720,framerate=25/1 ! capssetter caps=video/x-raw,format=RGBA,width=1280,height=720,framerate=20/1 ! queue ! nvvideoconvert ! queue ! nvv4l2h264enc name=encoder ! h264parse ! m.video_0 qtmux name=m ! filesink location=test.mp4

If there is any PTS error in the video, you will see the ball moving forward and backward, but I don’t see any thing wrong.

kudryavtsev_ia · June 28, 2023, 10:08am

Hello, we have provided you with all the logs and instructions.

Please check PTS correctness with logs. It is not a trivial problem that can be analyzed visually. The bug is important: if you try to avoid certain frames from being passed to the encoder (because there is no valuable information), you will encounter the problem.

As we mentioned, the problem doesn’t exist on dGPU, only on Jetson. Regarding your visual estimation: players like FFmpeg are smart enough to fix it.

You may see no problem because the stream doesn’t include B-frames, so it is trivial to fix PTS, but if there are B-frames included, the situation is not so trivial as PTS doesn’t correspond to DTS.

The problem is occasional, not persistent (from the perspective of distribution in a video stream). Do you think you can see a single dropped frame that the player decided to ignore because of an error, or is your eye capable of seeing a 30-ms-length frame?

We prepared the proof, which results in logs, so you don’t rely on visuals but can check it qualifiedly.

Fiona.Chen · July 13, 2023, 7:39am

I’ve checked the timestamp inside the test.mp4 file generated. There are some wrong timestamps. We will investigate the issue internally.

kudryavtsev_ia · July 14, 2023, 5:46pm

Thank you for your detailed review of the issue. It is very important to get that fixed.

Fiona.Chen · July 17, 2023, 2:13am

Can you tell us which company you are working for? Why does your project need to support such stream with wrong framerate?

kudryavtsev_ia · July 17, 2023, 4:15am

Hello, we develop Savant: a general-purpose high-level CV framework on DeepStream. Thus we test various functions and need them to work properly. The one function is conditional video encoding which is affected by the bug. Our developer implemented a workaround rearranging the frames properly on Jetson, but we believe it is beneficial to fix it in the core.

tomskih_pa · July 8, 2024, 11:25am

Jetson Orin NX with DeepStream 6.4 has the same issue. But after adding identity sleep-time=1000000 element before nvv4l2h264enc the timestamps are correct. Looks like the problem appears when nvv4l2h264enc has frames in internal queue.

Topic		Replies	Views
Gst_nvvconv_transform: NvBufSurfTransform Failed : DeepStream SDK jetson , deepstream	5	36	September 30, 2024
Nvvideoconvert Memory Compatibility Error DeepStream SDK	6	577	September 6, 2022
Nvv4l2decoder driver bug error on Tesla T4 DeepStream SDK	11	1641	October 12, 2021
Gstreamer use nvdewarper frame lag and tear DeepStream SDK cudnn , jetson , deepstream	22	58	November 18, 2024
How to use DeepStream nvv4l2h264enc DeepStream SDK	6	2675	October 12, 2021
H.264 decoding failure Jetson Nano gstreamer	12	3672	October 18, 2021
revising streaming with Xavier Jetson AGX Xavier	12	1252	October 18, 2021
Jetson goes curling (or, simultaneously viewing multiple IP-cams) Jetson TK1	33	12050	November 28, 2014
RTSP latency does not work with NVSTREAMMUX DeepStream SDK nvbugs	37	5136	January 23, 2022
PTS values altered by nvv4l2h64enc DeepStream SDK nvbugs	16	1572	April 21, 2023

Nvv4l2h264enc returns frames in wrong order when PTS doesn't align with framerate

Related topics