I am debugging my pipeline, since I find it slow, when I work with more than one streams. In the DS Troubleshouting guide I found these, which may be interesting to me:
One of the plugins in the pipeline may be running slowly. You can measure the latency of each plugin in the pipeline to determine if one of them is slow. * To enable frame latency measurement, run this command on the console:
$ export NVDS_ENABLE_LATENCY_MEASUREMENT=1
To enable latency for all plugins, run this command on the console:
$ export NVDS_ENABLE_COMPONENT_LATENCY_MEASUREMENT=1
So I set the above environmental variables to 1, and I restart my (c/c++) application. I experience no difference. What should the above variables turn on? Extra logging? I cannot see any additional lines compared to my previous runs. Do them generate any kind of report? Where?
What do you mean no difference? to enable this variable NVDS_ENABLE_LATENCY_MEASUREMENT you can get the frame latency, from this NVDS_ENABLE_COMPONENT_LATENCY_MEASUREMENT, you can get each component latency, like decoder, streammux, nvinfer, etc. it measures based on each frame in each batch. it did not generate report, you can get info from the output log.
I mean, that there is no difference in the output of my application between the case where the above environmental variables are set and when they are not. I.e you can see, that the difference is only the timestamps, there are no additional log entries:
$ ./myapp &>log1.txt
$ export NVDS_ENABLE_LATENCY_MEASUREMENT=1
$ export NVDS_ENABLE_COMPONENT_LATENCY_MEASUREMENT=1
$ ./myapp &>log2.txt
$ diff log1.txt log2.txt
7,12c7,12
< 0:00:02.845365283 18407 0x5595f76670 INFO nvinfer gstnvinfer.cpp:619:gst_nvinfer_logger:<face_detector> NvDsInferContext[UID 2]: Info from NvDsInferContextImpl::deserializeEngineAndBackend() <nvdsinfer_context_impl.cpp:1701> [UID = 2]: deserialized trt engine from :/nvme/wd/models/face_detection/peoplenet/resnet34_peoplenet_pruned.etlt_b2_gpu0_fp16.engine
< 0:00:02.845540240 18407 0x5595f76670 INFO nvinfer gstnvinfer.cpp:619:gst_nvinfer_logger:<face_detector> NvDsInferContext[UID 2]: Info from NvDsInferContextImpl::generateBackendContext() <nvdsinfer_context_impl.cpp:1805> [UID = 2]: Use deserialized engine model: /nvme/wd/models/face_detection/peoplenet/resnet34_peoplenet_pruned.etlt_b2_gpu0_fp16.engine
< 0:00:02.848875195 18407 0x5595f76670 INFO nvinfer gstnvinfer_impl.cpp:313:notifyLoadModelStatus:<face_detector> [UID 2]: Load new model:/nvme/wd/config/models_config/config_infer_peoplenet.txt sucessfully
< 0:00:02.947899408 18407 0x5595f76670 INFO nvinfer gstnvinfer.cpp:619:gst_nvinfer_logger:<gun_detector> NvDsInferContext[UID 1]: Info from NvDsInferContextImpl::deserializeEngineAndBackend() <nvdsinfer_context_impl.cpp:1701> [UID = 1]: deserialized trt engine from :/nvme/wd/models/gun_detection/export_42/yolo_resnet18_epoch_080.etlt_b2_gpu0_fp16.engine
< 0:00:02.948074205 18407 0x5595f76670 INFO nvinfer gstnvinfer.cpp:619:gst_nvinfer_logger:<gun_detector> NvDsInferContext[UID 1]: Info from NvDsInferContextImpl::generateBackendContext() <nvdsinfer_context_impl.cpp:1805> [UID = 1]: Use deserialized engine model: /nvme/wd/models/gun_detection/export_42/yolo_resnet18_epoch_080.etlt_b2_gpu0_fp16.engine
< 0:00:02.970459050 18407 0x5595f76670 INFO nvinfer gstnvinfer_impl.cpp:313:notifyLoadModelStatus:<gun_detector> [UID 1]: Load new model:/nvme/wd/config/models_config/config_infer_gun_detection.txt sucessfully
---
> 0:00:02.912155080 18577 0x55b2596070 INFO nvinfer gstnvinfer.cpp:619:gst_nvinfer_logger:<face_detector> NvDsInferContext[UID 2]: Info from NvDsInferContextImpl::deserializeEngineAndBackend() <nvdsinfer_context_impl.cpp:1701> [UID = 2]: deserialized trt engine from :/nvme/wd/models/face_detection/peoplenet/resnet34_peoplenet_pruned.etlt_b2_gpu0_fp16.engine
> 0:00:02.912312146 18577 0x55b2596070 INFO nvinfer gstnvinfer.cpp:619:gst_nvinfer_logger:<face_detector> NvDsInferContext[UID 2]: Info from NvDsInferContextImpl::generateBackendContext() <nvdsinfer_context_impl.cpp:1805> [UID = 2]: Use deserialized engine model: /nvme/wd/models/face_detection/peoplenet/resnet34_peoplenet_pruned.etlt_b2_gpu0_fp16.engine
> 0:00:02.915962850 18577 0x55b2596070 INFO nvinfer gstnvinfer_impl.cpp:313:notifyLoadModelStatus:<face_detector> [UID 2]: Load new model:/nvme/wd/config/models_config/config_infer_peoplenet.txt sucessfully
> 0:00:03.016628095 18577 0x55b2596070 INFO nvinfer gstnvinfer.cpp:619:gst_nvinfer_logger:<gun_detector> NvDsInferContext[UID 1]: Info from NvDsInferContextImpl::deserializeEngineAndBackend() <nvdsinfer_context_impl.cpp:1701> [UID = 1]: deserialized trt engine from :/nvme/wd/models/gun_detection/export_42/yolo_resnet18_epoch_080.etlt_b2_gpu0_fp16.engine
> 0:00:03.016809387 18577 0x55b2596070 INFO nvinfer gstnvinfer.cpp:619:gst_nvinfer_logger:<gun_detector> NvDsInferContext[UID 1]: Info from NvDsInferContextImpl::generateBackendContext() <nvdsinfer_context_impl.cpp:1805> [UID = 1]: Use deserialized engine model: /nvme/wd/models/gun_detection/export_42/yolo_resnet18_epoch_080.etlt_b2_gpu0_fp16.engine
> 0:00:03.044703893 18577 0x55b2596070 INFO nvinfer gstnvinfer_impl.cpp:313:notifyLoadModelStatus:<gun_detector> [UID 1]: Load new model:/nvme/wd/config/models_config/config_infer_gun_detection.txt sucessfully
How does such a log entry look like, i.e. what should I look for? I cannot find it in my app log. Do I need to set other environment variables, e.g. GST_DEBUG, etc?
No, I do not have the latency log on the stdout neither. I also tried to run gstlaunch instead of my cpp application. I do not receive any latency logs in this case neither:
$ export NVDS_ENABLE_LATENCY_MEASUREMENT=1
$ export NVDS_ENABLE_COMPONENT_LATENCY_MEASUREMENT=1
$ gst-launch-1.0 uridecodebin3 uri="file:///home/ubuntu/testvids/vid1.m4v" ! queue ! nvstreammux0.sink_0 nvstreammux name=nvstreammux0 batch-size=1 batched-push-timeout=40000 width=1280 height=720 live-source=TRUE ! queue ! nvvideoconvert ! queue ! nvinfer config-file-path="/nvme/wd/config/models_config/config_infer_peoplenet.txt" model-engine-file="/nvme/wd/models/face_detection/peoplenet/resnet34_peoplenet_pruned.etlt_b2_gpu0_fp16.engine" ! queue ! nvdsosd process-mode=HW_MODE ! queue ! nvoverlaysink sync=false
Warning: 'input-dims' parameter has been deprecated. Use 'infer-dims' instead.
Setting pipeline to PAUSED ...
0:00:02.796298202 934 0x55b9847660 INFO nvinfer gstnvinfer.cpp:619:gst_nvinfer_logger:<nvinfer0> NvDsInferContext[UID 2]: Info from NvDsInferContextImpl::deserializeEngineAndBackend() <nvdsinfer_context_impl.cpp:1701> [UID = 2]: deserialized trt engine from :/nvme/wd/models/face_detection/peoplenet/resnet34_peoplenet_pruned.etlt_b2_gpu0_fp16.engine
INFO: [Implicit Engine Info]: layers num: 3
0 INPUT kFLOAT input_1 3x544x960
1 OUTPUT kFLOAT output_bbox/BiasAdd 12x34x60
2 OUTPUT kFLOAT output_cov/Sigmoid 3x34x60
0:00:02.796559046 934 0x55b9847660 INFO nvinfer gstnvinfer.cpp:619:gst_nvinfer_logger:<nvinfer0> NvDsInferContext[UID 2]: Info from NvDsInferContextImpl::generateBackendContext() <nvdsinfer_context_impl.cpp:1805> [UID = 2]: Use deserialized engine model: /nvme/wd/models/face_detection/peoplenet/resnet34_peoplenet_pruned.etlt_b2_gpu0_fp16.engine
0:00:02.800783174 934 0x55b9847660 INFO nvinfer gstnvinfer_impl.cpp:313:notifyLoadModelStatus:<nvinfer0> [UID 2]: Load new model:/nvme/wd/config/models_config/config_infer_peoplenet.txt sucessfully
Pipeline is PREROLLING ...
Opening in BLOCKING MODE
NvMMLiteOpen : Block : BlockType = 261
NVMEDIA: Reading vendor.tegra.display-size : status: 6
NvMMLiteBlockCreate : Block : BlockType = 261
Pipeline is PREROLLED ...
Setting pipeline to PLAYING ...
New clock: GstSystemClock
Got EOS from element "pipeline0".
Execution ended after 0:00:22.930187396
Setting pipeline to PAUSED ...
Setting pipeline to READY ...
Setting pipeline to NULL ...
Freeing pipeline ...