Deepstream app won't start calling probe callbacks if I block the camera with something?

cheesiangleow5284 · October 14, 2020, 8:25am

• Jetson Xavier NX
• DeepStream Version:5
• JetPack Version: 4.4

I have a deepstream test5 app that will send the message to AMQP broker and create a RTSPStream sink for streaming. I start my app in the following way. However, the number 2 way I can’t get anything after unblock the camera…? Is the app must be inference one time for the app work properly?

pattern 1. Start the app and stand in front the camera which the app will detect person. → After the app started, It will start detecting person and keep sending message to AMQP broker and also the RTSPStream can be open.
pattern 2. Start the app and block the camera with paper which it will be dark image I think? it won’t detect anything and the app started. However when I unblock the camera, it won’t detect anything and won’t send any message and stream any RTSP Stream. Then I try to open the RTSPStream with VLC, it just shows the following error.

0:06:57.119163779 23010   0x7f48003400 WARN               rtspmedia rtsp-media.c:2994:wait_preroll: failed to preroll pipeline
0:06:57.119281925 23010   0x7f48003400 WARN               rtspmedia rtsp-media.c:3298:gst_rtsp_media_prepare: failed to preroll pipeline
0:06:57.122183723 23010   0x7f48003400 ERROR             rtspclient rtsp-client.c:1054:find_media: client 0x557e8a75e0: can't prepare media
0:06:57.122638097 23010   0x7f48003400 ERROR             rtspclient rtsp-client.c:2910:handle_describe_request: client 0x557e8a75e0: no media

EDIT: I have try to enable the PERF to check the framerate, it seems like the number 2 pattern shows the following PERF.

Wed Oct 14 18:38:39 2020
**PERF: 0.00 (0.00)
Wed Oct 14 18:38:44 2020
**PERF: 0.00 (0.00)
Wed Oct 14 18:38:49 2020
**PERF: 0.00 (0.00)
Wed Oct 14 18:38:54 2020
**PERF: 0.00 (0.00)
Wed Oct 14 18:38:59 2020
**PERF: 0.00 (0.00)
Wed Oct 14 18:39:04 2020
**PERF: 0.00 (0.00)
Wed Oct 14 18:39:09 2020
**PERF: 0.00 (0.00)
Wed Oct 14 18:39:14 2020
**PERF: 0.00 (0.00)
Wed Oct 14 18:39:19 2020
**PERF: 0.00 (0.00)
Wed Oct 14 18:39:24 2020
**PERF: 0.00 (0.00)

For the pattern 1 which the app can detect something when the app start. It just run properly.

Wed Oct 14 18:40:35 2020
**PERF: 19.98 (21.87)
Wed Oct 14 18:40:40 2020
**PERF: 20.09 (21.19)
Wed Oct 14 18:40:45 2020
**PERF: 20.01 (20.88)
Wed Oct 14 18:40:50 2020
**PERF: 19.98 (20.69)

UPDATE:
After some debugging, I found that if the app didn’t detect anything, the KLT Tracker won’t Initialize…and will not detect anything even after the camera unblock. Maybe is this the problem?
UPDATE 2:
Try disable KLT tracker, and block camera with paper, start the app it have a same problem…
UPDATE 3:
Try enable EglSink to display the output, seems like when blocking the camera shows a black screen and have same symptom like pattern 2

UPDATE 4:
Pattern 3: start the app and make it detect something, next block the camera. It will stop detect anything and stop sending message to AMQP broker, and unblock the camera , it can detect something again.
It seems like when the app is started, first time it must detect something in order to work properly.@@

cheesiangleow5284 · October 15, 2020, 1:48am

Does anyone know how to solve this problem? How come the started app must detect something in order to for the app run properly?

Fiona.Chen · October 15, 2020, 2:28am

What app are you using? What type of camera are you using? Will this type of camera stop output video when it’s lens was covered with paper?

cheesiangleow5284 · October 15, 2020, 5:24am

@Fiona.Chen I’m using a Arucom RD-CI601 camera, and I’m using the deepstream-test5 modified by adding smart record function and also add a function to send the base64 cropped object image to rabbitmq message broker. The camera won’t stop even it’s lens covered with paper confirmed from the IP camera web interface.

Fiona.Chen · October 15, 2020, 5:38am

So what do you mean to “block the camera”? Your application is for “person” detection, right? So when there is no “person” in front of the camera, nothing will be detected. Why did you cover the lens with paper? What will cause the application to show black screen when you using eglsink? To just cover a paper on lens will not show black screen since there is some light even when the lens is covered.

The PERF log of number 2 pattern shows there is no video from camera in the pipeline.

cheesiangleow5284 · October 15, 2020, 5:43am

@Fiona.Chen Thank you for your fast response. Yes my app is for “person” detection. I have tested don’t block the camera, and just let the camera facing a direction that nothing (no person in front of the camera) can be detected, it just shows the pattern 2 symptom. After this test it let me notice that if the camera can’t detect anything when the app starts, It will not getting the video stream from RTSP. That’s why after that I did the block the camera test. And as you said, suppose that even covered the lens with paper, it has some light and supposed to be work properly but it didn’t.
As you said, suppose if there is no person in front of the camera, it suppose detect nothing. I was expect that if even there is no person detected, the video suppose can be streaming. I have check the bbox_generated_probe_after_analytics probe by adding a global variable to count the number of frame, and for the pattern 2 symptom , the bbox_generated_probe_after_analytics won’t be call at all… This cause the eglsink show black screen.

To summarize, if there is no object can be detected when the app starts, it cause the app can’t get the RTSP Stream from IP camera. This cause the app can’t continue detect anything and show the PERF above, and it didn’t show any errors.

Is this kind of problem is related to camera stream?

Fiona.Chen · October 15, 2020, 6:34am

Do you mean your IP camera will stop streaming video when there is no person be captured?

Did your deepstream app receive RTSP video from camera and do the inferrence(the AMQP and RTSP streaming out is after the inferrence)?

If you are sure that bbox_generated_probe_after_analytics probe is never called in pattern 2, yo may need to check whether there is video input to deepstream app.

cheesiangleow5284 · October 15, 2020, 6:42am

@Fiona.Chen yes I mean that IP camera stop streaming to the app when no person is captured,however, I can view from IP camera browser. (Means the IP camera is working)
If there is nothing can be detect and start the app, the deepstream app won’t receive the RTSP video from camera and don’t do any inference, But the app won’t crash and keep showing the PERF with 0.00 frame.
I am sure that the IP camera is working because I keep viewing with a VLC player, so suppose the deepstream app can get the RTSP stream but it doesn’t.

cheesiangleow5284 · October 18, 2020, 2:39am

This is the log of GST_DEBUG=3…

 *** DeepStream: Launched RTSP Streaming at rtsp://localhost:8555/ds-test ***

Opening in BLOCKING MODE
0:00:00.201022280  7113   0x55a53af240 WARN                    v4l2 gstv4l2object.c:2372:gst_v4l2_object_add_interlace_mode:0x55a52e0000 Failed to determine interlace mode
0:00:00.201140969  7113   0x55a53af240 WARN                    v4l2 gstv4l2object.c:2372:gst_v4l2_object_add_interlace_mode:0x55a52e0000 Failed to determine interlace mode
0:00:00.201206345  7113   0x55a53af240 WARN                    v4l2 gstv4l2object.c:2372:gst_v4l2_object_add_interlace_mode:0x55a52e0000 Failed to determine interlace mode
0:00:00.201418602  7113   0x55a53af240 WARN                    v4l2 gstv4l2object.c:4410:gst_v4l2_object_probe_caps:<sink_sub_bin_encoder2:src> Failed to probe pixel aspect ratio with VIDIOC_CROPCAP: Unknown error -1
gstnvtracker: Loading low-level lib at /opt/nvidia/deepstream/deepstream-5.0/lib/libnvds_mot_klt.so
gstnvtracker: Optional NvMOT_RemoveStreams not implemented
gstnvtracker: Batch processing is OFF
WARNING: [TRT]: Using an engine plan file across different models of devices is not recommended and is likely to affect performance or even cause errors.
0:00:05.073520767  7113   0x55a53af240 INFO                 nvinfer gstnvinfer.cpp:602:gst_nvinfer_logger:<primary_gie> NvDsInferContext[UID 1]: Info from NvDsInferContextImpl::deserializeEngineAndBackend() <nvdsinfer_context_impl.cpp:1577> [UID = 1]: deserialized trt engine from :/home/administrator/deepstream_yolov5/Deepstream-5.0/yolov5s.engine
INFO: [Implicit Engine Info]: layers num: 2
0   INPUT  kFLOAT data            3x608x608
1   OUTPUT kFLOAT prob            6001x1x1

0:00:05.073749313  7113   0x55a53af240 INFO                 nvinfer gstnvinfer.cpp:602:gst_nvinfer_logger:<primary_gie> NvDsInferContext[UID 1]: Info from NvDsInferContextImpl::generateBackendContext() <nvdsinfer_context_impl.cpp:1681> [UID = 1]: Use deserialized engine model: /home/administrator/deepstream_yolov5/Deepstream-5.0/yolov5s.engine
0:00:05.080159274  7113   0x55a53af240 INFO                 nvinfer gstnvinfer_impl.cpp:311:notifyLoadModelStatus:<primary_gie> [UID 1]: Load new model:/home/administrator/deepstream_yolov5/Deepstream-5.0/config_infer_primary_yoloV5.txt sucessfully
cb_sourcesetup set 100 latency

Runtime commands:
	h: Print this help
	q: Quit

	p: Pause
	r: Resume

NOTE: To expand a source in the 2D tiled display and view object details, left-click on the source.
      To go back to the tiled display, right-click anywhere on the window.

** INFO: <bus_callback:185>: Pipeline ready

** INFO: <bus_callback:171>: Pipeline running

0:00:05.128012575  7113   0x55d71b1c50 FIXME                default gstutils.c:3981:gst_pad_create_stream_id_internal:<fakesrc0:src> Creating random stream-id, consider implementing a deterministic way of creating a stream-id

**PERF: FPS 0 (Avg)
Sun Oct 18 11:38:09 2020
**PERF: 0.00 (0.00)
Opening in BLOCKING MODE
0:00:05.233565641  7113   0x7edc003630 WARN                    v4l2 gstv4l2object.c:4410:gst_v4l2_object_probe_caps:<nvv4l2decoder0:src> Failed to probe pixel aspect ratio with VIDIOC_CROPCAP: Unknown error -1
0:00:05.233646921  7113   0x7edc003630 WARN                    v4l2 gstv4l2object.c:2372:gst_v4l2_object_add_interlace_mode:0x7ed00a8400 Failed to determine interlace mode
NvMMLiteOpen : Block : BlockType = 261
NVMEDIA: Reading vendor.tegra.display-size : status: 6
NvMMLiteBlockCreate : Block : BlockType = 261
0:00:05.342778602  7113   0x7edc003630 WARN                    v4l2 gstv4l2object.c:4410:gst_v4l2_object_probe_caps:<nvv4l2decoder0:src> Failed to probe pixel aspect ratio with VIDIOC_CROPCAP: Unknown error -1
0:00:05.342945835  7113   0x7edc003630 WARN                    v4l2 gstv4l2object.c:2372:gst_v4l2_object_add_interlace_mode:0x7ed00a8400 Failed to determine interlace mode
0:00:05.347657098  7113   0x55a53b0450 FIXME               basesink gstbasesink.c:3145:gst_base_sink_default_event:<src_fakesink> stream-start event without group-id. Consider implementing group-id handling in the upstream elements
0:00:05.348049452  7113   0x55a53b0770 FIXME               basesink gstbasesink.c:3145:gst_base_sink_default_event:<sink_sub_bin_sink1> stream-start event without group-id. Consider implementing group-id handling in the upstream elements
** INFO: <bus_callback:171>: Pipeline running

0:00:05.365110842  7113   0x55a530aa30 FIXME               basesink gstbasesink.c:3145:gst_base_sink_default_event:<sink_sub_bin_udpsink2> stream-start event without group-id. Consider implementing group-id handling in the upstream elements
NvMMLiteOpen : Block : BlockType = 8
===== NVMEDIA: NVENC =====
NvMMLiteBlockCreate : Block : BlockType = 8
0:00:05.369975930  7113   0x55a530aa30 WARN          v4l2bufferpool gstv4l2bufferpool.c:1057:gst_v4l2_buffer_pool_start:<sink_sub_bin_encoder2:pool:src> Uncertain or not enough buffers, enabling copy threshold
0:00:05.393233808  7113   0x7edc003630 WARN            v4l2videodec gstv4l2videodec.c:1609:gst_v4l2_video_dec_decide_allocation:<nvv4l2decoder0> Duration invalid, not setting latency
0:00:05.394423992  7113   0x7edc003630 WARN          v4l2bufferpool gstv4l2bufferpool.c:1057:gst_v4l2_buffer_pool_start:<nvv4l2decoder0:pool:src> Uncertain or not enough buffers, enabling copy threshold
0:00:05.409809179  7113   0x7ed0779770 WARN          v4l2bufferpool gstv4l2bufferpool.c:1535:gst_v4l2_buffer_pool_dqbuf:<nvv4l2decoder0:pool:src> Driver should never set v4l2_buffer.field to ANY
0:00:05.654346632  7113   0x7edc003630 WARN          v4l2bufferpool gstv4l2bufferpool.c:1491:gst_v4l2_buffer_pool_dqbuf:<nvv4l2decoder0:pool:sink> v4l2 provided buffer that is too big for the memory it was writing into.  v4l2 claims 64 bytes used but memory is only 0B.  This is probably a driver bug.
0:00:05.701903388  7113   0x7edc003630 WARN          v4l2bufferpool gstv4l2bufferpool.c:1491:gst_v4l2_buffer_pool_dqbuf:<nvv4l2decoder0:pool:sink> v4l2 provided buffer that is too big for the memory it was writing into.  v4l2 claims 64 bytes used but memory is only 0B.  This is probably a driver bug.
0:00:05.751434876  7113   0x7edc003630 WARN          v4l2bufferpool gstv4l2bufferpool.c:1491:gst_v4l2_buffer_pool_dqbuf:<nvv4l2decoder0:pool:sink> v4l2 provided buffer that is too big for the memory it was writing into.  v4l2 claims 64 bytes used but memory is only 0B.  This is probably a driver bug.
0:00:05.801949507  7113   0x7edc003630 WARN          v4l2bufferpool gstv4l2bufferpool.c:1491:gst_v4l2_buffer_pool_dqbuf:<nvv4l2decoder0:pool:sink> v4l2 provided buffer that is too big for the memory it was writing into.  v4l2 claims 64 bytes used but memory is only 0B.  This is probably a driver bug.
0:00:05.851738980  7113   0x7edc003630 WARN          v4l2bufferpool gstv4l2bufferpool.c:1491:gst_v4l2_buffer_pool_dqbuf:<nvv4l2decoder0:pool:sink> v4l2 provided buffer that is too big for the memory it was writing into.  v4l2 claims 64 bytes used but memory is only 0B.  This is probably a driver bug.
0:00:05.901810600  7113   0x7edc003630 WARN          v4l2bufferpool gstv4l2bufferpool.c:1491:gst_v4l2_buffer_pool_dqbuf:<nvv4l2decoder0:pool:sink> v4l2 provided buffer that is too big for the memory it was writing into.  v4l2 claims 64 bytes used but memory is only 0B.  This is probably a driver bug.
0:00:05.952162574  7113   0x7edc003630 WARN          v4l2bufferpool gstv4l2bufferpool.c:1491:gst_v4l2_buffer_pool_dqbuf:<nvv4l2decoder0:pool:sink> v4l2 provided buffer that is too big for the memory it was writing into.  v4l2 claims 64 bytes used but memory is only 0B.  This is probably a driver bug.
0:00:06.002352306  7113   0x7edc003630 WARN          v4l2bufferpool gstv4l2bufferpool.c:1491:gst_v4l2_buffer_pool_dqbuf:<nvv4l2decoder0:pool:sink> v4l2 provided buffer that is too big for the memory it was writing into.  v4l2 claims 64 bytes used but memory is only 0B.  This is probably a driver bug.
0:00:06.051810642  7113   0x7edc003630 WARN          v4l2bufferpool gstv4l2bufferpool.c:1491:gst_v4l2_buffer_pool_dqbuf:<nvv4l2decoder0:pool:sink> v4l2 provided buffer that is too big for the memory it was writing into.  v4l2 claims 64 bytes used but memory is only 0B.  This is probably a driver bug.
0:00:06.102018486  7113   0x7edc003630 WARN          v4l2bufferpool gstv4l2bufferpool.c:1491:gst_v4l2_buffer_pool_dqbuf:<nvv4l2decoder0:pool:sink> v4l2 provided buffer that is too big for the memory it was writing into.  v4l2 claims 64 bytes used but memory is only 0B.  This is probably a driver bug.
0:00:06.152229851  7113   0x7edc003630 WARN          v4l2bufferpool gstv4l2bufferpool.c:1491:gst_v4l2_buffer_pool_dqbuf:<nvv4l2decoder0:pool:sink> v4l2 provided buffer that is too big for the memory it was writing into.  v4l2 claims 64 bytes used but memory is only 0B.  This is probably a driver bug.
0:00:06.202424384  7113   0x7edc003630 WARN          v4l2bufferpool gstv4l2bufferpool.c:1491:gst_v4l2_buffer_pool_dqbuf:<nvv4l2decoder0:pool:sink> v4l2 provided buffer that is too big for the memory it was writing into.  v4l2 claims 64 bytes used but memory is only 0B.  This is probably a driver bug.
0:00:06.251269851  7113   0x7edc003630 WARN          v4l2bufferpool gstv4l2bufferpool.c:1491:gst_v4l2_buffer_pool_dqbuf:<nvv4l2decoder0:pool:sink> v4l2 provided buffer that is too big for the memory it was writing into.  v4l2 claims 64 bytes used but memory is only 0B.  This is probably a driver bug.
0:00:06.301652609  7113   0x7edc003630 WARN          v4l2bufferpool gstv4l2bufferpool.c:1491:gst_v4l2_buffer_pool_dqbuf:<nvv4l2decoder0:pool:sink> v4l2 provided buffer that is too big for the memory it was writing into.  v4l2 claims 64 bytes used but memory is only 0B.  This is probably a driver bug.
0:00:06.352034503  7113   0x7edc003630 WARN          v4l2bufferpool gstv4l2bufferpool.c:1491:gst_v4l2_buffer_pool_dqbuf:<nvv4l2decoder0:pool:sink> v4l2 provided buffer that is too big for the memory it was writing into.  v4l2 claims 64 bytes used but memory is only 0B.  This is probably a driver bug.
0:00:06.401286374  7113   0x7edc003630 WARN          v4l2bufferpool gstv4l2bufferpool.c:1491:gst_v4l2_buffer_pool_dqbuf:<nvv4l2decoder0:pool:sink> v4l2 provided buffer that is too big for the memory it was writing into.  v4l2 claims 64 bytes used but memory is only 0B.  This is probably a driver bug.
0:00:06.451945646  7113   0x7edc003630 WARN          v4l2bufferpool gstv4l2bufferpool.c:1491:gst_v4l2_buffer_pool_dqbuf:<nvv4l2decoder0:pool:sink> v4l2 provided buffer that is too big for the memory it was writing into.  v4l2 claims 64 bytes used but memory is only 0B.  This is probably a driver bug.
0:00:06.501320494  7113   0x7edc003630 WARN          v4l2bufferpool gstv4l2bufferpool.c:1491:gst_v4l2_buffer_pool_dqbuf:<nvv4l2decoder0:pool:sink> v4l2 provided buffer that is too big for the memory it was writing into.  v4l2 claims 64 bytes used but memory is only 0B.  This is probably a driver bug.
0:00:06.552000950  7113   0x7edc003630 WARN          v4l2bufferpool gstv4l2bufferpool.c:1491:gst_v4l2_buffer_pool_dqbuf:<nvv4l2decoder0:pool:sink> v4l2 provided buffer that is too big for the memory it was writing into.  v4l2 claims 64 bytes used but memory is only 0B.  This is probably a driver bug.
0:00:06.601802488  7113   0x7edc003630 WARN          v4l2bufferpool gstv4l2bufferpool.c:1491:gst_v4l2_buffer_pool_dqbuf:<nvv4l2decoder0:pool:sink> v4l2 provided buffer that is too big for the memory it was writing into.  v4l2 claims 64 bytes used but memory is only 0B.  This is probably a driver bug.
0:00:06.651653787  7113   0x7edc003630 WARN          v4l2bufferpool gstv4l2bufferpool.c:1491:gst_v4l2_buffer_pool_dqbuf:<nvv4l2decoder0:pool:sink> v4l2 provided buffer that is too big for the memory it was writing into.  v4l2 claims 64 bytes used but memory is only 0B.  This is probably a driver bug.
0:00:06.702319267  7113   0x7edc003630 WARN          v4l2bufferpool gstv4l2bufferpool.c:1491:gst_v4l2_buffer_pool_dqbuf:<nvv4l2decoder0:pool:sink> v4l2 provided buffer that is too big for the memory it was writing into.  v4l2 claims 64 bytes used but memory is only 0B.  This is probably a driver bug.
0:00:06.751929796  7113   0x7edc003630 WARN          v4l2bufferpool gstv4l2bufferpool.c:1491:gst_v4l2_buffer_pool_dqbuf:<nvv4l2decoder0:pool:sink> v4l2 provided buffer that is too big for the memory it was writing into.  v4l2 claims 64 bytes used but memory is only 0B.  This is probably a driver bug.
0:00:06.801210467  7113   0x7edc003630 WARN          v4l2bufferpool gstv4l2bufferpool.c:1491:gst_v4l2_buffer_pool_dqbuf:<nvv4l2decoder0:pool:sink> v4l2 provided buffer that is too big for the memory it was writing into.  v4l2 claims 64 bytes used but memory is only 0B.  This is probably a driver bug.
0:00:06.851476425  7113   0x7edc003630 WARN          v4l2bufferpool gstv4l2bufferpool.c:1491:gst_v4l2_buffer_pool_dqbuf:<nvv4l2decoder0:pool:sink> v4l2 provided buffer that is too big for the memory it was writing into.  v4l2 claims 64 bytes used but memory is only 0B.  This is probably a driver bug.
Sun Oct 18 11:38:14 2020
**PERF: 0.00 (0.00)
Sun Oct 18 11:38:19 2020
**PERF: 0.00 (0.00)
Sun Oct 18 11:38:24 2020
**PERF: 0.00 (0.00)
Sun Oct 18 11:38:29 2020
**PERF: 0.00 (0.00)
Sun Oct 18 11:38:34 2020
**PERF: 0.00 (0.00)
Sun Oct 18 11:38:39 2020
**PERF: 0.00 (0.00)

cheesiangleow5284 · October 18, 2020, 4:23am

@Fiona.Chen I think i found the problem, my deepstream test5 app added nvds_obj_enc_process when an object is detected will attach the cropped image to the NvDsUserMeta. The problem is that, I have a pgie_src_pad_buffer_probe on the primary gie. Within this probe, if the detect a person, then it will use the nvds_obj_enc_process to add the metadata to the NvDsUserMeta, and then the nvds_obj_enc_finish should be call. The problem of this issue is that, I didn’t check whether the nvds_obj_enc_process is being call. But instead i always call nvds_obj_enc_finish every time within the probe, this lead to the NvDsUserMeta data can’t be call on next bbox_generated_probe_after_analytics probe. Maybe for the nvds_obj_enc_finish documentation can add that this function must be call after the nvds_obj_enc_process is being called. Could help somebody who trying to use this module. But anyway thank you for helping!