Deepstream-app displays latency information twice for each frame

Accelerated Computing Intelligent Video Analytics DeepStream SDK
1

Please provide complete information as applicable to your setup.

• Hardware Platform ( RTX 2080 Ti)
• DeepStream Version 5.0
• TensorRT Version 7
• NVIDIA GPU Driver Version 450.36.06 CUDA Version: 11.0

The default deepstream-app with YoloV3 (using objectDetector_Yolo sample provided by NVIDIA) displays the latency measurements twice for each frame as below.
The output below is when only Mux-Tile-Demux-Osd is enabled in the config.
8 Inputs are from RTSP streams and has 8 output RTSP Streams.

Is this normal? Or is the frame processed twice? Or Am I missing something?

BATCH-NUM = 786**
Comp name = nvv4l2decoder7 in_system_timestamp = 1594367645297.946045 out_system_timestamp = 1594367645381.386963 component latency= 83.440918
Comp name = src_bin_muxer source_id = 2 pad_index = 2 frame_num = 393 in_system_timestamp = 1594367645381.424072 out_system_timestamp = 1594367645381.800049 component_latency = 0.375977
Comp name = nvv4l2decoder2 in_system_timestamp = 1594367645297.982910 out_system_timestamp = 1594367645381.493896 component latency= 83.510986
Comp name = src_bin_muxer source_id = 6 pad_index = 6 frame_num = 393 in_system_timestamp = 1594367645381.519043 out_system_timestamp = 1594367645381.800049 component_latency = 0.281006
Comp name = nvv4l2decoder3 in_system_timestamp = 1594367645297.933105 out_system_timestamp = 1594367645381.575928 component latency= 83.642822
Comp name = src_bin_muxer source_id = 3 pad_index = 3 frame_num = 393 in_system_timestamp = 1594367645381.595947 out_system_timestamp = 1594367645381.801025 component_latency = 0.205078
Comp name = nvv4l2decoder1 in_system_timestamp = 1594367645297.930908 out_system_timestamp = 1594367645381.689941 component latency= 83.759033
Comp name = src_bin_muxer source_id = 7 pad_index = 7 frame_num = 393 in_system_timestamp = 1594367645381.724121 out_system_timestamp = 1594367645381.801025 component_latency = 0.076904
Comp name = nvv4l2decoder5 in_system_timestamp = 1594367645298.030029 out_system_timestamp = 1594367645381.685059 component latency= 83.655029
Comp name = src_bin_muxer source_id = 1 pad_index = 1 frame_num = 393 in_system_timestamp = 1594367645381.721924 out_system_timestamp = 1594367645381.801025 component_latency = 0.079102
Comp name = nvv4l2decoder6 in_system_timestamp = 1594367645297.930908 out_system_timestamp = 1594367645381.707031 component latency= 83.776123
Comp name = src_bin_muxer source_id = 4 pad_index = 4 frame_num = 393 in_system_timestamp = 1594367645381.727051 out_system_timestamp = 1594367645381.801025 component_latency = 0.073975
Comp name = nvv4l2decoder0 in_system_timestamp = 1594367645297.971924 out_system_timestamp = 1594367645381.727051 component latency= 83.755127
Comp name = src_bin_muxer source_id = 0 pad_index = 0 frame_num = 393 in_system_timestamp = 1594367645381.746094 out_system_timestamp = 1594367645381.801025 component_latency = 0.054932
Comp name = nvv4l2decoder4 in_system_timestamp = 1594367645298.031982 out_system_timestamp = 1594367645381.760010 component latency= 83.728027
Comp name = src_bin_muxer source_id = 5 pad_index = 5 frame_num = 393 in_system_timestamp = 1594367645381.779053 out_system_timestamp = 1594367645381.801025 component_latency = 0.021973
Comp name = tracking_tracker in_system_timestamp = 1594367645381.809082 out_system_timestamp = 1594367645384.010986 component latency= 2.201904
Comp name = tiled_display_tiler in_system_timestamp = 1594367645384.047119 out_system_timestamp = 1594367645384.291016 component latency= 0.243896
Comp name = nvosd0 in_system_timestamp = 1594367645384.502930 out_system_timestamp = 1594367645385.145996 component latency= 0.643066
Source id = 2 Frame_num = 393 Frame latency = 133.633057 (ms)
Source id = 6 Frame_num = 393 Frame latency = 133.596191 (ms)
Source id = 3 Frame_num = 393 Frame latency = 133.645996 (ms)
Source id = 7 Frame_num = 393 Frame latency = 133.648193 (ms)
Source id = 1 Frame_num = 393 Frame latency = 133.549072 (ms)
Source id = 4 Frame_num = 393 Frame latency = 133.648193 (ms)
Source id = 0 Frame_num = 393 Frame latency = 133.607178 (ms)
Source id = 5 Frame_num = 393 Frame latency = 133.547119 (ms)

BATCH-NUM = 787**
Comp name = nvv4l2decoder7 in_system_timestamp = 1594367645297.946045 out_system_timestamp = 1594367645381.386963 component latency= 83.440918
Comp name = src_bin_muxer source_id = 2 pad_index = 2 frame_num = 393 in_system_timestamp = 1594367645381.424072 out_system_timestamp = 1594367645381.800049 component_latency = 0.375977
Comp name = nvv4l2decoder2 in_system_timestamp = 1594367645297.982910 out_system_timestamp = 1594367645381.493896 component latency= 83.510986
Comp name = src_bin_muxer source_id = 6 pad_index = 6 frame_num = 393 in_system_timestamp = 1594367645381.519043 out_system_timestamp = 1594367645381.800049 component_latency = 0.281006
Comp name = nvv4l2decoder3 in_system_timestamp = 1594367645297.933105 out_system_timestamp = 1594367645381.575928 component latency= 83.642822
Comp name = src_bin_muxer source_id = 3 pad_index = 3 frame_num = 393 in_system_timestamp = 1594367645381.595947 out_system_timestamp = 1594367645381.801025 component_latency = 0.205078
Comp name = nvv4l2decoder1 in_system_timestamp = 1594367645297.930908 out_system_timestamp = 1594367645381.689941 component latency= 83.759033
Comp name = src_bin_muxer source_id = 7 pad_index = 7 frame_num = 393 in_system_timestamp = 1594367645381.724121 out_system_timestamp = 1594367645381.801025 component_latency = 0.076904
Comp name = nvv4l2decoder5 in_system_timestamp = 1594367645298.030029 out_system_timestamp = 1594367645381.685059 component latency= 83.655029
Comp name = src_bin_muxer source_id = 1 pad_index = 1 frame_num = 393 in_system_timestamp = 1594367645381.721924 out_system_timestamp = 1594367645381.801025 component_latency = 0.079102
Comp name = nvv4l2decoder6 in_system_timestamp = 1594367645297.930908 out_system_timestamp = 1594367645381.707031 component latency= 83.776123
Comp name = src_bin_muxer source_id = 4 pad_index = 4 frame_num = 393 in_system_timestamp = 1594367645381.727051 out_system_timestamp = 1594367645381.801025 component_latency = 0.073975
Comp name = nvv4l2decoder0 in_system_timestamp = 1594367645297.971924 out_system_timestamp = 1594367645381.727051 component latency= 83.755127
Comp name = src_bin_muxer source_id = 0 pad_index = 0 frame_num = 393 in_system_timestamp = 1594367645381.746094 out_system_timestamp = 1594367645381.801025 component_latency = 0.054932
Comp name = nvv4l2decoder4 in_system_timestamp = 1594367645298.031982 out_system_timestamp = 1594367645381.760010 component latency= 83.728027
Comp name = src_bin_muxer source_id = 5 pad_index = 5 frame_num = 393 in_system_timestamp = 1594367645381.779053 out_system_timestamp = 1594367645381.801025 component_latency = 0.021973
Comp name = tracking_tracker in_system_timestamp = 1594367645381.809082 out_system_timestamp = 1594367645384.010986 component latency= 2.201904
Comp name = tiled_display_tiler in_system_timestamp = 1594367645384.047119 out_system_timestamp = 1594367645384.291016 component latency= 0.243896
Comp name = nvosd0 in_system_timestamp = 1594367645384.502930 out_system_timestamp = 1594367645385.145996 component latency= 0.643066
Source id = 2 Frame_num = 393 Frame latency = 133.880859 (ms)
Source id = 6 Frame_num = 393 Frame latency = 133.843994 (ms)
Source id = 3 Frame_num = 393 Frame latency = 133.893799 (ms)
Source id = 7 Frame_num = 393 Frame latency = 133.895996 (ms)
Source id = 1 Frame_num = 393 Frame latency = 133.796875 (ms)
Source id = 4 Frame_num = 393 Frame latency = 133.895996 (ms)
Source id = 0 Frame_num = 393 Frame latency = 133.854980 (ms)
Source id = 5 Frame_num = 393 Frame latency = 133.794922 (ms)

3

Hi,
I have reproed your issue, will update to you ASAP.

4

Thank you and will look forward to your response. It appears as if the buffers are being processed more than once and it may even be related to this:
https://forums.developer.nvidia.com/t/deepstream-app-buffer-caching-observed-when-using-yolov3-with-multiple-rtsp-output-streams/140298/9

5

Fix will be available in upcoming release.
but you could comment below code, and recompile deepstream-app

from line 1236
NVGSTDS_ELEM_ADD_PROBE (latency_probe_id,
pipeline->instance_bins->sink_bin.sub_bins[0].sink, “sink”,
latency_measurement_buf_prob, GST_PAD_PROBE_TYPE_BUFFER,
appCtx);