The most efficient method to evaluate time each plugin (in DeepStream)cost?

Please provide complete information as applicable to your setup. **
• Hardware Platform (Jetson / GPU) NX **
• DeepStream Version 5.1 **
• JetPack Version (valid for Jetson only) 4.4 **
• TensorRT Version 7.1 **
• NVIDIA GPU Driver Version (valid for GPU only) 10.2 **
• Issue Type( questions, new requirements, bugs) questions **
• How to reproduce the issue ? This is development questions, we want to know how to evaluate time for each plugin in deepstream pipeline.
• Requirement details

Would you please tell me the most efficient method to evaluate time each plugin cost? Thanks!

Please check this,
DeepStream SDK FAQ - Intelligent Video Analytics / DeepStream SDK - NVIDIA Developer Forums Enable Latency measurement for deepstream sample apps

Hi,

Thanks for your response.

deepstream-app (config file is: source12_1080p_dec_infer-resnet_tracker_tiled_display_fp16_tx2.txt )

has print messge like this, I want to know whether it is reasonable.

  1. Is compent latency unit is ms?
  2. Frame latency is about 700ms, but “PERF” is 25, how can they match? I see no obvious delay in display window.

Comp name = nvv4l2decoder2 in_system_timestamp = 1627981884473.815918 out_system_timestamp = 1627981884885.383057 component latency= 411.567139 → Is it ms?
Comp name = src_bin_muxer source_id = 10 pad_index = 10 frame_num = 211 in_system_timestamp = 1627981884885.531982 out_system_timestamp = 1627981884921.508057 component_latency = 35.976074
Comp name = nvv4l2decoder11 in_system_timestamp = 1627981884479.458008 out_system_timestamp = 1627981884888.670898 component latency= 409.212891
Comp name = src_bin_muxer source_id = 0 pad_index = 0 frame_num = 209 in_system_timestamp = 1627981884888.853027 out_system_timestamp = 1627981884921.508057 component_latency = 32.655029
Comp name = nvv4l2decoder4 in_system_timestamp = 1627981884476.093994 out_system_timestamp = 1627981884889.753906 component latency= 413.659912
Comp name = src_bin_muxer source_id = 1 pad_index = 1 frame_num = 211 in_system_timestamp = 1627981884889.886963 out_system_timestamp = 1627981884921.509033 component_latency = 31.622070
Comp name = nvv4l2decoder6 in_system_timestamp = 1627981884474.951904 out_system_timestamp = 1627981884890.599121 component latency= 415.647217
Comp name = src_bin_muxer source_id = 2 pad_index = 2 frame_num = 211 in_system_timestamp = 1627981884890.735107 out_system_timestamp = 1627981884921.509033 component_latency = 30.773926
Comp name = nvv4l2decoder3 in_system_timestamp = 1627981884473.780029 out_system_timestamp = 1627981884891.916992 component latency= 418.136963
Comp name = src_bin_muxer source_id = 4 pad_index = 4 frame_num = 209 in_system_timestamp = 1627981884892.082031 out_system_timestamp = 1627981884921.509033 component_latency = 29.427002
Comp name = nvv4l2decoder0 in_system_timestamp = 1627981884474.635010 out_system_timestamp = 1627981884894.041016 component latency= 419.406006
Comp name = src_bin_muxer source_id = 7 pad_index = 7 frame_num = 209 in_system_timestamp = 1627981884894.272949 out_system_timestamp = 1627981884921.509033 component_latency = 27.236084
Comp name = nvv4l2decoder1 in_system_timestamp = 1627981884408.022949 out_system_timestamp = 1627981884916.481934 component latency= 508.458984
Comp name = src_bin_muxer source_id = 11 pad_index = 11 frame_num = 208 in_system_timestamp = 1627981884917.289062 out_system_timestamp = 1627981884921.509033 component_latency = 4.219971
Comp name = nvv4l2decoder5 in_system_timestamp = 1627981884407.516113 out_system_timestamp = 1627981884917.409912 component latency= 509.893799
Comp name = src_bin_muxer source_id = 3 pad_index = 3 frame_num = 208 in_system_timestamp = 1627981884917.635986 out_system_timestamp = 1627981884921.510010 component_latency = 3.874023
Comp name = nvv4l2decoder9 in_system_timestamp = 1627981884405.874023 out_system_timestamp = 1627981884917.489990 component latency= 511.615967
Comp name = src_bin_muxer source_id = 5 pad_index = 5 frame_num = 210 in_system_timestamp = 1627981884917.675049 out_system_timestamp = 1627981884921.510010 component_latency = 3.834961
Comp name = nvv4l2decoder10 in_system_timestamp = 1627981884409.489990 out_system_timestamp = 1627981884917.528076 component latency= 508.038086
Comp name = src_bin_muxer source_id = 6 pad_index = 6 frame_num = 208 in_system_timestamp = 1627981884917.697998 out_system_timestamp = 1627981884921.510010 component_latency = 3.812012
Comp name = nvv4l2decoder7 in_system_timestamp = 1627981884408.485107 out_system_timestamp = 1627981884919.400879 component latency= 510.915771
Comp name = src_bin_muxer source_id = 8 pad_index = 8 frame_num = 208 in_system_timestamp = 1627981884919.709961 out_system_timestamp = 1627981884921.510010 component_latency = 1.800049
Comp name = nvv4l2decoder8 in_system_timestamp = 1627981884407.990967 out_system_timestamp = 1627981884918.370117 component latency= 510.379150
Comp name = src_bin_muxer source_id = 9 pad_index = 9 frame_num = 208 in_system_timestamp = 1627981884918.459961 out_system_timestamp = 1627981884921.510010 component_latency = 3.050049
Comp name = primary_gie in_system_timestamp = 1627981884921.563965 out_system_timestamp = 1627981884956.114990 component latency= 34.551025
Comp name = tracking_tracker in_system_timestamp = 1627981884956.150879 out_system_timestamp = 1627981885000.101074 component latency= 43.950195
Comp name = tiled_display_tiler in_system_timestamp = 1627981885032.174072 out_system_timestamp = 1627981885044.089111 component latency= 11.915039
Comp name = osd_conv in_system_timestamp = 1627981885129.451904 out_system_timestamp = 1627981885132.058105 component latency= 2.606201
Comp name = nvosd0 in_system_timestamp = 1627981885132.687012 out_system_timestamp = 1627981885133.831055 component latency= 1.144043
Source id = 10 Frame_num = 211 Frame latency = 707.656006 (ms)
Source id = 0 Frame_num = 209 Frame latency = 702.013916 (ms)
Source id = 1 Frame_num = 211 Frame latency = 705.377930 (ms)
Source id = 2 Frame_num = 211 Frame latency = 706.520020 (ms)
Source id = 4 Frame_num = 209 Frame latency = 707.691895 (ms)
Source id = 7 Frame_num = 209 Frame latency = 706.836914 (ms)
Source id = 11 Frame_num = 208 Frame latency = 773.448975 (ms)
Source id = 3 Frame_num = 208 Frame latency = 773.955811 (ms)
Source id = 5 Frame_num = 210 Frame latency = 775.597900 (ms)
Source id = 6 Frame_num = 208 Frame latency = 771.981934 (ms)
Source id = 8 Frame_num = 208 Frame latency = 772.986816 (ms)
Source id = 9 Frame_num = 208 Frame latency = 773.480957 (ms)

BATCH-NUM = 212**
Comp name = nvv4l2decoder2 in_system_timestamp = 1627981884453.597900 out_system_timestamp = 1627981884918.232910 component latency= 464.635010
Comp name = src_bin_muxer source_id = 10 pad_index = 10 frame_num = 212 in_system_timestamp = 1627981884918.301025 out_system_timestamp = 1627981884954.457031 component_latency = 36.156006
Comp name = nvv4l2decoder1 in_system_timestamp = 1627981884529.069092 out_system_timestamp = 1627981884916.613037 component latency= 387.543945
Comp name = src_bin_muxer source_id = 11 pad_index = 11 frame_num = 209 in_system_timestamp = 1627981884920.387939 out_system_timestamp = 1627981884954.457031 component_latency = 34.069092
Comp name = nvv4l2decoder4 in_system_timestamp = 1627981884459.672119 out_system_timestamp = 1627981884918.719971 component latency= 459.047852
Comp name = src_bin_muxer source_id = 1 pad_index = 1 frame_num = 212 in_system_timestamp = 1627981884918.961914 out_system_timestamp = 1627981884954.457031 component_latency = 35.495117
Comp name = nvv4l2decoder6 in_system_timestamp = 1627981884455.013916 out_system_timestamp = 1627981884918.697021 component latency= 463.683105
Comp name = src_bin_muxer source_id = 2 pad_index = 2 frame_num = 212 in_system_timestamp = 1627981884918.934082 out_system_timestamp = 1627981884954.457031 component_latency = 35.522949
Comp name = nvv4l2decoder5 in_system_timestamp = 1627981884531.343994 out_system_timestamp = 1627981884917.785889 component latency= 386.441895
Comp name = src_bin_muxer source_id = 3 pad_index = 3 frame_num = 209 in_system_timestamp = 1627981884920.419922 out_system_timestamp = 1627981884954.458008 component_latency = 34.038086
Comp name = nvv4l2decoder9 in_system_timestamp = 1627981884530.553955 out_system_timestamp = 1627981884917.576904 component latency= 387.022949
Comp name = src_bin_muxer source_id = 5 pad_index = 5 frame_num = 211 in_system_timestamp = 1627981884920.631104 out_system_timestamp = 1627981884954.458008 component_latency = 33.826904
Comp name = nvv4l2decoder10 in_system_timestamp = 1627981884531.251953 out_system_timestamp = 1627981884917.583984 component latency= 386.332031
Comp name = src_bin_muxer source_id = 6 pad_index = 6 frame_num = 209 in_system_timestamp = 1627981884920.636963 out_system_timestamp = 1627981884954.458008 component_latency = 33.821045
Comp name = nvv4l2decoder7 in_system_timestamp = 1627981884530.034912 out_system_timestamp = 1627981884919.467041 component latency= 389.432129
Comp name = src_bin_muxer source_id = 8 pad_index = 8 frame_num = 209 in_system_timestamp = 1627981884921.185059 out_system_timestamp = 1627981884954.458008 component_latency = 33.272949
Comp name = nvv4l2decoder8 in_system_timestamp = 1627981884531.791992 out_system_timestamp = 1627981884918.424072 component latency= 386.632080
Comp name = src_bin_muxer source_id = 9 pad_index = 9 frame_num = 209 in_system_timestamp = 1627981884921.205078 out_system_timestamp = 1627981884954.458008 component_latency = 33.252930
Comp name = nvv4l2decoder11 in_system_timestamp = 1627981884476.641113 out_system_timestamp = 1627981884951.281982 component latency= 474.640869
Comp name = src_bin_muxer source_id = 0 pad_index = 0 frame_num = 210 in_system_timestamp = 1627981884954.198975 out_system_timestamp = 1627981884954.458008 component_latency = 0.259033
Comp name = nvv4l2decoder3 in_system_timestamp = 1627981884452.771973 out_system_timestamp = 1627981884953.008057 component latency= 500.236084
Comp name = src_bin_muxer source_id = 4 pad_index = 4 frame_num = 210 in_system_timestamp = 1627981884954.232910 out_system_timestamp = 1627981884954.458984 component_latency = 0.226074
Comp name = nvv4l2decoder0 in_system_timestamp = 1627981884456.447021 out_system_timestamp = 1627981884952.968018 component latency= 496.520996
Comp name = src_bin_muxer source_id = 7 pad_index = 7 frame_num = 210 in_system_timestamp = 1627981884954.264893 out_system_timestamp = 1627981884954.458984 component_latency = 0.194092
Comp name = primary_gie in_system_timestamp = 1627981884954.599121 out_system_timestamp = 1627981884993.627930 component latency= 39.028809
Comp name = tracking_tracker in_system_timestamp = 1627981884993.683105 out_system_timestamp = 1627981885027.315918 component latency= 33.632812
Comp name = tiled_display_tiler in_system_timestamp = 1627981885063.824951 out_system_timestamp = 1627981885071.133057 component latency= 7.308105
Comp name = osd_conv in_system_timestamp = 1627981885163.148926 out_system_timestamp = 1627981885164.018066 component latency= 0.869141
Comp name = nvosd0 in_system_timestamp = 1627981885164.518066 out_system_timestamp = 1627981885166.062012 component latency= 1.543945
Source id = 10 Frame_num = 212 Frame latency = 761.643066 (ms)
Source id = 11 Frame_num = 209 Frame latency = 686.171875 (ms)
Source id = 1 Frame_num = 212 Frame latency = 755.568848 (ms)
Source id = 2 Frame_num = 212 Frame latency = 760.227051 (ms)
Source id = 3 Frame_num = 209 Frame latency = 683.896973 (ms)
Source id = 5 Frame_num = 211 Frame latency = 684.687012 (ms)
Source id = 6 Frame_num = 209 Frame latency = 683.989014 (ms)
Source id = 8 Frame_num = 209 Frame latency = 685.206055 (ms)
Source id = 9 Frame_num = 209 Frame latency = 683.448975 (ms)
Source id = 0 Frame_num = 210 Frame latency = 738.599854 (ms)
Source id = 4 Frame_num = 210 Frame latency = 762.468994 (ms)
Source id = 7 Frame_num = 210 Frame latency = 758.793945 (ms)

Did you run with local file? please be noted it’s only for rtsp stream or camera.

Yes, for deepstream-app it is local file.
Do you mean the print messages “frame latency” and “component latency” in deepstream-app is useless?

No, the latency is only used for rtsp stream/camera. for local file, it will have large latency for decoder.

ok, thanks. The component latency is ms? right? Is it related to GPU frequency?

Comp name = primary_gie in_system_timestamp = 1627981884921.563965 out_system_timestamp = 1627981884956.114990 component latency= 34.551025

Yes, it’s ms. and GPU frequency have impact on the components performance, like nvinfer, nvstreammux, nvosd, nvtracker, nvvideoconvert, etc. some components used both CPU, GPU, you can find details from each plugin documentation.