Deepstream-infer-tensor-meta-test 5.0 queue_dataflow gstqueue.c:1243:gst_queue_loop:<queue0> queue is empty

Accelerated Computing Intelligent Video Analytics DeepStream SDK
1

Please provide complete information as applicable to your setup.

• Hardware Platform (Jetson / GPU) GPU
• DeepStream Version 5.0
• TensorRT Version 7
• NVIDIA GPU Driver Version (valid for GPU only) 440
• Issue Type( questions, new requirements, bugs) question
• How to reproduce the issue ?
I’m using deepstream-infer-tensor-meta-test.
In one of the classifier (say dstensor_sgie2_config.txt), if I change input-object-min-width and input-object-min-height to 16 or 32 (from default 64), the deepstream app stalls after processing 163 frames. I’m using batch size of 1.

Command used:

/deepstream-infer-tensor-meta-app /opt/nvidia/deepstream/deepstream/samples/streams/sample_720p.h264

By using GST_DEBUG=5, I get the error

queue_dataflow gstqueue.c:1516:gst_queue_loop:<queue3> queue is empty

I’m using filesink to save output video (modification in pipeline done according to Encoding and saving to a file with deepstream_test1_app.c - #2 by DaneLLL The app runs fine if the min-width and height are set to 64 only.

3

Hey, could you share the whole log with us, BTW, have you changed the original deepstream-infer-tensor-meta-app source code?

4

Hi @bcao,

I had modified pipeline to include video saving code, but, nevertheless, even if I don’t modify the original app, and only make the below changes:

  1. Change nveglsink to fakesink (just for testing)
  2. In dstensor_sgie2_config.txt, make these changes:
batch-size=1
input-object-min-width=32
input-object-min-height=32

The app stalls after few frames, you can check it yourself (but in deepstream-test2 app, this doesn’t happen).
Thanks.

With GST_DEBUG=4, this is what I get when app stalls

Frame Number = 32 Number of objects = 8 Vehicle Count = 6 Person Count = 2
0:00:02.922845464 25655 0x55eb181688a0 INFO            videodecoder gstvideodecoder.c:1330:gst_video_decoder_sink_event_default:<nvv4l2decoder0> upstream tags: taglist, video-codec=(string)"H.264\ \(High\ Profile\)", minimum-bitrate=(uint)430800, maximum-bitrate=(uint)8223360, bitrate=(uint)3166788;
Frame Number = 33 Number of objects = 8 Vehicle Count = 6 Person Count = 2
Frame Number = 34 Number of objects = 7 Vehicle Count = 5 Person Count = 2
Frame Number = 35 Number of objects = 9 Vehicle Count = 7 Person Count = 2
0:00:02.966718606 25655 0x55eb181688a0 INFO            videodecoder gstvideodecoder.c:1330:gst_video_decoder_sink_event_default:<nvv4l2decoder0> upstream tags: taglist, video-codec=(string)"H.264\ \(High\ Profile\)", minimum-bitrate=(uint)430800, maximum-bitrate=(uint)8223360, bitrate=(uint)3080629;
Frame Number = 36 Number of objects = 10 Vehicle Count = 7 Person Count = 3
Frame Number = 37 Number of objects = 11 Vehicle Count = 8 Person Count = 3

With GST_DEGUB=5, the log is on github gist. The last portion of log is

0:00:03.518131261 25758 0x5596e4d2db70 DEBUG               basesink gstbasesink.c:3421:gst_base_sink_chain_unlocked:<nvvideo-renderer> got times start: 0:00:01.233333321, end: 99:99:99.999999999
0:00:03.518147521 25758 0x5596e4d2db70 DEBUG               basesink gstbasesink.c:2006:gst_base_sink_get_sync_times:<nvvideo-renderer> got times start: 0:00:01.233333321, stop: 99:99:99.999999999, do_sync 1
0:00:03.518153784 25758 0x5596e4d2db70 DEBUG                default gstsegment.c:737:gst_segment_to_running_time_full: invalid position (-1)
0:00:03.518162654 25758 0x5596e4d2db70 DEBUG               basesink gstbasesink.c:2591:gst_base_sink_do_sync:<nvvideo-renderer> reset rc_time to time 0:00:01.233333321
0:00:03.518174790 25758 0x5596e4d2db70 DEBUG               basesink gstbasesink.c:2603:gst_base_sink_do_sync:<nvvideo-renderer> possibly waiting for clock to reach 0:00:01.233333321, adjusted 0:00:01.233333321
0:00:03.518179763 25758 0x5596e4e50370 DEBUG             bufferpool gstbufferpool.c:304:do_alloc_buffer:<bufferpool1> max buffers reached
0:00:03.518196045 25758 0x5596e4d2db70 DEBUG               basesink gstbasesink.c:2223:gst_base_sink_wait_clock:<nvvideo-renderer> sync disabled
0:00:03.518199932 25758 0x5596e4e50370 DEBUG               GST_POLL gstpoll.c:1317:gst_poll_wait: 0x5596e4d2db20: timeout :99:99:99.999999999
0:00:03.518210963 25758 0x5596e4d2db70 DEBUG               basesink gstbasesink.c:2610:gst_base_sink_do_sync:<nvvideo-renderer> clock returned 4, jitter  0:00:00.000000000
0:00:03.518225351 25758 0x5596e4d2db70 DEBUG               basesink gstbasesink.c:3538:gst_base_sink_chain_unlocked:<nvvideo-renderer> rendering object 0x7f04c4012e00
0:00:03.518231449 25758 0x5596e4d2db70 DEBUG               basesink gstbasesink.c:994:gst_base_sink_set_last_buffer_unlocked:<nvvideo-renderer> setting last buffer to 0x7f04c4012e00
0:00:03.518238276 25758 0x5596e4d2db70 DEBUG             GST_BUFFER gstbuffer.c:2384:gst_buffer_foreach_meta: remove metadata 0x5596e4d22a48 (NvDsMeta)
0:00:03.518254907 25758 0x5596e4d2db70 DEBUG               nvdspool gstnvdsbufferpool.c:492:gst_nvds_buffer_pool_release_buffer:<nvdsbufferpool0> release_buffer
0:00:03.518261507 25758 0x5596e4d2db70 DEBUG             GST_BUFFER gstbuffer.c:1375:gst_buffer_is_memory_range_writable: idx 0, length -1
0:00:03.518268530 25758 0x5596e4d2db70 DEBUG               basesink gstbasesink.c:3577:gst_base_sink_chain_unlocked:<nvvideo-renderer> object unref after render 0x7f04c4012e00
0:00:03.518275604 25758 0x5596e4d2db70 DEBUG         GST_SCHEDULING gstpad.c:4326:gst_pad_chain_data_unchecked:<nvvideo-renderer:sink> called chainfunction &gst_base_sink_chain with buffer 0x7f04c4012e00, returned ok
0:00:03.518282993 25758 0x5596e4d2db70 DEBUG         GST_SCHEDULING gstpad.c:4326:gst_pad_chain_data_unchecked:<nv-onscreendisplay:sink> called chainfunction &gst_base_transform_chain with buffer 0x7f04c4012e00, returned ok
0:00:03.518290275 25758 0x5596e4d2db70 DEBUG               GST_PADS gstpad.c:3980:check_sticky:<queue3:src> pushing all sticky events
0:00:03.518296500 25758 0x5596e4d2db70 DEBUG               GST_PADS gstpad.c:3910:push_sticky:<queue3:src> event stream-start was already received
0:00:03.518302358 25758 0x5596e4d2db70 DEBUG               GST_PADS gstpad.c:3910:push_sticky:<queue3:src> event caps was already received
0:00:03.518308009 25758 0x5596e4d2db70 DEBUG               GST_PADS gstpad.c:3910:push_sticky:<queue3:src> event segment was already received
0:00:03.518321369 25758 0x5596e4d2db70 DEBUG              GST_EVENT gstpad.c:5693:gst_pad_send_event_unchecked:<nv-onscreendisplay:sink> have event type tag event: 0x7f046832dae0, time 99:99:99.999999999, seq-num 227, GstTagList-stream, taglist=(taglist)"taglist\,\ video-codec\=\(string\)\"H.264\\\ \\\(High\\\ Profile\\\)\"\,\ minimum-bitrate\=\(uint\)430800\,\ maximum-bitrate\=\(uint\)8223360\,\ bitrate\=\(uint\)3250788\;";
0:00:03.518328430 25758 0x5596e4d2db70 DEBUG               GST_PADS gstpad.c:3810:do_probe_callbacks:<nv-onscreendisplay:sink> data is passed
0:00:03.518334727 25758 0x5596e4d2db70 DEBUG               GST_PADS gstpad.c:3980:check_sticky:<nv-onscreendisplay:src> pushing all sticky events
0:00:03.518340885 25758 0x5596e4d2db70 DEBUG               GST_PADS gstpad.c:3910:push_sticky:<nv-onscreendisplay:src> event stream-start was already received
0:00:03.518346724 25758 0x5596e4d2db70 DEBUG               GST_PADS gstpad.c:3910:push_sticky:<nv-onscreendisplay:src> event caps was already received
0:00:03.518352512 25758 0x5596e4d2db70 DEBUG               GST_PADS gstpad.c:3910:push_sticky:<nv-onscreendisplay:src> event segment was already received
0:00:03.518362965 25758 0x5596e4d2db70 DEBUG              GST_EVENT gstpad.c:5693:gst_pad_send_event_unchecked:<nvvideo-renderer:sink> have event type tag event: 0x7f046832dae0, time 99:99:99.999999999, seq-num 227, GstTagList-stream, taglist=(taglist)"taglist\,\ video-codec\=\(string\)\"H.264\\\ \\\(High\\\ Profile\\\)\"\,\ minimum-bitrate\=\(uint\)430800\,\ maximum-bitrate\=\(uint\)8223360\,\ bitrate\=\(uint\)3250788\;";
0:00:03.518374118 25758 0x5596e4d2db70 DEBUG               basesink gstbasesink.c:3252:gst_base_sink_event:<nvvideo-renderer> received event 0x7f046832dae0 tag event: 0x7f046832dae0, time 99:99:99.999999999, seq-num 227, GstTagList-stream, taglist=(taglist)"taglist\,\ video-codec\=\(string\)\"H.264\\\ \\\(High\\\ Profile\\\)\"\,\ minimum-bitrate\=\(uint\)430800\,\ maximum-bitrate\=\(uint\)8223360\,\ bitrate\=\(uint\)3250788\;";
0:00:03.518389180 25758 0x5596e4d2db70 DEBUG                GST_BUS gstbus.c:318:gst_bus_post:<bus0> [msg 0x5596e4e54430] posting on bus tag message: 0x5596e4e54430, time 99:99:99.999999999, seq-num 237, element 'nvvideo-renderer', GstMessageTag, taglist=(taglist)"taglist\,\ video-codec\=\(string\)\"H.264\\\ \\\(High\\\ Profile\\\)\"\,\ minimum-bitrate\=\(uint\)430800\,\ maximum-bitrate\=\(uint\)8223360\,\ bitrate\=\(uint\)3250788\;";
0:00:03.518397321 25758 0x5596e4d2db70 DEBUG                    bin gstbin.c:3717:gst_bin_handle_message_func:<dstensor-pipeline> [msg 0x5596e4e54430] handling child nvvideo-renderer message of type tag
0:00:03.518401879 25758 0x5596e4d2db70 DEBUG                    bin gstbin.c:4054:gst_bin_handle_message_func:<dstensor-pipeline> posting message upward
0:00:03.518410481 25758 0x5596e4d2db70 DEBUG                GST_BUS gstbus.c:318:gst_bus_post:<bus1> [msg 0x5596e4e54430] posting on bus tag message: 0x5596e4e54430, time 99:99:99.999999999, seq-num 237, element 'nvvideo-renderer', GstMessageTag, taglist=(taglist)"taglist\,\ video-codec\=\(string\)\"H.264\\\ \\\(High\\\ Profile\\\)\"\,\ minimum-bitrate\=\(uint\)430800\,\ maximum-bitrate\=\(uint\)8223360\,\ bitrate\=\(uint\)3250788\;";
0:00:03.518415674 25758 0x5596e4d2db70 DEBUG                GST_BUS gstbus.c:357:gst_bus_post:<bus1> [msg 0x5596e4e54430] pushing on async queue
0:00:03.518426592 25758 0x5596e4d2db70 DEBUG                GST_BUS gstbus.c:360:gst_bus_post:<bus1> [msg 0x5596e4e54430] pushed on async queue
0:00:03.518436134 25758 0x5596e4d2db70 DEBUG                GST_BUS gstbus.c:353:gst_bus_post:<bus0> [msg 0x5596e4e54430] dropped
0:00:03.518440092 25758 0x5596e4a5c800 DEBUG                GST_BUS gstbus.c:546:gst_bus_timed_pop_filtered:<bus1> got message 0x5596e4e54430, tag from nvvideo-renderer, type mask is 4294967295
0:00:03.518449433 25758 0x5596e4d2db70 DEBUG               GST_PADS gstpad.c:5776:gst_pad_send_event_unchecked:<nvvideo-renderer:sink> sent event, ret ok
0:00:03.518469544 25758 0x5596e4d2db70 DEBUG               GST_PADS gstpad.c:3932:push_sticky:<nv-onscreendisplay:src> event tag marked received
0:00:03.518471051 25758 0x5596e4a5c800 DEBUG                GST_BUS gstbus.c:839:gst_bus_source_dispatch:<bus1> source 0x5596e4d5e1e0 calling dispatch with tag message: 0x5596e4e54430, time 99:99:99.999999999, seq-num 237, element 'nvvideo-renderer', GstMessageTag, taglist=(taglist)"taglist\,\ video-codec\=\(string\)\"H.264\\\ \\\(High\\\ Profile\\\)\"\,\ minimum-bitrate\=\(uint\)430800\,\ maximum-bitrate\=\(uint\)8223360\,\ bitrate\=\(uint\)3250788\;";
0:00:03.518482712 25758 0x5596e4d2db70 DEBUG               GST_PADS gstpad.c:5776:gst_pad_send_event_unchecked:<nv-onscreendisplay:sink> sent event, ret ok
0:00:03.518497803 25758 0x5596e4a5c800 DEBUG                GST_BUS gstbus.c:844:gst_bus_source_dispatch:<bus1> source 0x5596e4d5e1e0 handler returns 1
0:00:03.518508602 25758 0x5596e4d2db70 DEBUG               GST_PADS gstpad.c:3932:push_sticky:<queue3:src> event tag marked received
0:00:03.518520936 25758 0x5596e4d2db70 DEBUG         queue_dataflow gstqueue.c:1516:gst_queue_loop:<queue3> queue is empty
0:00:03.518533891 25758 0x7f044c0024f0 DEBUG             GST_BUFFER gstbuffer.c:1375:gst_buffer_is_memory_range_writable: idx 0, length -1
0:00:03.518645530 25758 0x5596e4e50370 DEBUG             bufferpool gstbufferpool.c:304:do_alloc_buffer:<bufferpool1> max buffers reached
0:00:03.518658750 25758 0x5596e4e50370 DEBUG               GST_POLL gstpoll.c:1317:gst_poll_wait: 0x5596e4d2db20: timeout :99:99:99.999999999
0:00:03.518704990 25758 0x5596e4e501e0 DEBUG         GST_SCHEDULING gstpad.c:4320:gst_pad_chain_data_unchecked:<queue4:sink> calling chainfunction &gst_queue_chain with buffer buffer: 0x7f046801a5f0, pts 0:00:01.366666653, dts 99:99:99.999999999, dur 99:99:99.999999999, size 64, offset none, offset_end none, flags 0x0
0:00:03.518718486 25758 0x5596e4e501e0 DEBUG         GST_SCHEDULING gstpad.c:4326:gst_pad_chain_data_unchecked:<queue4:sink> called chainfunction &gst_queue_chain with buffer 0x7f046801a5f0, returned ok
0:00:03.518799236 25758 0x7f044c0024f0 DEBUG             GST_BUFFER gstbuffer.c:1375:gst_buffer_is_memory_range_writable: idx 0, length -1
0:00:03.518865258 25758 0x5596e4e50370 DEBUG             bufferpool gstbufferpool.c:304:do_alloc_buffer:<bufferpool1> max buffers reached
0:00:03.518880255 25758 0x5596e4e50370 DEBUG               GST_POLL gstpoll.c:1317:gst_poll_wait: 0x5596e4d2db20: timeout :99:99:99.999999999
5

I can repro the issue locally, will check it internally.

6

Could you increase the batch size to 8/16/32 (practical values for better perf). Or increase In gstnvinfer.cpp increase NVDSINFER_CTX_OUT_POOL_SIZE_FLOW_META (so that if more than default NVDSINFER_CTX_OUT_POOL_SIZE_FLOW_META are present, issue won’t be seen.)

8

thanks, what does NVDSINFER_CTX_OUT_POOL_SIZE_FLOW_META do?

9

NVDSINFER_CTX_OUT_POOL_SIZE_FLOW_META is number of objects in the pool. If we exhaust them then the pipeline will be stuck

1 Like