Latency_measurement_buf_prob The results of the two latency tests differed greatly

complete information:
**• Hardware Platform (Jetson / GPU)Jetson
**• DeepStream Version 6.2
**• JetPack Version (valid for Jetson only) 5.0.2
**• TensorRT Version 8.4.1.5
**• NVIDIA GPU Driver Version (valid for GPU only) CUDA 11.4.239;cuDNN 8.4.1.50
**• Issue Type( questions, new requirements, bugs)questions

I tried to add latency_measurement_buf_prob to Deepstream Test3 When testing the latency of each plug-in of the pipeline, I found that the latency results at different times were very different (the 12-way RTSP stream I pulled during the test).

deepstream-test3-latency.zip (11.0 KB)
You should modify the RTSP and dstest3_pgie_config.yml of the source-list to reproduce.

Questions1
Here’s how late I tested it twice:
For the first time:
nvds_enable_latency_measurement is : 1

BATCH-NUM = 1673**
Comp name = nvv4l2decoder9 in_system_timestamp = 1733387221086.923096 out_system_timestamp = 1733387221089.014893 component latency= 2.091797
Comp name = nvstreammux-stream-muxer source_id = 3 pad_index = 3 frame_num = 1556 in_system_timestamp = 1733387221089.718018 out_system_timestamp = 1733387221100.105957 component_latency = 10.387939
Comp name = nvv4l2decoder5 in_system_timestamp = 1733387221088.268066 out_system_timestamp = 1733387221095.292969 component latency= 7.024902
Comp name = nvstreammux-stream-muxer source_id = 5 pad_index = 5 frame_num = 1201 in_system_timestamp = 1733387221096.023926 out_system_timestamp = 1733387221100.105957 component_latency = 4.082031
Comp name = nvv4l2decoder4 in_system_timestamp = 1733387221087.134033 out_system_timestamp = 1733387221095.541016 component latency= 8.406982
Comp name = nvstreammux-stream-muxer source_id = 0 pad_index = 0 frame_num = 1523 in_system_timestamp = 1733387221096.298096 out_system_timestamp = 1733387221100.105957 component_latency = 3.807861
Comp name = nvv4l2decoder1 in_system_timestamp = 1733387221087.221924 out_system_timestamp = 1733387221095.907959 component latency= 8.686035
Comp name = nvstreammux-stream-muxer source_id = 4 pad_index = 4 frame_num = 1109 in_system_timestamp = 1733387221096.339111 out_system_timestamp = 1733387221100.105957 component_latency = 3.766846
Comp name = nvv4l2decoder10 in_system_timestamp = 1733387221088.422119 out_system_timestamp = 1733387221096.096924 component latency= 7.674805
Comp name = nvstreammux-stream-muxer source_id = 11 pad_index = 11 frame_num = 1519 in_system_timestamp = 1733387221096.826904 out_system_timestamp = 1733387221100.105957 component_latency = 3.279053
Comp name = nvv4l2decoder2 in_system_timestamp = 1733387221087.240967 out_system_timestamp = 1733387221096.402100 component latency= 9.161133
Comp name = nvstreammux-stream-muxer source_id = 2 pad_index = 2 frame_num = 1517 in_system_timestamp = 1733387221097.072998 out_system_timestamp = 1733387221100.105957 component_latency = 3.032959
Comp name = nvv4l2decoder6 in_system_timestamp = 1733387221087.250977 out_system_timestamp = 1733387221096.997070 component latency= 9.746094
Comp name = nvstreammux-stream-muxer source_id = 1 pad_index = 1 frame_num = 1072 in_system_timestamp = 1733387221097.656006 out_system_timestamp = 1733387221100.105957 component_latency = 2.449951
Comp name = nvv4l2decoder8 in_system_timestamp = 1733387221087.506104 out_system_timestamp = 1733387221097.821045 component latency= 10.314941
Comp name = nvstreammux-stream-muxer source_id = 8 pad_index = 8 frame_num = 1451 in_system_timestamp = 1733387221098.437988 out_system_timestamp = 1733387221100.105957 component_latency = 1.667969
Comp name = nvv4l2decoder7 in_system_timestamp = 1733387221087.677979 out_system_timestamp = 1733387221098.587891 component latency= 10.909912
Comp name = nvstreammux-stream-muxer source_id = 6 pad_index = 6 frame_num = 1279 in_system_timestamp = 1733387221099.055908 out_system_timestamp = 1733387221100.105957 component_latency = 1.050049
Comp name = nvv4l2decoder0 in_system_timestamp = 1733387221087.980957 out_system_timestamp = 1733387221099.128906 component latency= 11.147949
Comp name = nvstreammux-stream-muxer source_id = 9 pad_index = 9 frame_num = 1531 in_system_timestamp = 1733387221099.657959 out_system_timestamp = 1733387221100.105957 component_latency = 0.447998
Comp name = nvv4l2decoder3 in_system_timestamp = 1733387221087.886963 out_system_timestamp = 1733387221098.957031 component latency= 11.070068
Comp name = nvstreammux-stream-muxer source_id = 10 pad_index = 10 frame_num = 1533 in_system_timestamp = 1733387221099.666016 out_system_timestamp = 1733387221100.105957 component_latency = 0.439941
Comp name = nvv4l2decoder11 in_system_timestamp = 1733387221088.043945 out_system_timestamp = 1733387221099.393066 component latency= 11.349121
Comp name = nvstreammux-stream-muxer source_id = 7 pad_index = 7 frame_num = 1029 in_system_timestamp = 1733387221100.076904 out_system_timestamp = 1733387221100.105957 component_latency = 0.029053
Comp name = primary-nvinference-engine in_system_timestamp = 1733387221114.606934 out_system_timestamp = 1733387221141.728027 component latency= 27.121094
Comp name = nvtiler in_system_timestamp = 1733387221141.843994 out_system_timestamp = 1733387221160.225098 component latency= 18.381104
Comp name = nvvideo-converter in_system_timestamp = 1733387221160.801025 out_system_timestamp = 1733387221161.697021 component latency= 0.895996
Comp name = nv-onscreendisplay in_system_timestamp = 1733387221161.816895 out_system_timestamp = 1733387221162.528076 component latency= 0.711182
Source id = 3 Frame_num = 1556 Frame latency = 75.694824 (ms)
Source id = 5 Frame_num = 1201 Frame latency = 74.349854 (ms)
Source id = 0 Frame_num = 1523 Frame latency = 75.483887 (ms)
Source id = 4 Frame_num = 1109 Frame latency = 75.395996 (ms)
Source id = 11 Frame_num = 1519 Frame latency = 74.195801 (ms)
Source id = 2 Frame_num = 1517 Frame latency = 75.376953 (ms)
Source id = 1 Frame_num = 1072 Frame latency = 75.366943 (ms)
Source id = 8 Frame_num = 1451 Frame latency = 75.111816 (ms)
Source id = 6 Frame_num = 1279 Frame latency = 74.939941 (ms)
Source id = 9 Frame_num = 1531 Frame latency = 74.636963 (ms)
Source id = 10 Frame_num = 1533 Frame latency = 74.730957 (ms)
Source id = 7 Frame_num = 1029 Frame latency = 74.573975 (ms)
0:04:14.603927499 962157 0xaaaaf40b0b60 TRACE GST_TRACER :0:: latency, src-element-id=(string)0xfffe9c00cc00, src-element=(string)udpsrc27, src=(string)src, sink-element-id=(string)0xaaaaf4bd03c0, sink-element=(string)nv3d-sink, sink=(string)sink, time=(guint64)134104873, ts=(guint64)254603876106;

second time:
nvds_enable_latency_measurement is : 1

BATCH-NUM = 209**
Comp name = nvv4l2decoder10 in_system_timestamp = 1733480950170.841064 out_system_timestamp = 1733480950264.981934 component latency= 94.140869
Comp name = nvstreammux-stream-muxer source_id = 9 pad_index = 9 frame_num = 197 in_system_timestamp = 1733480950265.029053 out_system_timestamp = 1733480950313.181885 component_latency = 48.152832
Comp name = nvv4l2decoder8 in_system_timestamp = 1733480950205.176025 out_system_timestamp = 1733480950257.156982 component latency= 51.980957
Comp name = nvstreammux-stream-muxer source_id = 0 pad_index = 0 frame_num = 198 in_system_timestamp = 1733480950257.197021 out_system_timestamp = 1733480950313.181885 component_latency = 55.984863
Comp name = nvv4l2decoder3 in_system_timestamp = 1733480950183.861084 out_system_timestamp = 1733480950280.308105 component latency= 96.447021
Comp name = nvstreammux-stream-muxer source_id = 1 pad_index = 1 frame_num = 199 in_system_timestamp = 1733480950280.344971 out_system_timestamp = 1733480950313.181885 component_latency = 32.836914
Comp name = nvv4l2decoder4 in_system_timestamp = 1733480950191.086914 out_system_timestamp = 1733480950288.048096 component latency= 96.961182
Comp name = nvstreammux-stream-muxer source_id = 2 pad_index = 2 frame_num = 199 in_system_timestamp = 1733480950288.105957 out_system_timestamp = 1733480950313.181885 component_latency = 25.075928
Comp name = nvv4l2decoder7 in_system_timestamp = 1733480950198.749023 out_system_timestamp = 1733480950295.781006 component latency= 97.031982
Comp name = nvstreammux-stream-muxer source_id = 3 pad_index = 3 frame_num = 197 in_system_timestamp = 1733480950295.831055 out_system_timestamp = 1733480950313.181885 component_latency = 17.350830
Comp name = nvv4l2decoder2 in_system_timestamp = 1733480950148.779053 out_system_timestamp = 1733480950234.116943 component latency= 85.337891
Comp name = nvstreammux-stream-muxer source_id = 4 pad_index = 4 frame_num = 200 in_system_timestamp = 1733480950234.156006 out_system_timestamp = 1733480950313.183105 component_latency = 79.027100
Comp name = nvv4l2decoder1 in_system_timestamp = 1733480950164.381104 out_system_timestamp = 1733480950249.564941 component latency= 85.183838
Comp name = nvstreammux-stream-muxer source_id = 5 pad_index = 5 frame_num = 197 in_system_timestamp = 1733480950249.615967 out_system_timestamp = 1733480950313.183105 component_latency = 63.567139
Comp name = nvv4l2decoder9 in_system_timestamp = 1733480950219.112061 out_system_timestamp = 1733480950311.224121 component latency= 92.112061
Comp name = nvstreammux-stream-muxer source_id = 6 pad_index = 6 frame_num = 196 in_system_timestamp = 1733480950311.277100 out_system_timestamp = 1733480950313.183105 component_latency = 1.906006
Comp name = nvv4l2decoder5 in_system_timestamp = 1733480950177.091064 out_system_timestamp = 1733480950272.673096 component latency= 95.582031
Comp name = nvstreammux-stream-muxer source_id = 7 pad_index = 7 frame_num = 198 in_system_timestamp = 1733480950272.719971 out_system_timestamp = 1733480950313.183105 component_latency = 40.463135
Comp name = nvv4l2decoder0 in_system_timestamp = 1733480950212.014893 out_system_timestamp = 1733480950303.607910 component latency= 91.593018
Comp name = nvstreammux-stream-muxer source_id = 8 pad_index = 8 frame_num = 198 in_system_timestamp = 1733480950303.672119 out_system_timestamp = 1733480950313.183105 component_latency = 9.510986
Comp name = primary-nvinference-engine in_system_timestamp = 1733480950313.245117 out_system_timestamp = 1733480950339.681885 component latency= 26.436768
Comp name = nvtiler in_system_timestamp = 1733480950553.333984 out_system_timestamp = 1733480950574.867920 component latency= 21.533936
Comp name = nvvideo-converter in_system_timestamp = 1733480950818.933105 out_system_timestamp = 1733480950820.281982 component latency= 1.348877
Comp name = nv-onscreendisplay in_system_timestamp = 1733480950820.395996 out_system_timestamp = 1733480950820.416016 component latency= 0.020020
Source id = 9 Frame_num = 197 Frame latency = 649.631836 (ms)
Source id = 0 Frame_num = 198 Frame latency = 615.296875 (ms)
Source id = 1 Frame_num = 199 Frame latency = 636.611816 (ms)
Source id = 2 Frame_num = 199 Frame latency = 629.385986 (ms)
Source id = 3 Frame_num = 197 Frame latency = 621.723877 (ms)
Source id = 4 Frame_num = 200 Frame latency = 671.693848 (ms)
Source id = 5 Frame_num = 197 Frame latency = 656.091797 (ms)
Source id = 6 Frame_num = 196 Frame latency = 601.360840 (ms)
Source id = 7 Frame_num = 198 Frame latency = 643.381836 (ms)
Source id = 8 Frame_num = 198 Frame latency = 608.458008 (ms)

Questions2

  1. Use GST_TRACERS=“latency(flags=pipeline)” GST_DEBUG=GST_TRACER:7 ./deepstream ./dstest3.yaml to test whether the delay is the latency of the entire pipeline?
  2. GST_TRACER :0:: latency, src-element-id=(string)0xfffe9c00cc00, src-element=(string)udpsrc27, src=(string)src, sink-element-id=(string)0xaaaaf4bd03c0, sink-element=(string)nv3d-sink, sink=(string)sink, time=(guint64)134104873, ts=(guint64)254603876106;

Is time=(guint64)134104873 134ms in the above log?

Same as the question in the link below:
An understanding of the delay result produced by latency_measurement_buf_probe - Intelligent Video Analytics / DeepStream SDK - NVIDIA Developer Forums

Since it is duplicated with An understanding of the delay result produced by latency_measurement_buf_probe - Intelligent Video Analytics / DeepStream SDK - NVIDIA Developer Forums. Close this one.

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