Not getting buffers from upstream...

mdegans · August 21, 2019, 7:34pm

I finally got back to my project after a family emergency and am still stuck about where I was a few weeks ago. I have a basic pipeline with two branches after a tee but they don’t seem to be getting buffers from the camera through it to either branch. From what I can tell, everything looks right but it’s not working. At this point I’m hoping a second pair of eyes has already experienced this.

Here is my pipeline made with GST_DEBUG_BIN_TO_DOT_FILE and graphviz (may be easier to right click and open the image in a new tab). It’s generated immediately after pipeline linkage, but before it’s set to the playing state:
External Media

Also attached to the fake-sink but not shown is a probe for the metadata.

mdegans · August 21, 2019, 7:34pm

Wow. My post got truncated. I’m going to attempt to post it in chunks. Here is the GStreamer log at level 4.

Error during pretty printers setup: Error while executing Python code.

Some features and performance optimizations will not be available.

/tmp/tmp.k8vyzaB1Ro/generation_path/birbcam_c -o test --gst-debug-level=4
0:00:00.000835689 25351   0x5555578ec0 INFO                GST_INIT gstmessage.c:127:_priv_gst_message_initialize: init messages
0:00:00.002443266 25351   0x5555578ec0 INFO                GST_INIT gstcontext.c:84:_priv_gst_context_initialize: init contexts
0:00:00.003027025 25351   0x5555578ec0 INFO      GST_PLUGIN_LOADING gstplugin.c:317:_priv_gst_plugin_initialize: registering 0 static plugins
0:00:00.003348019 25351   0x5555578ec0 INFO      GST_PLUGIN_LOADING gstplugin.c:225:gst_plugin_register_static: registered static plugin "staticelements"
0:00:00.003401562 25351   0x5555578ec0 INFO      GST_PLUGIN_LOADING gstplugin.c:227:gst_plugin_register_static: added static plugin "staticelements", result: 1
0:00:00.003442343 25351   0x5555578ec0 INFO            GST_REGISTRY gstregistry.c:1727:ensure_current_registry: reading registry cache: /home/anzu/.cache/gstreamer-1.0/registry.aarch64.bin
0:00:00.057341755 25351   0x5555578ec0 INFO            GST_REGISTRY gstregistrybinary.c:621:priv_gst_registry_binary_read_cache: loaded /home/anzu/.cache/gstreamer-1.0/registry.aarch64.bin in 0.053839 seconds
0:00:00.057506341 25351   0x5555578ec0 INFO            GST_REGISTRY gstregistry.c:1583:scan_and_update_registry: Validating plugins from registry cache: /home/anzu/.cache/gstreamer-1.0/registry.aarch64.bin
0:00:00.064412331 25351   0x5555578ec0 INFO            GST_REGISTRY gstregistry.c:1332:gst_registry_scan_path_level:<registry0> cached info for /usr/lib/aarch64-linux-gnu/gstreamer-1.0/libgstvideo4linux2.so is stale
0:00:00.290283101 25351   0x5555578ec0 INFO            GST_REGISTRY gstregistry.c:1694:scan_and_update_registry: Registry cache changed. Writing new registry cache
0:00:00.290422321 25351   0x5555578ec0 INFO            GST_REGISTRY gstregistrybinary.c:369:priv_gst_registry_binary_write_cache: Building binary registry cache image
0:00:00.400163309 25351   0x5555578ec0 INFO            GST_REGISTRY gstregistrybinary.c:401:priv_gst_registry_binary_write_cache: Writing binary registry cache
0:00:00.578374397 25351   0x5555578ec0 INFO            GST_REGISTRY gstregistrybinary.c:262:gst_registry_binary_cache_finish: Wrote binary registry cache
0:00:00.578443826 25351   0x5555578ec0 INFO            GST_REGISTRY gstregistry.c:1703:scan_and_update_registry: Registry cache written successfully
0:00:00.578470857 25351   0x5555578ec0 INFO            GST_REGISTRY gstregistry.c:1762:ensure_current_registry: registry reading and updating done, result = 1
0:00:00.578618151 25351   0x5555578ec0 INFO                GST_INIT gst.c:807:init_post: GLib runtime version: 2.56.4
0:00:00.578653412 25351   0x5555578ec0 INFO                GST_INIT gst.c:809:init_post: GLib headers version: 2.56.4
0:00:00.578672839 25351   0x5555578ec0 INFO                GST_INIT gst.c:810:init_post: initialized GStreamer successfully
0:00:00.579426028 25351   0x5555578ec0 INFO                 default main.c:47:parse_args: MKV FILENAME: test.mkv
0:00:00.579683949 25351   0x5555578ec0 INFO                 default main.c:55:parse_args: METADATA_FILENAME: test.jl
0:00:00.580000568 25351   0x5555578ec0 INFO     GST_ELEMENT_FACTORY gstelementfactory.c:359:gst_element_factory_create: creating element "pipeline" named "pipeline"
0:00:01.203350127 25351   0x5555578ec0 INFO      GST_PLUGIN_LOADING gstplugin.c:901:_priv_gst_plugin_load_file_for_registry: plugin "/usr/lib/aarch64-linux-gnu/gstreamer-1.0/libgstnvarguscamerasrc.so" loaded
0:00:01.203419607 25351   0x5555578ec0 INFO     GST_ELEMENT_FACTORY gstelementfactory.c:359:gst_element_factory_create: creating element "nvarguscamerasrc" named "nvarguscamerasrc"
0:00:01.203834822 25351   0x5555578ec0 INFO        GST_ELEMENT_PADS gstelement.c:670:gst_element_add_pad:<GstBaseSrc@0x55559040e0> adding pad 'src'
0:00:01.231660765 25351   0x5555578ec0 INFO      GST_PLUGIN_LOADING gstplugin.c:901:_priv_gst_plugin_load_file_for_registry: plugin "/usr/lib/aarch64-linux-gnu/gstreamer-1.0/libgstcoreelements.so" loaded
0:00:01.231717120 25351   0x5555578ec0 INFO     GST_ELEMENT_FACTORY gstelementfactory.c:359:gst_element_factory_create: creating element "capsfilter" named "capsfilter"
0:00:01.231933165 25351   0x5555578ec0 INFO        GST_ELEMENT_PADS gstelement.c:670:gst_element_add_pad:<GstBaseTransform@0x55559e6300> adding pad 'sink'
0:00:01.231987697 25351   0x5555578ec0 INFO        GST_ELEMENT_PADS gstelement.c:670:gst_element_add_pad:<GstBaseTransform@0x55559e6300> adding pad 'src'
0:00:01.232094053 25351   0x5555578ec0 INFO               GST_EVENT gstevent.c:1517:gst_event_new_reconfigure: creating reconfigure event
0:00:01.232129939 25351   0x5555578ec0 INFO     GST_ELEMENT_FACTORY gstelementfactory.c:359:gst_element_factory_create: creating element "tee" named "tee"
0:00:01.232293118 25351   0x5555578ec0 INFO        GST_ELEMENT_PADS gstelement.c:670:gst_element_add_pad:<GstTee@0x55559e9000> adding pad 'sink'
0:00:01.232356713 25351   0x5555578ec0 INFO     GST_ELEMENT_FACTORY gstelementfactory.c:359:gst_element_factory_create: creating element "queue" named "enc_queue"
0:00:01.232539893 25351   0x5555578ec0 INFO        GST_ELEMENT_PADS gstelement.c:670:gst_element_add_pad:<GstQueue@0x55559ea0c0> adding pad 'sink'
0:00:01.232592550 25351   0x5555578ec0 INFO        GST_ELEMENT_PADS gstelement.c:670:gst_element_add_pad:<GstQueue@0x55559ea0c0> adding pad 'src'
0:00:01.259036076 25351   0x5555578ec0 INFO      GST_PLUGIN_LOADING gstplugin.c:901:_priv_gst_plugin_load_file_for_registry: plugin "/usr/lib/aarch64-linux-gnu/gstreamer-1.0/libgstnvvideo4linux2.so" loaded
0:00:01.259094566 25351   0x5555578ec0 INFO     GST_ELEMENT_FACTORY gstelementfactory.c:359:gst_element_factory_create: creating element "nvv4l2h265enc" named "nvv4l2h265enc"
0:00:01.259473010 25351   0x5555578ec0 INFO        GST_ELEMENT_PADS gstelement.c:670:gst_element_add_pad:<GstVideoEncoder@0x55558eab10> adding pad 'sink'
0:00:01.259530406 25351   0x5555578ec0 INFO        GST_ELEMENT_PADS gstelement.c:670:gst_element_add_pad:<GstVideoEncoder@0x55558eab10> adding pad 'src'
0:00:01.347914351 25351   0x5555578ec0 INFO      GST_PLUGIN_LOADING gstplugin.c:901:_priv_gst_plugin_load_file_for_registry: plugin "/usr/lib/aarch64-linux-gnu/gstreamer-1.0/libgstvideoparsersbad.so" loaded
0:00:01.347973571 25351   0x5555578ec0 INFO     GST_ELEMENT_FACTORY gstelementfactory.c:359:gst_element_factory_create: creating element "h265parse" named "h265parse"
0:00:01.348206751 25351   0x5555578ec0 INFO        GST_ELEMENT_PADS gstelement.c:670:gst_element_add_pad:<GstBaseParse@0x5555592a60> adding pad 'sink'
0:00:01.348260867 25351   0x5555578ec0 INFO        GST_ELEMENT_PADS gstelement.c:670:gst_element_add_pad:<GstBaseParse@0x5555592a60> adding pad 'src'
0:00:01.348335712 25351   0x5555578ec0 INFO               baseparse gstbaseparse.c:3961:gst_base_parse_set_pts_interpolation:<GstH265Parse@0x5555592a60> PTS interpolation: no
0:00:01.381726947 25351   0x5555578ec0 INFO      GST_PLUGIN_LOADING gstplugin.c:901:_priv_gst_plugin_load_file_for_registry: plugin "/usr/lib/aarch64-linux-gnu/gstreamer-1.0/libgstmatroska.so" loaded
0:00:01.381784656 25351   0x5555578ec0 INFO     GST_ELEMENT_FACTORY gstelementfactory.c:359:gst_element_factory_create: creating element "matroskamux" named "matroskamux"
0:00:01.382317425 25351   0x5555578ec0 INFO        GST_ELEMENT_PADS gstelement.c:670:gst_element_add_pad:<GstMatroskaMux@0x55559f8000> adding pad 'src'
0:00:01.382495292 25351   0x5555578ec0 INFO     GST_ELEMENT_FACTORY gstelementfactory.c:359:gst_element_factory_create: creating element "filesink" named "filesink"
0:00:01.382684253 25351   0x5555578ec0 INFO        GST_ELEMENT_PADS gstelement.c:670:gst_element_add_pad:<GstBaseSink@0x55558c8be0> adding pad 'sink'
0:00:01.382773005 25351   0x5555578ec0 INFO                filesink gstfilesink.c:294:gst_file_sink_set_location:<filesink> filename : test.mkv
0:00:01.382796130 25351   0x5555578ec0 INFO                filesink gstfilesink.c:295:gst_file_sink_set_location:<filesink> uri      : file:///tmp/tmp.k8vyzaB1Ro/generation_path/test.mkv
0:00:01.382820037 25351   0x5555578ec0 INFO     GST_ELEMENT_FACTORY gstelementfactory.c:359:gst_element_factory_create: creating element "queue" named "infer_queue"
0:00:01.382902173 25351   0x5555578ec0 INFO        GST_ELEMENT_PADS gstelement.c:670:gst_element_add_pad:<GstQueue@0x55559ea3c0> adding pad 'sink'
0:00:01.382958216 25351   0x5555578ec0 INFO        GST_ELEMENT_PADS gstelement.c:670:gst_element_add_pad:<GstQueue@0x55559ea3c0> adding pad 'src'
0:00:01.518889184 25351   0x5555578ec0 INFO      GST_PLUGIN_LOADING gstplugin.c:901:_priv_gst_plugin_load_file_for_registry: plugin "/usr/lib/aarch64-linux-gnu/gstreamer-1.0/deepstream/libnvdsgst_multistream.so" loaded
0:00:01.518945279 25351   0x5555578ec0 INFO     GST_ELEMENT_FACTORY gstelementfactory.c:359:gst_element_factory_create: creating element "nvstreammux" named "nvstreammux"
0:00:01.519248096 25351   0x5555578ec0 INFO        GST_ELEMENT_PADS gstelement.c:670:gst_element_add_pad:<GstNvStreamMux@0x55559ea6c0> adding pad 'src'
0:00:02.422886906 25351   0x5555578ec0 INFO      GST_PLUGIN_LOADING gstplugin.c:901:_priv_gst_plugin_load_file_for_registry: plugin "/usr/lib/aarch64-linux-gnu/gstreamer-1.0/deepstream/libnvdsgst_infer.so" loaded
0:00:02.422962428 25351   0x5555578ec0 INFO     GST_ELEMENT_FACTORY gstelementfactory.c:359:gst_element_factory_create: creating element "nvinfer" named "nvinfer"
0:00:02.426288364 25351   0x5555578ec0 INFO        GST_ELEMENT_PADS gstelement.c:670:gst_element_add_pad:<GstBaseTransform@0x5555cc9390> adding pad 'sink'
0:00:02.426399928 25351   0x5555578ec0 INFO        GST_ELEMENT_PADS gstelement.c:670:gst_element_add_pad:<GstBaseTransform@0x5555cc9390> adding pad 'src'
0:00:02.429118146 25351   0x5555578ec0 INFO     GST_ELEMENT_FACTORY gstelementfactory.c:359:gst_element_factory_create: creating element "fakesink" named "fakesink"
0:00:02.429534715 25351   0x5555578ec0 INFO        GST_ELEMENT_PADS gstelement.c:670:gst_element_add_pad:<GstBaseSink@0x5555cd79e0> adding pad 'sink'
0:00:02.429623779 25351   0x5555578ec0 INFO        GST_ELEMENT_PADS gstutils.c:1774:gst_element_link_pads_full: trying to link element nvarguscamerasrc:(any) to element capsfilter:(any)
0:00:02.429660967 25351   0x5555578ec0 INFO                GST_PADS gstutils.c:1035:gst_pad_check_link: trying to link nvarguscamerasrc:src and capsfilter:sink
0:00:02.429699197 25351   0x5555578ec0 INFO                GST_PADS gstpad.c:4232:gst_pad_peer_query:<capsfilter:src> pad has no peer
0:00:02.429755604 25351   0x5555578ec0 INFO                GST_PADS gstutils.c:1588:prepare_link_maybe_ghosting: nvarguscamerasrc and capsfilter in same bin, no need for ghost pads
0:00:02.429803573 25351   0x5555578ec0 INFO                GST_PADS gstpad.c:2378:gst_pad_link_prepare: trying to link nvarguscamerasrc:src and capsfilter:sink
0:00:02.429846855 25351   0x5555578ec0 INFO                GST_PADS gstpad.c:4232:gst_pad_peer_query:<capsfilter:src> pad has no peer
0:00:02.429885866 25351   0x5555578ec0 INFO                GST_PADS gstpad.c:2586:gst_pad_link_full: linked nvarguscamerasrc:src and capsfilter:sink, successful
0:00:02.429909096 25351   0x5555578ec0 INFO               GST_EVENT gstevent.c:1517:gst_event_new_reconfigure: creating reconfigure event
0:00:02.429940763 25351   0x5555578ec0 INFO               GST_EVENT gstpad.c:5808:gst_pad_send_event_unchecked:<nvarguscamerasrc:src> Received event on flushing pad. Discarding
0:00:02.429979774 25351   0x5555578ec0 INFO        GST_ELEMENT_PADS gstutils.c:1774:gst_element_link_pads_full: trying to link element capsfilter:(any) to element tee:(any)
0:00:02.430025712 25351   0x5555578ec0 INFO                GST_PADS gstutils.c:1035:gst_pad_check_link: trying to link capsfilter:src and tee:sink
0:00:02.430138839 25351   0x5555578ec0 INFO                GST_PADS gstutils.c:1588:prepare_link_maybe_ghosting: capsfilter and tee in same bin, no need for ghost pads
0:00:02.430184985 25351   0x5555578ec0 INFO                GST_PADS gstpad.c:2378:gst_pad_link_prepare: trying to link capsfilter:src and tee:sink
0:00:02.430273007 25351   0x5555578ec0 INFO                GST_PADS gstpad.c:2586:gst_pad_link_full: linked capsfilter:src and tee:sink, successful
0:00:02.430297956 25351   0x5555578ec0 INFO               GST_EVENT gstevent.c:1517:gst_event_new_reconfigure: creating reconfigure event
0:00:02.430330352 25351   0x5555578ec0 INFO               GST_EVENT gstpad.c:5808:gst_pad_send_event_unchecked:<capsfilter:src> Received event on flushing pad. Discarding
0:00:02.430370040 25351   0x5555578ec0 INFO        GST_ELEMENT_PADS gstutils.c:1774:gst_element_link_pads_full: trying to link element enc_queue:(any) to element nvv4l2h265enc:(any)
0:00:02.430430041 25351   0x5555578ec0 INFO                GST_PADS gstutils.c:1035:gst_pad_check_link: trying to link enc_queue:src and nvv4l2h265enc:sink
0:00:02.430469885 25351   0x5555578ec0 INFO                GST_PADS gstpad.c:4232:gst_pad_peer_query:<enc_queue:sink> pad has no peer
0:00:02.430524990 25351   0x5555578ec0 INFO                GST_PADS gstpad.c:4232:gst_pad_peer_query:<nvv4l2h265enc:src> pad has no peer
0:00:02.430599210 25351   0x5555578ec0 INFO                GST_PADS gstutils.c:1588:prepare_link_maybe_ghosting: enc_queue and nvv4l2h265enc in same bin, no need for ghost pads
0:00:02.430656190 25351   0x5555578ec0 INFO                GST_PADS gstpad.c:2378:gst_pad_link_prepare: trying to link enc_queue:src and nvv4l2h265enc:sink
0:00:02.430689628 25351   0x5555578ec0 INFO                GST_PADS gstpad.c:4232:gst_pad_peer_query:<enc_queue:sink> pad has no peer
0:00:02.430756660 25351   0x5555578ec0 INFO                GST_PADS gstpad.c:4232:gst_pad_peer_query:<nvv4l2h265enc:src> pad has no peer
0:00:02.430837130 25351   0x5555578ec0 INFO                GST_PADS gstpad.c:2586:gst_pad_link_full: linked enc_queue:src and nvv4l2h265enc:sink, successful
0:00:02.430860725 25351   0x5555578ec0 INFO               GST_EVENT gstevent.c:1517:gst_event_new_reconfigure: creating reconfigure event
0:00:02.430879475 25351   0x5555578ec0 INFO               GST_EVENT gstpad.c:5808:gst_pad_send_event_unchecked:<enc_queue:src> Received event on flushing pad. Discarding
0:00:02.430937809 25351   0x5555578ec0 INFO        GST_ELEMENT_PADS gstutils.c:1774:gst_element_link_pads_full: trying to link element nvv4l2h265enc:(any) to element h265parse:(any)
0:00:02.430973695 25351   0x5555578ec0 INFO                GST_PADS gstutils.c:1035:gst_pad_check_link: trying to link nvv4l2h265enc:src and h265parse:sink
0:00:02.431027133 25351   0x5555578ec0 INFO                GST_PADS gstpad.c:4232:gst_pad_peer_query:<h265parse:src> pad has no peer
0:00:02.431069999 25351   0x5555578ec0 INFO                GST_PADS gstutils.c:1588:prepare_link_maybe_ghosting: nvv4l2h265enc and h265parse in same bin, no need for ghost pads
0:00:02.431121979 25351   0x5555578ec0 INFO                GST_PADS gstpad.c:2378:gst_pad_link_prepare: trying to link nvv4l2h265enc:src and h265parse:sink
0:00:02.431157812 25351   0x5555578ec0 INFO                GST_PADS gstpad.c:4232:gst_pad_peer_query:<h265parse:src> pad has no peer
0:00:02.431212292 25351   0x5555578ec0 INFO                GST_PADS gstpad.c:2586:gst_pad_link_full: linked nvv4l2h265enc:src and h265parse:sink, successful
0:00:02.431234949 25351   0x5555578ec0 INFO               GST_EVENT gstevent.c:1517:gst_event_new_reconfigure: creating reconfigure event
0:00:02.431253595 25351   0x5555578ec0 INFO               GST_EVENT gstpad.c:5808:gst_pad_send_event_unchecked:<nvv4l2h265enc:src> Received event on flushing pad. Discarding
0:00:02.431302502 25351   0x5555578ec0 INFO        GST_ELEMENT_PADS gstutils.c:1774:gst_element_link_pads_full: trying to link element h265parse:(any) to element matroskamux:(any)
0:00:02.431543391 25351   0x5555578ec0 INFO        GST_ELEMENT_PADS gstelement.c:670:gst_element_add_pad:<matroskamux> adding pad 'video_0'
0:00:02.431598965 25351   0x5555578ec0 INFO                GST_PADS gstutils.c:1588:prepare_link_maybe_ghosting: h265parse and matroskamux in same bin, no need for ghost pads
0:00:02.431634070 25351   0x5555578ec0 INFO                GST_PADS gstpad.c:2378:gst_pad_link_prepare: trying to link h265parse:src and matroskamux:video_0
0:00:02.431693914 25351   0x5555578ec0 INFO                GST_PADS gstpad.c:2586:gst_pad_link_full: linked h265parse:src and matroskamux:video_0, successful
0:00:02.431720894 25351   0x5555578ec0 INFO               GST_EVENT gstevent.c:1517:gst_event_new_reconfigure: creating reconfigure event
0:00:02.431751936 25351   0x5555578ec0 INFO               GST_EVENT gstpad.c:5808:gst_pad_send_event_unchecked:<h265parse:src> Received event on flushing pad. Discarding
0:00:02.431797197 25351   0x5555578ec0 INFO        GST_ELEMENT_PADS gstutils.c:1774:gst_element_link_pads_full: trying to link element matroskamux:(any) to element filesink:(any)
0:00:02.431843708 25351   0x5555578ec0 INFO                GST_PADS gstutils.c:1035:gst_pad_check_link: trying to link matroskamux:src and filesink:sink
0:00:02.431891053 25351   0x5555578ec0 INFO                GST_PADS gstutils.c:1588:prepare_link_maybe_ghosting: matroskamux and filesink in same bin, no need for ghost pads
0:00:02.431930064 25351   0x5555578ec0 INFO                GST_PADS gstpad.c:2378:gst_pad_link_prepare: trying to link matroskamux:src and filesink:sink
0:00:02.431974439 25351   0x5555578ec0 INFO                GST_PADS gstpad.c:2586:gst_pad_link_full: linked matroskamux:src and filesink:sink, successful
0:00:02.431999284 25351   0x5555578ec0 INFO               GST_EVENT gstevent.c:1517:gst_event_new_reconfigure: creating reconfigure event
0:00:02.432017721 25351   0x5555578ec0 INFO               GST_EVENT gstpad.c:5808:gst_pad_send_event_unchecked:<matroskamux:src> Received event on flushing pad. Discarding
0:00:02.432060066 25351   0x5555578ec0 INFO        GST_ELEMENT_PADS gstutils.c:1774:gst_element_link_pads_full: trying to link element infer_queue:src to element nvstreammux:sink_0
0:00:02.432089233 25351   0x5555578ec0 INFO        GST_ELEMENT_PADS gstelement.c:920:gst_element_get_static_pad: found pad infer_queue:src
0:00:02.432111525 25351   0x5555578ec0 INFO        GST_ELEMENT_PADS gstelement.c:917:gst_element_get_static_pad: no such pad 'sink_0' in element "nvstreammux"
0:00:02.432143713 25351   0x5555578ec0 INFO        GST_ELEMENT_PADS gstelement.c:917:gst_element_get_static_pad: no such pad 'sink_0' in element "nvstreammux"
0:00:02.432229183 25351   0x5555578ec0 INFO        GST_ELEMENT_PADS gstelement.c:670:gst_element_add_pad:<nvstreammux> adding pad 'sink_0'
0:00:02.432264444 25351   0x5555578ec0 INFO                GST_PADS gstutils.c:1588:prepare_link_maybe_ghosting: infer_queue and nvstreammux in same bin, no need for ghost pads
0:00:02.432303924 25351   0x5555578ec0 INFO                GST_PADS gstpad.c:2378:gst_pad_link_prepare: trying to link infer_queue:src and nvstreammux:sink_0
0:00:02.432338299 25351   0x5555578ec0 INFO                GST_PADS gstpad.c:4232:gst_pad_peer_query:<infer_queue:sink> pad has no peer
0:00:02.432378508 25351   0x5555578ec0 INFO                GST_PADS gstpad.c:4232:gst_pad_peer_query:<nvstreammux:src> pad has no peer
0:00:02.432482885 25351   0x5555578ec0 INFO                GST_PADS gstpad.c:2586:gst_pad_link_full: linked infer_queue:src and nvstreammux:sink_0, successful
0:00:02.432508354 25351   0x5555578ec0 INFO               GST_EVENT gstevent.c:1517:gst_event_new_reconfigure: creating reconfigure event
0:00:02.432526687 25351   0x5555578ec0 INFO               GST_EVENT gstpad.c:5808:gst_pad_send_event_unchecked:<infer_queue:src> Received event on flushing pad. Discarding
0:00:02.432569396 25351   0x5555578ec0 INFO        GST_ELEMENT_PADS gstutils.c:1774:gst_element_link_pads_full: trying to link element nvstreammux:(any) to element nvinfer:(any)
0:00:02.432603095 25351   0x5555578ec0 INFO                GST_PADS gstutils.c:1035:gst_pad_check_link: trying to link nvstreammux:src and nvinfer:sink
0:00:02.432641897 25351   0x5555578ec0 INFO                GST_PADS gstpad.c:4232:gst_pad_peer_query:<nvinfer:src> pad has no peer
0:00:02.432714503 25351   0x5555578ec0 INFO                GST_PADS gstutils.c:1588:prepare_link_maybe_ghosting: nvstreammux and nvinfer in same bin, no need for ghost pads
0:00:02.432753357 25351   0x5555578ec0 INFO                GST_PADS gstpad.c:2378:gst_pad_link_prepare: trying to link nvstreammux:src and nvinfer:sink
0:00:02.432789973 25351   0x5555578ec0 INFO                GST_PADS gstpad.c:4232:gst_pad_peer_query:<nvinfer:src> pad has no peer
0:00:02.432856744 25351   0x5555578ec0 INFO                GST_PADS gstpad.c:2586:gst_pad_link_full: linked nvstreammux:src and nvinfer:sink, successful
0:00:02.432879714 25351   0x5555578ec0 INFO               GST_EVENT gstevent.c:1517:gst_event_new_reconfigure: creating reconfigure event
0:00:02.432897891 25351   0x5555578ec0 INFO               GST_EVENT gstpad.c:5808:gst_pad_send_event_unchecked:<nvstreammux:src> Received event on flushing pad. Discarding
0:00:02.432941433 25351   0x5555578ec0 INFO        GST_ELEMENT_PADS gstutils.c:1774:gst_element_link_pads_full: trying to link element nvinfer:(any) to element fakesink:(any)
0:00:02.432977163 25351   0x5555578ec0 INFO                GST_PADS gstutils.c:1035:gst_pad_check_link: trying to link nvinfer:src and fakesink:sink
0:00:02.433070758 25351   0x5555578ec0 INFO                GST_PADS gstutils.c:1588:prepare_link_maybe_ghosting: nvinfer and fakesink in same bin, no need for ghost pads
0:00:02.433110498 25351   0x5555578ec0 INFO                GST_PADS gstpad.c:2378:gst_pad_link_prepare: trying to link nvinfer:src and fakesink:sink
0:00:02.433205604 25351   0x5555578ec0 INFO                GST_PADS gstpad.c:2586:gst_pad_link_full: linked nvinfer:src and fakesink:sink, successful
0:00:02.433330085 25351   0x5555578ec0 INFO               GST_EVENT gstevent.c:1517:gst_event_new_reconfigure: creating reconfigure event
0:00:02.433350242 25351   0x5555578ec0 INFO               GST_EVENT gstpad.c:5808:gst_pad_send_event_unchecked:<nvinfer:src> Received event on flushing pad. Discarding
0:00:02.433383107 25351   0x5555578ec0 INFO        GST_ELEMENT_PADS gstutils.c:1774:gst_element_link_pads_full: trying to link element tee:(any) to element enc_queue:(any)
0:00:02.433660507 25351   0x5555578ec0 INFO        GST_ELEMENT_PADS gstelement.c:670:gst_element_add_pad:<tee> adding pad 'src_0'
0:00:02.433693163 25351   0x5555578ec0 INFO                GST_PADS gstutils.c:1588:prepare_link_maybe_ghosting: tee and enc_queue in same bin, no need for ghost pads
0:00:02.433765300 25351   0x5555578ec0 INFO                GST_PADS gstpad.c:2378:gst_pad_link_prepare: trying to link tee:src_0 and enc_queue:sink
0:00:02.434001866 25351   0x5555578ec0 INFO                GST_PADS gstpad.c:2586:gst_pad_link_full: linked tee:src_0 and enc_queue:sink, successful
0:00:02.434022231 25351   0x5555578ec0 INFO               GST_EVENT gstevent.c:1517:gst_event_new_reconfigure: creating reconfigure event
0:00:02.434073065 25351   0x5555578ec0 INFO               GST_EVENT gstpad.c:5808:gst_pad_send_event_unchecked:<tee:src_0> Received event on flushing pad. Discarding
0:00:02.434102440 25351   0x5555578ec0 INFO        GST_ELEMENT_PADS gstutils.c:1774:gst_element_link_pads_full: trying to link element tee:(any) to element infer_queue:(any)
0:00:02.434269266 25351   0x5555578ec0 INFO        GST_ELEMENT_PADS gstelement.c:670:gst_element_add_pad:<tee> adding pad 'src_1'
0:00:02.434303381 25351   0x5555578ec0 INFO                GST_PADS gstutils.c:1588:prepare_link_maybe_ghosting: tee and infer_queue in same bin, no need for ghost pads
0:00:02.434327860 25351   0x5555578ec0 INFO                GST_PADS gstpad.c:2378:gst_pad_link_prepare: trying to link tee:src_1 and infer_queue:sink
0:00:02.434467342 25351   0x5555578ec0 INFO                GST_PADS gstpad.c:2586:gst_pad_link_full: linked tee:src_1 and infer_queue:sink, successful
0:00:02.434485155 25351   0x5555578ec0 INFO               GST_EVENT gstevent.c:1517:gst_event_new_reconfigure: creating reconfigure event
0:00:02.434498332 25351   0x5555578ec0 INFO               GST_EVENT gstpad.c:5808:gst_pad_send_event_unchecked:<tee:src_1> Received event on flushing pad. Discarding
0:00:02.434619219 25351   0x5555578ec0 INFO              GST_STATES gstbin.c:2089:gst_bin_get_state_func:<pipeline> getting state
0:00:02.527479586 25351   0x5555578ec0 INFO                    v4l2 v4l2_calls.c:622:gst_v4l2_open:<nvv4l2h265enc:sink> Opened device '' (/dev/nvhost-msenc) successfully
0:00:02.549974510 25351   0x5555578ec0 INFO                 default gstdebugutils.c:864:gst_debug_bin_to_dot_file: wrote bin graph to : '/tmp/pipeline.dot'
0:00:02.551131559 25351   0x5555578ec0 INFO        GST_ELEMENT_PADS gstelement.c:920:gst_element_get_static_pad: found pad fakesink:sink
0:00:02.551275311 25351   0x5555578ec0 INFO              GST_STATES gstbin.c:2506:gst_bin_element_set_state:<fakesink> current NULL pending VOID_PENDING, desired next READY
0:00:02.551301718 25351   0x5555578ec0 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<fakesink> completed state change to READY
0:00:02.551321875 25351   0x5555578ec0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<fakesink> notifying about state-changed NULL to READY (VOID_PENDING pending)
0:00:02.551368594 25351   0x5555578ec0 INFO              GST_STATES gstbin.c:2954:gst_bin_change_state_func:<pipeline> child 'fakesink' changed state to 2(READY) successfully
0:00:02.551394063 25351   0x5555578ec0 INFO              GST_STATES gstbin.c:2506:gst_bin_element_set_state:<filesink> current NULL pending VOID_PENDING, desired next READY
0:00:02.551490002 25351   0x5555578ec0 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<filesink> completed state change to READY
0:00:02.551512346 25351   0x5555578ec0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<filesink> notifying about state-changed NULL to READY (VOID_PENDING pending)
0:00:02.551540420 25351   0x5555578ec0 INFO              GST_STATES gstbin.c:2954:gst_bin_change_state_func:<pipeline> child 'filesink' changed state to 2(READY) successfully
0:00:02.551561097 25351   0x5555578ec0 INFO              GST_STATES gstbin.c:2506:gst_bin_element_set_state:<nvinfer> current NULL pending VOID_PENDING, desired next READY
0:00:02.551580941 25351   0x5555578ec0 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<nvinfer> completed state change to READY
0:00:02.551599795 25351   0x5555578ec0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<nvinfer> notifying about state-changed NULL to READY (VOID_PENDING pending)
0:00:02.551624900 25351   0x5555578ec0 INFO              GST_STATES gstbin.c:2954:gst_bin_change_state_func:<pipeline> child 'nvinfer' changed state to 2(READY) successfully
0:00:02.551648338 25351   0x5555578ec0 INFO              GST_STATES gstbin.c:2506:gst_bin_element_set_state:<matroskamux> current NULL pending VOID_PENDING, desired next READY
0:00:02.551668546 25351   0x5555578ec0 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<matroskamux> completed state change to READY
0:00:02.551687557 25351   0x5555578ec0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<matroskamux> notifying about state-changed NULL to READY (VOID_PENDING pending)
0:00:02.551712662 25351   0x5555578ec0 INFO              GST_STATES gstbin.c:2954:gst_bin_change_state_func:<pipeline> child 'matroskamux' changed state to 2(READY) successfully
0:00:02.551737089 25351   0x5555578ec0 INFO              GST_STATES gstbin.c:2506:gst_bin_element_set_state:<nvstreammux> current NULL pending VOID_PENDING, desired next READY
0:00:02.634150318 25351   0x5555578ec0 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<nvstreammux> completed state change to READY
0:00:02.634209590 25351   0x5555578ec0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<nvstreammux> notifying about state-changed NULL to READY (VOID_PENDING pending)
0:00:02.634254799 25351   0x5555578ec0 INFO              GST_STATES gstbin.c:2954:gst_bin_change_state_func:<pipeline> child 'nvstreammux' changed state to 2(READY) successfully
0:00:02.634298133 25351   0x5555578ec0 INFO              GST_STATES gstbin.c:2506:gst_bin_element_set_state:<h265parse> current NULL pending VOID_PENDING, desired next READY
0:00:02.634325738 25351   0x5555578ec0 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<h265parse> completed state change to READY
0:00:02.634349019 25351   0x5555578ec0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<h265parse> notifying about state-changed NULL to READY (VOID_PENDING pending)
0:00:02.634392457 25351   0x5555578ec0 INFO              GST_STATES gstbin.c:2954:gst_bin_change_state_func:<pipeline> child 'h265parse' changed state to 2(READY) successfully
0:00:02.634426781 25351   0x5555578ec0 INFO              GST_STATES gstbin.c:2506:gst_bin_element_set_state:<infer_queue> current NULL pending VOID_PENDING, desired next READY
0:00:02.634449698 25351   0x5555578ec0 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<infer_queue> completed state change to READY
0:00:02.634470011 25351   0x5555578ec0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<infer_queue> notifying about state-changed NULL to READY (VOID_PENDING pending)
0:00:02.634498188 25351   0x5555578ec0 INFO              GST_STATES gstbin.c:2954:gst_bin_change_state_func:<pipeline> child 'infer_queue' changed state to 2(READY) successfully
0:00:02.634526053 25351   0x5555578ec0 INFO              GST_STATES gstbin.c:2506:gst_bin_element_set_state:<nvv4l2h265enc> current NULL pending VOID_PENDING, desired next READY
0:00:02.689716994 25351   0x5555578ec0 INFO                    v4l2 v4l2_calls.c:622:gst_v4l2_open:<nvv4l2h265enc:sink> Opened device '' (/dev/nvhost-msenc) successfully
0:00:02.689777204 25351   0x5555578ec0 INFO                    v4l2 v4l2_calls.c:723:gst_v4l2_dup:<nvv4l2h265enc:src> Cloned device '' (/dev/nvhost-msenc) successfully
0:00:02.691008368 25351   0x5555578ec0 INFO                    v4l2 gstv4l2object.c:1280:gst_v4l2_object_fill_format_list:<nvv4l2h265enc:sink> got 4 format(s):
0:00:02.691038473 25351   0x5555578ec0 INFO                    v4l2 gstv4l2object.c:1286:gst_v4l2_object_fill_format_list:<nvv4l2h265enc:sink>   YM12
0:00:02.691055608 25351   0x5555578ec0 INFO                    v4l2 gstv4l2object.c:1286:gst_v4l2_object_fill_format_list:<nvv4l2h265enc:sink>   PM10
0:00:02.691072067 25351   0x5555578ec0 INFO                    v4l2 gstv4l2object.c:1286:gst_v4l2_object_fill_format_list:<nvv4l2h265enc:sink>   NM12
0:00:02.691088161 25351   0x5555578ec0 INFO                    v4l2 gstv4l2object.c:1286:gst_v4l2_object_fill_format_list:<nvv4l2h265enc:sink>   YM24
0:00:02.691129412 25351   0x5555578ec0 WARN                    v4l2 gstv4l2object.c:2370:gst_v4l2_object_add_interlace_mode:0x555599c400 Failed to determine interlace mode
0:00:02.691171131 25351   0x5555578ec0 WARN                    v4l2 gstv4l2object.c:2370:gst_v4l2_object_add_interlace_mode:0x555599c400 Failed to determine interlace mode
0:00:02.691207955 25351   0x5555578ec0 WARN                    v4l2 gstv4l2object.c:2370:gst_v4l2_object_add_interlace_mode:0x555599c400 Failed to determine interlace mode
0:00:02.691301862 25351   0x5555578ec0 INFO                    v4l2 gstv4l2object.c:4464:gst_v4l2_object_probe_caps:<nvv4l2h265enc:sink> probed caps: video/x-raw, format=(string)I420, width=(int)[ 48, 4096 ], height=(int)[ 48, 4096 ], framerate=(fraction)[ 0/1, 2147483647/1 ]; video/x-raw, format=(string)P010_10LE, width=(int)[ 48, 4096 ], height=(int)[ 48, 4096 ], framerate=(fraction)[ 0/1, 2147483647/1 ]; video/x-raw, format=(string)NV12, width=(int)[ 48, 4096 ], height=(int)[ 48, 4096 ], framerate=(fraction)[ 0/1, 2147483647/1 ]
0:00:02.691329206 25351   0x5555578ec0 INFO                    v4l2 gstv4l2object.c:1280:gst_v4l2_object_fill_format_list:<nvv4l2h265enc:src> got 3 format(s):
0:00:02.691345977 25351   0x5555578ec0 INFO                    v4l2 gstv4l2object.c:1286:gst_v4l2_object_fill_format_list:<nvv4l2h265enc:src>   VP80
0:00:02.691360874 25351   0x5555578ec0 INFO                    v4l2 gstv4l2object.c:1286:gst_v4l2_object_fill_format_list:<nvv4l2h265enc:src>   H265
0:00:02.691375822 25351   0x5555578ec0 INFO                    v4l2 gstv4l2object.c:1286:gst_v4l2_object_fill_format_list:<nvv4l2h265enc:src>   H264
0:00:02.691421604 25351   0x5555578ec0 WARN                    v4l2 gstv4l2object.c:4408:gst_v4l2_object_probe_caps:<nvv4l2h265enc:src> Failed to probe pixel aspect ratio with VIDIOC_CROPCAP: Unknown error -1
0:00:02.691494938 25351   0x5555578ec0 INFO                    v4l2 gstv4l2object.c:4464:gst_v4l2_object_probe_caps:<nvv4l2h265enc:src> probed caps: video/x-h265, stream-format=(string)byte-stream, alignment=(string)au, width=(int)[ 48, 4096 ], height=(int)[ 48, 4096 ], framerate=(fraction)[ 0/1, 2147483647/1 ]
0:00:02.691555043 25351   0x5555578ec0 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<nvv4l2h265enc> completed state change to READY
0:00:02.691576606 25351   0x5555578ec0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<nvv4l2h265enc> notifying about state-changed NULL to READY (VOID_PENDING pending)
0:00:02.691611815 25351   0x5555578ec0 INFO              GST_STATES gstbin.c:2954:gst_bin_change_state_func:<pipeline> child 'nvv4l2h265enc' changed state to 2(READY) successfully
0:00:02.691651451 25351   0x5555578ec0 INFO              GST_STATES gstbin.c:2506:gst_bin_element_set_state:<enc_queue> current NULL pending VOID_PENDING, desired next READY
0:00:02.691670357 25351   0x5555578ec0 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<enc_queue> completed state change to READY
0:00:02.691686920 25351   0x5555578ec0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<enc_queue> notifying about state-changed NULL to READY (VOID_PENDING pending)
0:00:02.691710202 25351   0x5555578ec0 INFO              GST_STATES gstbin.c:2954:gst_bin_change_state_func:<pipeline> child 'enc_queue' changed state to 2(READY) successfully
0:00:02.691734473 25351   0x5555578ec0 INFO              GST_STATES gstbin.c:2506:gst_bin_element_set_state:<tee> current NULL pending VOID_PENDING, desired next READY
0:00:02.691751609 25351   0x5555578ec0 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<tee> completed state change to READY
0:00:02.691766817 25351   0x5555578ec0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<tee> notifying about state-changed NULL to READY (VOID_PENDING pending)
0:00:02.691787859 25351   0x5555578ec0 INFO              GST_STATES gstbin.c:2954:gst_bin_change_state_func:<pipeline> child 'tee' changed state to 2(READY) successfully
0:00:02.691811037 25351   0x5555578ec0 INFO              GST_STATES gstbin.c:2506:gst_bin_element_set_state:<capsfilter> current NULL pending VOID_PENDING, desired next READY
0:00:02.691827339 25351   0x5555578ec0 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<capsfilter> completed state change to READY
0:00:02.691842808 25351   0x5555578ec0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<capsfilter> notifying about state-changed NULL to READY (VOID_PENDING pending)
0:00:02.691865100 25351   0x5555578ec0 INFO              GST_STATES gstbin.c:2954:gst_bin_change_state_func:<pipeline> child 'capsfilter' changed state to 2(READY) successfully
0:00:02.691885204 25351   0x5555578ec0 INFO              GST_STATES gstbin.c:2506:gst_bin_element_set_state:<nvarguscamerasrc> current NULL pending VOID_PENDING, desired next READY
0:00:02.691902236 25351   0x5555578ec0 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<nvarguscamerasrc> completed state change to READY
0:00:02.691918486 25351   0x5555578ec0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<nvarguscamerasrc> notifying about state-changed NULL to READY (VOID_PENDING pending)
0:00:02.691942289 25351   0x5555578ec0 INFO              GST_STATES gstbin.c:2954:gst_bin_change_state_func:<pipeline> child 'nvarguscamerasrc' changed state to 2(READY) successfully
0:00:02.691976143 25351   0x5555578ec0 INFO              GST_STATES gstelement.c:2651:gst_element_continue_state:<pipeline> committing state from NULL to READY, pending PLAYING, next PAUSED

mdegans · August 21, 2019, 7:38pm

log continued

0:00:02.691996039 25351   0x5555578ec0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<pipeline> notifying about state-changed NULL to READY (PLAYING pending)
0:00:02.692018748 25351   0x5555578ec0 INFO              GST_STATES gstelement.c:2658:gst_element_continue_state:<pipeline> continue state change READY to PAUSED, final PLAYING
0:00:02.692077811 25351   0x5555578ec0 INFO              GST_STATES gstbin.c:2506:gst_bin_element_set_state:<fakesink> current READY pending VOID_PENDING, desired next PAUSED
0:00:02.692116354 25351   0x5555578ec0 INFO              GST_STATES gstbin.c:2960:gst_bin_change_state_func:<pipeline> child 'fakesink' is changing state asynchronously to PAUSED
0:00:02.692139114 25351   0x5555578ec0 INFO              GST_STATES gstbin.c:2506:gst_bin_element_set_state:<filesink> current READY pending VOID_PENDING, desired next PAUSED
0:00:02.692168073 25351   0x5555578ec0 INFO              GST_STATES gstbin.c:2960:gst_bin_change_state_func:<pipeline> child 'filesink' is changing state asynchronously to PAUSED
0:00:02.692190313 25351   0x5555578ec0 INFO              GST_STATES gstbin.c:2506:gst_bin_element_set_state:<nvinfer> current READY pending VOID_PENDING, desired next PAUSED
0:00:13.279417168 25351   0x5555578ec0 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<nvinfer> completed state change to PAUSED
0:00:13.279705870 25351   0x5555578ec0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<nvinfer> notifying about state-changed READY to PAUSED (VOID_PENDING pending)
0:00:13.279773996 25351   0x5555578ec0 INFO              GST_STATES gstbin.c:2954:gst_bin_change_state_func:<pipeline> child 'nvinfer' changed state to 3(PAUSED) successfully
0:00:13.279826549 25351   0x5555578ec0 INFO              GST_STATES gstbin.c:2506:gst_bin_element_set_state:<matroskamux> current READY pending VOID_PENDING, desired next PAUSED
0:00:13.279882800 25351   0x5555578ec0 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<matroskamux> completed state change to PAUSED
0:00:13.279915821 25351   0x5555578ec0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<matroskamux> notifying about state-changed READY to PAUSED (VOID_PENDING pending)
0:00:13.279960717 25351   0x5555578ec0 INFO              GST_STATES gstbin.c:2954:gst_bin_change_state_func:<pipeline> child 'matroskamux' changed state to 3(PAUSED) successfully
0:00:13.280007385 25351   0x5555578ec0 INFO              GST_STATES gstbin.c:2506:gst_bin_element_set_state:<nvstreammux> current READY pending VOID_PENDING, desired next PAUSED
0:00:13.280144783 25351   0x5555578ec0 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<nvstreammux> completed state change to PAUSED
0:00:13.280166137 25351   0x5555578ec0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<nvstreammux> notifying about state-changed READY to PAUSED (VOID_PENDING pending)
0:00:13.280195773 25351   0x5555578ec0 INFO              GST_STATES gstbin.c:2954:gst_bin_change_state_func:<pipeline> child 'nvstreammux' changed state to 3(PAUSED) successfully
0:00:13.280221034 25351   0x5555578ec0 INFO              GST_STATES gstbin.c:2506:gst_bin_element_set_state:<h265parse> current READY pending VOID_PENDING, desired next PAUSED
0:00:13.280461246 25351   0x5555578ec0 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<h265parse> completed state change to PAUSED
0:00:13.280486298 25351   0x5555578ec0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<h265parse> notifying about state-changed READY to PAUSED (VOID_PENDING pending)
0:00:13.280516663 25351   0x5555578ec0 INFO              GST_STATES gstbin.c:2954:gst_bin_change_state_func:<pipeline> child 'h265parse' changed state to 3(PAUSED) successfully
0:00:13.280545883 25351   0x5555578ec0 INFO              GST_STATES gstbin.c:2506:gst_bin_element_set_state:<infer_queue> current READY pending VOID_PENDING, desired next PAUSED
0:00:13.280585519 25351   0x5555578ec0 INFO                    task gsttask.c:457:gst_task_set_lock: setting stream lock 0x55559fe1d0 on task 0x55559f33b0
0:00:13.280604373 25351   0x5555578ec0 INFO                GST_PADS gstpad.c:6154:gst_pad_start_task:<infer_queue:src> created task 0x55559f33b0
0:00:13.281486626 25351   0x5555578ec0 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<infer_queue> completed state change to PAUSED
0:00:13.281531991 25351   0x5555578ec0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<infer_queue> notifying about state-changed READY to PAUSED (VOID_PENDING pending)
0:00:13.281565586 25351   0x5555578ec0 INFO              GST_STATES gstbin.c:2954:gst_bin_change_state_func:<pipeline> child 'infer_queue' changed state to 3(PAUSED) successfully
0:00:13.281595326 25351   0x5555578ec0 INFO              GST_STATES gstbin.c:2506:gst_bin_element_set_state:<nvv4l2h265enc> current READY pending VOID_PENDING, desired next PAUSED
0:00:13.281632774 25351   0x5555578ec0 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<nvv4l2h265enc> completed state change to PAUSED
0:00:13.281652253 25351   0x5555578ec0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<nvv4l2h265enc> notifying about state-changed READY to PAUSED (VOID_PENDING pending)
0:00:13.281677879 25351   0x5555578ec0 INFO              GST_STATES gstbin.c:2954:gst_bin_change_state_func:<pipeline> child 'nvv4l2h265enc' changed state to 3(PAUSED) successfully
0:00:13.281702879 25351   0x5555578ec0 INFO              GST_STATES gstbin.c:2506:gst_bin_element_set_state:<enc_queue> current READY pending VOID_PENDING, desired next PAUSED
0:00:13.281741213 25351   0x5555578ec0 INFO                    task gsttask.c:457:gst_task_set_lock: setting stream lock 0x55559e4d20 on task 0x55559f34d0
0:00:13.281759130 25351   0x5555578ec0 INFO                GST_PADS gstpad.c:6154:gst_pad_start_task:<enc_queue:src> created task 0x55559f34d0
0:00:13.282422890 25351   0x5555578ec0 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<enc_queue> completed state change to PAUSED
0:00:13.282461693 25351   0x5555578ec0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<enc_queue> notifying about state-changed READY to PAUSED (VOID_PENDING pending)
0:00:13.282609820 25351   0x5555578ec0 INFO              GST_STATES gstbin.c:2954:gst_bin_change_state_func:<pipeline> child 'enc_queue' changed state to 3(PAUSED) successfully
0:00:13.282646956 25351   0x5555578ec0 INFO              GST_STATES gstbin.c:2506:gst_bin_element_set_state:<tee> current READY pending VOID_PENDING, desired next PAUSED
0:00:13.282684873 25351   0x5555578ec0 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<tee> completed state change to PAUSED
0:00:13.282708467 25351   0x5555578ec0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<tee> notifying about state-changed READY to PAUSED (VOID_PENDING pending)
0:00:13.282740968 25351   0x5555578ec0 INFO              GST_STATES gstbin.c:2954:gst_bin_change_state_func:<pipeline> child 'tee' changed state to 3(PAUSED) successfully
0:00:13.282772739 25351   0x5555578ec0 INFO              GST_STATES gstbin.c:2506:gst_bin_element_set_state:<capsfilter> current READY pending VOID_PENDING, desired next PAUSED
0:00:13.282807375 25351   0x5555578ec0 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<capsfilter> completed state change to PAUSED
0:00:13.282831386 25351   0x5555578ec0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<capsfilter> notifying about state-changed READY to PAUSED (VOID_PENDING pending)
0:00:13.282861230 25351   0x5555578ec0 INFO              GST_STATES gstbin.c:2954:gst_bin_change_state_func:<pipeline> child 'capsfilter' changed state to 3(PAUSED) successfully
0:00:13.282889251 25351   0x5555578ec0 INFO              GST_STATES gstbin.c:2506:gst_bin_element_set_state:<nvarguscamerasrc> current READY pending VOID_PENDING, desired next PAUSED
0:00:13.282942898 25351   0x5555578ec0 INFO                 basesrc gstbasesrc.c:1358:gst_base_src_do_seek:<nvarguscamerasrc> seeking: time segment start=0:00:00.000000000, offset=0:00:00.000000000, stop=99:99:99.999999999, rate=1.000000, applied_rate=1.000000, flags=0x00, time=0:00:00.000000000, base=0:00:00.000000000, position 0:00:00.000000000, duration 99:99:99.999999999
0:00:13.282994566 25351   0x5555578ec0 INFO                    task gsttask.c:457:gst_task_set_lock: setting stream lock 0x55559e4190 on task 0x55559f35f0
0:00:13.283014930 25351   0x5555578ec0 INFO                GST_PADS gstpad.c:6154:gst_pad_start_task:<nvarguscamerasrc:src> created task 0x55559f35f0
0:00:13.283750254 25351   0x5555578ec0 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<nvarguscamerasrc> completed state change to PAUSED
0:00:13.283785359 25351   0x5555578ec0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<nvarguscamerasrc> notifying about state-changed READY to PAUSED (VOID_PENDING pending)
0:00:13.283814734 25351   0x5555578ec0 INFO              GST_STATES gstbin.c:2997:gst_bin_change_state_func:<pipeline> child 'nvarguscamerasrc' changed state to 3(PAUSED) successfully without preroll
0:00:13.283827391 25351   0x55559df1e0 INFO        GST_ELEMENT_PADS gstelement.c:917:gst_element_get_static_pad: no such pad 'sink' in element "nvarguscamerasrc"
0:00:13.283850360 25351   0x5555578ec0 INFO              GST_STATES gstelement.c:2651:gst_element_continue_state:<pipeline> committing state from READY to PAUSED, pending PLAYING, next PLAYING
0:00:13.283866922 25351   0x5555578ec0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<pipeline> notifying about state-changed READY to PAUSED (PLAYING pending)
0:00:13.283868277 25351   0x55559df1e0 FIXME                default gstutils.c:3981:gst_pad_create_stream_id_internal:<nvarguscamerasrc:src> Creating random stream-id, consider implementing a deterministic way of creating a stream-id
0:00:13.283897808 25351   0x5555578ec0 INFO              GST_STATES gstelement.c:2658:gst_element_continue_state:<pipeline> continue state change PAUSED to PLAYING, final PLAYING
0:00:13.284110468 25351   0x5555578ec0 INFO               GST_EVENT gstevent.c:1388:gst_event_new_latency: creating latency event 0:00:00.000000000
0:00:13.284206198 25351   0x5555578ec0 INFO                     bin gstbin.c:2783:gst_bin_do_latency_func:<pipeline> configured latency of 0:00:00.000000000
0:00:13.284275991 25351   0x5555578ec0 INFO              GST_STATES gstbin.c:2506:gst_bin_element_set_state:<fakesink> current READY pending PAUSED, desired next PLAYING
0:00:13.284302971 25351   0x5555578ec0 INFO              GST_STATES gstbin.c:2960:gst_bin_change_state_func:<pipeline> child 'fakesink' is changing state asynchronously to PLAYING
0:00:13.284326669 25351   0x5555578ec0 INFO              GST_STATES gstbin.c:2506:gst_bin_element_set_state:<filesink> current READY pending PAUSED, desired next PLAYING
0:00:13.284343701 25351   0x5555578ec0 INFO              GST_STATES gstbin.c:2960:gst_bin_change_state_func:<pipeline> child 'filesink' is changing state asynchronously to PLAYING
0:00:13.284364899 25351   0x5555578ec0 INFO              GST_STATES gstbin.c:2506:gst_bin_element_set_state:<nvinfer> current PAUSED pending VOID_PENDING, desired next PLAYING
0:00:13.284384951 25351   0x5555578ec0 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<nvinfer> completed state change to PLAYING
0:00:13.284404483 25351   0x5555578ec0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<nvinfer> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)
0:00:13.284431566 25351   0x5555578ec0 INFO              GST_STATES gstbin.c:2954:gst_bin_change_state_func:<pipeline> child 'nvinfer' changed state to 4(PLAYING) successfully
0:00:13.284513339 25351   0x5555578ec0 INFO              GST_STATES gstbin.c:2506:gst_bin_element_set_state:<matroskamux> current PAUSED pending VOID_PENDING, desired next PLAYING
0:00:13.284538443 25351   0x5555578ec0 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<matroskamux> completed state change to PLAYING
0:00:13.284557245 25351   0x5555578ec0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<matroskamux> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)
0:00:13.284590475 25351   0x5555578ec0 INFO              GST_STATES gstbin.c:2954:gst_bin_change_state_func:<pipeline> child 'matroskamux' changed state to 4(PLAYING) successfully
0:00:13.284620996 25351   0x5555578ec0 INFO              GST_STATES gstbin.c:2506:gst_bin_element_set_state:<nvstreammux> current PAUSED pending VOID_PENDING, desired next PLAYING
0:00:13.284656518 25351   0x5555578ec0 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<nvstreammux> completed state change to PLAYING
0:00:13.284680893 25351   0x5555578ec0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<nvstreammux> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)
0:00:13.284712612 25351   0x5555578ec0 INFO              GST_STATES gstbin.c:2954:gst_bin_change_state_func:<pipeline> child 'nvstreammux' changed state to 4(PLAYING) successfully
0:00:13.284744592 25351   0x5555578ec0 INFO              GST_STATES gstbin.c:2506:gst_bin_element_set_state:<h265parse> current PAUSED pending VOID_PENDING, desired next PLAYING
0:00:13.284769592 25351   0x5555578ec0 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<h265parse> completed state change to PLAYING
0:00:13.284791207 25351   0x5555578ec0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<h265parse> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)
0:00:13.284822354 25351   0x5555578ec0 INFO              GST_STATES gstbin.c:2954:gst_bin_change_state_func:<pipeline> child 'h265parse' changed state to 4(PLAYING) successfully
0:00:13.284853865 25351   0x5555578ec0 INFO              GST_STATES gstbin.c:2506:gst_bin_element_set_state:<infer_queue> current PAUSED pending VOID_PENDING, desired next PLAYING
0:00:13.284877667 25351   0x5555578ec0 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<infer_queue> completed state change to PLAYING
0:00:13.284901209 25351   0x5555578ec0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<infer_queue> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)
0:00:13.284930845 25351   0x5555578ec0 INFO              GST_STATES gstbin.c:2954:gst_bin_change_state_func:<pipeline> child 'infer_queue' changed state to 4(PLAYING) successfully
0:00:13.284961575 25351   0x5555578ec0 INFO              GST_STATES gstbin.c:2506:gst_bin_element_set_state:<nvv4l2h265enc> current PAUSED pending VOID_PENDING, desired next PLAYING
0:00:13.284987148 25351   0x5555578ec0 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<nvv4l2h265enc> completed state change to PLAYING
0:00:13.285008815 25351   0x5555578ec0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<nvv4l2h265enc> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)
0:00:13.285035013 25351   0x5555578ec0 INFO              GST_STATES gstbin.c:2954:gst_bin_change_state_func:<pipeline> child 'nvv4l2h265enc' changed state to 4(PLAYING) successfully
0:00:13.285061576 25351   0x5555578ec0 INFO              GST_STATES gstbin.c:2506:gst_bin_element_set_state:<enc_queue> current PAUSED pending VOID_PENDING, desired next PLAYING
0:00:13.285080951 25351   0x5555578ec0 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<enc_queue> completed state change to PLAYING
0:00:13.285098868 25351   0x5555578ec0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<enc_queue> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)
0:00:13.285123400 25351   0x5555578ec0 INFO              GST_STATES gstbin.c:2954:gst_bin_change_state_func:<pipeline> child 'enc_queue' changed state to 4(PLAYING) successfully
0:00:13.285147775 25351   0x5555578ec0 INFO              GST_STATES gstbin.c:2506:gst_bin_element_set_state:<tee> current PAUSED pending VOID_PENDING, desired next PLAYING
0:00:13.285165744 25351   0x5555578ec0 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<tee> completed state change to PLAYING
0:00:13.285182984 25351   0x5555578ec0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<tee> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)
0:00:13.285251579 25351   0x5555578ec0 INFO              GST_STATES gstbin.c:2954:gst_bin_change_state_func:<pipeline> child 'tee' changed state to 4(PLAYING) successfully
0:00:13.285304913 25351   0x5555578ec0 INFO              GST_STATES gstbin.c:2506:gst_bin_element_set_state:<capsfilter> current PAUSED pending VOID_PENDING, desired next PLAYING
0:00:13.285329028 25351   0x5555578ec0 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<capsfilter> completed state change to PLAYING
0:00:13.285348403 25351   0x5555578ec0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<capsfilter> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)
0:00:13.285374914 25351   0x5555578ec0 INFO              GST_STATES gstbin.c:2954:gst_bin_change_state_func:<pipeline> child 'capsfilter' changed state to 4(PLAYING) successfully
0:00:13.285401842 25351   0x5555578ec0 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<nvarguscamerasrc> completed state change to PLAYING
0:00:13.285421894 25351   0x5555578ec0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<nvarguscamerasrc> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)
0:00:13.285451894 25351   0x5555578ec0 INFO              GST_STATES gstbin.c:2954:gst_bin_change_state_func:<pipeline> child 'nvarguscamerasrc' changed state to 4(PLAYING) successfully
0:00:13.291753917 25351   0x55559df1e0 INFO               GST_EVENT gstevent.c:814:gst_event_new_caps: creating caps event video/x-raw(memory:NVMM), width=(int)1920, height=(int)1080, format=(string)NV12, framerate=(fraction)30/1
0:00:13.292072411 25351   0x55559df1e0 INFO           basetransform gstbasetransform.c:1308:gst_base_transform_setcaps:<capsfilter> reuse caps
0:00:13.292124756 25351   0x55559df1e0 INFO               GST_EVENT gstevent.c:814:gst_event_new_caps: creating caps event video/x-raw(memory:NVMM), width=(int)1920, height=(int)1080, format=(string)NV12, framerate=(fraction)30/1
0:00:13.292650962 25351   0x5555cc3850 INFO               GST_EVENT gstevent.c:814:gst_event_new_caps: creating caps event video/x-raw(memory:NVMM), width=(int)384, height=(int)216, format=(string)NV12, framerate=(fraction)30/1, batch-size=(int)1, num-surfaces-per-frame=(int)1
0:00:13.292755807 25351   0x5555cc3b70 INFO               GST_EVENT gstevent.c:814:gst_event_new_caps: creating caps event video/x-h265, stream-format=(string)byte-stream, alignment=(string)au, profile=(string)NULL, width=(int)1920, height=(int)1080, pixel-aspect-ratio=(fraction)1/1, framerate=(fraction)30/1, interlace-mode=(string)progressive, colorimetry=(string)bt709, chroma-site=(string)mpeg2
0:00:13.292834038 25351   0x5555cc3850 INFO           basetransform gstbasetransform.c:1308:gst_base_transform_setcaps:<nvinfer> reuse caps
0:00:13.292875965 25351   0x5555cc3850 INFO               GST_EVENT gstevent.c:814:gst_event_new_caps: creating caps event video/x-raw(memory:NVMM), width=(int)384, height=(int)216, format=(string)NV12, framerate=(fraction)30/1, batch-size=(int)1, num-surfaces-per-frame=(int)1
0:00:13.292909508 25351   0x5555cc3b70 INFO                    v4l2 gstv4l2object.c:3146:gst_v4l2_object_setup_pool:<nvv4l2h265enc:src> accessing buffers via mode 2
0:00:13.293189356 25351   0x5555cc3b70 INFO          v4l2bufferpool gstv4l2bufferpool.c:814:gst_v4l2_buffer_pool_set_config:<nvv4l2h265enc:pool:src> increasing minimum buffers to 2
0:00:13.293228627 25351   0x5555cc3b70 INFO          v4l2bufferpool gstv4l2bufferpool.c:827:gst_v4l2_buffer_pool_set_config:<nvv4l2h265enc:pool:src> reducing maximum buffers to 32
0:00:13.293257950 25351   0x5555cc3b70 INFO          v4l2bufferpool gstv4l2bufferpool.c:838:gst_v4l2_buffer_pool_set_config:<nvv4l2h265enc:pool:src> can't allocate, setting maximum to minimum
0:00:13.293278524 25351   0x5555cc3850 INFO                    task gsttask.c:457:gst_task_set_lock: setting stream lock 0x55559fe420 on task 0x7f44007290
0:00:13.293296649 25351   0x5555cc3850 INFO                GST_PADS gstpad.c:6154:gst_pad_start_task:<nvstreammux:src> created task 0x7f44007290
0:00:13.293377535 25351   0x5555cc3b70 INFO          v4l2bufferpool gstv4l2bufferpool.c:827:gst_v4l2_buffer_pool_set_config:<nvv4l2h265enc:pool:src> reducing maximum buffers to 32
0:00:13.293394098 25351   0x5555cc3b70 INFO          v4l2bufferpool gstv4l2bufferpool.c:838:gst_v4l2_buffer_pool_set_config:<nvv4l2h265enc:pool:src> can't allocate, setting maximum to minimum
NvMMLiteOpen : Block : BlockType = 8 
===== NVMEDIA: NVENC =====
0:00:13.295272304 25351   0x5555cc3850 INFO             nvstreammux gstnvstreammux.c:983:gst_nvstreammux_sink_event:<nvstreammux> Conversion enabled for source 0
NvMMLiteBlockCreate : Block : BlockType = 8 
0:00:13.296127421 25351   0x5555cc3b70 INFO                    v4l2 gstv4l2object.c:3973:gst_v4l2_object_set_format_full:<nvv4l2h265enc:sink> Set output framerate to 30/1
0:00:13.296164401 25351   0x5555cc3b70 INFO                    v4l2 gstv4l2object.c:3146:gst_v4l2_object_setup_pool:<nvv4l2h265enc:sink> accessing buffers via mode 5
0:00:13.296313361 25351   0x5555cc3b70 INFO          v4l2bufferpool gstv4l2bufferpool.c:814:gst_v4l2_buffer_pool_set_config:<nvv4l2h265enc:pool:sink> increasing minimum buffers to 2
0:00:13.296338935 25351   0x5555cc3b70 INFO          v4l2bufferpool gstv4l2bufferpool.c:821:gst_v4l2_buffer_pool_set_config:<nvv4l2h265enc:pool:sink> increasing minimum buffers to 4
0:00:13.296352372 25351   0x5555cc3b70 INFO          v4l2bufferpool gstv4l2bufferpool.c:827:gst_v4l2_buffer_pool_set_config:<nvv4l2h265enc:pool:sink> reducing maximum buffers to 32
0:00:13.296363622 25351   0x5555cc3b70 INFO          v4l2bufferpool gstv4l2bufferpool.c:838:gst_v4l2_buffer_pool_set_config:<nvv4l2h265enc:pool:sink> can't allocate, setting maximum to minimum
0:00:13.296374352 25351   0x5555cc3b70 INFO          v4l2bufferpool gstv4l2bufferpool.c:843:gst_v4l2_buffer_pool_set_config:<nvv4l2h265enc:pool:sink> adding needed video meta
0:00:13.298116982 25351   0x7f4c0018f0 INFO               GST_EVENT gstevent.c:895:gst_event_new_segment: creating segment event time segment start=0:00:00.000000000, offset=0:00:00.000000000, stop=99:99:99.999999999, rate=1.000000, applied_rate=1.000000, flags=0x00, time=0:00:00.000000000, base=0:00:00.000000000, position 0:00:00.000000000, duration 99:99:99.999999999
0:00:13.314126808 25351   0x5555cc3b70 WARN          v4l2bufferpool gstv4l2bufferpool.c:1054:gst_v4l2_buffer_pool_start:<nvv4l2h265enc:pool:src> Uncertain or not enough buffers, enabling copy threshold
0:00:14.221563275 25351   0x55559df1e0 INFO               GST_EVENT gstevent.c:895:gst_event_new_segment: creating segment event time segment start=0:00:00.000000000, offset=0:00:00.000000000, stop=99:99:99.999999999, rate=1.000000, applied_rate=1.000000, flags=0x00, time=0:00:00.000000000, base=0:00:00.000000000, position 0:00:00.000000000, duration 99:99:99.999999999
0:00:14.221681819 25351   0x55559df1e0 INFO                 basesrc gstbasesrc.c:2945:gst_base_src_loop:<nvarguscamerasrc> marking pending DISCONT
0:00:14.221803279 25351   0x5555cc3850 WARN             nvstreammux gstnvstreammux.c:308:gst_nvstreammux_chain:<nvstreammux> error: Input buffer number of surfaces (0) must be equal to mux->num_surfaces_per_frame (1)
	Set nvstreammux property num-surfaces-per-frame appropriately

0:00:14.221846665 25351   0x5555cc3850 INFO        GST_ERROR_SYSTEM gstelement.c:2145:gst_element_message_full_with_details:<nvstreammux> posting message: Input buffer number of surfaces (0) must be equal to mux->num_surfaces_per_frame (1)
	Set nvstreammux property num-surfaces-per-frame appropriately

0:00:14.221945104 25351   0x5555cc3850 INFO        GST_ERROR_SYSTEM gstelement.c:2172:gst_element_message_full_with_details:<nvstreammux> posted error message: Input buffer number of surfaces (0) must be equal to mux->num_surfaces_per_frame (1)
	Set nvstreammux property num-surfaces-per-frame appropriately

0:00:14.221975782 25351   0x5555cc3850 INFO                    task gsttask.c:316:gst_task_func:<infer_queue:src> Task going to paused
0:00:14.222029324 25351   0x5555cc3b70 INFO                    task gsttask.c:457:gst_task_set_lock: setting stream lock 0x55559e51c0 on task 0x7f44007710
0:00:14.222053283 25351   0x5555cc3b70 INFO                GST_PADS gstpad.c:6154:gst_pad_start_task:<nvv4l2h265enc:src> created task 0x7f44007710
Opening in BLOCKING MODE 
Opening in BLOCKING MODE 
BUS_DEBUG: fakesink: state-changed
BUS_DEBUG: filesink: state-changed
BUS_DEBUG: nvinfer: state-changed
BUS_DEBUG: matroskamux: state-changed
BUS_DEBUG: nvstreammux: state-changed
BUS_DEBUG: h265parse: state-changed
BUS_DEBUG: infer_queue: state-changed
BUS_DEBUG: nvv4l2h265enc: state-changed
BUS_DEBUG: enc_queue: state-changed
BUS_DEBUG: tee: state-changed
BUS_DEBUG: capsfilter: state-changed
BUS_DEBUG: nvarguscamerasrc: state-changed
BUS_DEBUG: pipeline: state-changed
BUS_DEBUG: nvinfer: state-changed
BUS_DEBUG: matroskamux: state-changed
BUS_DEBUG: nvstreammux: state-changed
BUS_DEBUG: h265parse: state-changed
BUS_DEBUG: src: stream-status
BUS_DEBUG: infer_queue: state-changed
BUS_DEBUG: src: stream-status
BUS_DEBUG: nvv4l2h265enc: state-changed
BUS_DEBUG: src: stream-status
BUS_DEBUG: enc_queue: state-changed
BUS_DEBUG: src: stream-status
BUS_DEBUG: tee: state-changed
BUS_DEBUG: capsfilter: state-changed
BUS_DEBUG: src: stream-status
BUS_DEBUG: nvarguscamerasrc: state-changed
BUS_DEBUG: src: stream-status
BUS_DEBUG: pipeline: state-changed
BUS_DEBUG: pipeline: new-clock
BUS_DEBUG: nvinfer: state-changed
BUS_DEBUG: matroskamux: state-changed
BUS_DEBUG: nvstreammux: state-changed
BUS_DEBUG: h265parse: state-changed
BUS_DEBUG: infer_queue: state-changed
BUS_DEBUG: nvv4l2h265enc: state-changed
BUS_DEBUG: enc_queue: state-changed
BUS_DEBUG: tee: state-changed
BUS_DEBUG: capsfilter: state-changed
BUS_DEBUG: nvarguscamerasrc: state-changed
BUS_DEBUG: src: stream-status
BUS_DEBUG: nvv4l2h265enc: latency
BUS_DEBUG: src: stream-status
GST_ARGUS: Creating output stream
CONSUMER: Waiting until producer is connected...
GST_ARGUS: Available Sensor modes :
GST_ARGUS: 3264 x 2464 FR = 21.000000 fps Duration = 47619048 ; Analog Gain range min 1.000000, max 10.625000; Exposure Range min 13000, max 683709000;

GST_ARGUS: 3264 x 1848 FR = 28.000001 fps Duration = 35714284 ; Analog Gain range min 1.000000, max 10.625000; Exposure Range min 13000, max 683709000;

GST_ARGUS: 1920 x 1080 FR = 29.999999 fps Duration = 33333334 ; Analog Gain range min 1.000000, max 10.625000; Exposure Range min 13000, max 683709000;

GST_ARGUS: 1280 x 720 FR = 59.999999 fps Duration = 16666667 ; Analog Gain range min 1.000000, max 10.625000; Exposure Range min 13000, max 683709000;

GST_ARGUS: 1280 x 720 FR = 120.000005 fps Duration = 8333333 ; Analog Gain range min 1.000000, max 10.625000; Exposure Range min 13000, max 683709000;

0:00:14.222140055 25351   0x5555578ec0 INFO              GST_STATES gstbin.c:2506:gst_bin_element_set_state:<fakesink> current READY pending PAUSED, desired next READY
0:00:14.222384902 25351   0x5555578ec0 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<fakesink> completed state change to READY
0:00:14.222420215 25351   0x5555578ec0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<fakesink> notifying about state-changed READY to READY (VOID_PENDING pending)
0:00:14.222447455 25351   0x5555578ec0 INFO              GST_STATES gstbin.c:2954:gst_bin_change_state_func:<pipeline> child 'fakesink' changed state to 2(READY) successfully
0:00:14.222473758 25351   0x5555578ec0 INFO              GST_STATES gstbin.c:2506:gst_bin_element_set_state:<filesink> current READY pending PAUSED, desired next READY
0:00:14.222514279 25351   0x5555578ec0 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<filesink> completed state change to READY
0:00:14.222531780 25351   0x5555578ec0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<filesink> notifying about state-changed READY to READY (VOID_PENDING pending)
GST_ARGUS: Running with following settings:
   Camera index = 0 
   Camera mode  = 2 
   Output Stream W = 1920 H = 1080 
   seconds to Run    = 0 
   Frame Rate = 29.999999 
GST_ARGUS: PowerService: requested_clock_Hz=627200000
GST_ARGUS: Setup Complete, Starting captures for 0 seconds
GST_ARGUS: Starting repeat capture requests.
CONSUMER: Producer has connected; continuing.
** ERROR: <on_bus_message:18>: Error received from nvstreammux: Input buffer number of surfaces (0) must be equal to mux->num_surfaces_per_frame (1)
	Set nvstreammux property num-surfaces-per-frame appropriately

0:00:14.222564020 25351   0x5555578ec0 INFO              GST_STATES gstbin.c:2954:gst_bin_change_state_func:<pipeline> child 'filesink' changed state to 2(READY) successfully
0:00:14.222586468 25351   0x5555578ec0 INFO              GST_STATES gstbin.c:2506:gst_bin_element_set_state:<nvinfer> current PLAYING pending VOID_PENDING, desired next READY
0:00:14.222611468 25351   0x5555578ec0 INFO              GST_STATES gstelement.c:2651:gst_element_continue_state:<nvinfer> committing state from PLAYING to PAUSED, pending READY, next READY
0:00:14.222627614 25351   0x5555578ec0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<nvinfer> notifying about state-changed PLAYING to PAUSED (READY pending)
0:00:14.222651886 25351   0x5555578ec0 INFO              GST_STATES gstelement.c:2658:gst_element_continue_state:<nvinfer> continue state change PAUSED to READY, final READY
0:00:14.228292284 25351   0x5555578ec0 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<nvinfer> completed state change to READY
0:00:14.228441713 25351   0x5555578ec0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<nvinfer> notifying about state-changed PAUSED to READY (VOID_PENDING pending)
0:00:14.228522652 25351   0x5555578ec0 INFO              GST_STATES gstbin.c:2954:gst_bin_change_state_func:<pipeline> child 'nvinfer' changed state to 2(READY) successfully
0:00:14.228586767 25351   0x5555578ec0 INFO              GST_STATES gstbin.c:2506:gst_bin_element_set_state:<matroskamux> current PLAYING pending VOID_PENDING, desired next READY
0:00:14.228653435 25351   0x5555578ec0 INFO              GST_STATES gstelement.c:2651:gst_element_continue_state:<matroskamux> committing state from PLAYING to PAUSED, pending READY, next READY
0:00:14.228759062 25351   0x5555578ec0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<matroskamux> notifying about state-changed PLAYING to PAUSED (READY pending)
0:00:14.228852136 25351   0x5555578ec0 INFO              GST_STATES gstelement.c:2658:gst_element_continue_state:<matroskamux> continue state change PAUSED to READY, final READY
0:00:14.228976148 25351   0x5555578ec0 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<matroskamux> completed state change to READY
0:00:14.229006565 25351   0x5555578ec0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<matroskamux> notifying about state-changed PAUSED to READY (VOID_PENDING pending)
0:00:14.229049795 25351   0x5555578ec0 INFO              GST_STATES gstbin.c:2954:gst_bin_change_state_func:<pipeline> child 'matroskamux' changed state to 2(READY) successfully
0:00:14.229097765 25351   0x5555578ec0 INFO              GST_STATES gstbin.c:2506:gst_bin_element_set_state:<nvstreammux> current PLAYING pending VOID_PENDING, desired next READY
0:00:14.229148442 25351   0x5555578ec0 INFO              GST_STATES gstelement.c:2651:gst_element_continue_state:<nvstreammux> committing state from PLAYING to PAUSED, pending READY, next READY
0:00:14.229171099 25351   0x5555578ec0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<nvstreammux> notifying about state-changed PLAYING to PAUSED (READY pending)
0:00:14.229251934 25351   0x5555578ec0 INFO              GST_STATES gstelement.c:2658:gst_element_continue_state:<nvstreammux> continue state change PAUSED to READY, final READY
Signal: SIGSEGV (Segmentation fault)

mdegans · August 21, 2019, 7:42pm

Pipeline creation code:

CLion variables tab:

CLion gdb tab:

So I’m guessing the camera is the issue, but I can’t see what’s wrong. My C is kind of basic (haven’t done it seriously since college) so I could be making a beginner mistake. Hopefully that’s the case and somebody can come across and correct me.

DaneLLL · August 22, 2019, 2:38am

Hi,
We have samples in deepstream_sdk_v4.0_jetson/sources/apps/sample_apps/
Could you check which sample is close to your usecase, and share a patch so that we can apply the patch, re-build and run the sample to reproduce the issue? It is not clear from the log and we would like to reproduce it for further checking.

mdegans · August 22, 2019, 11:26pm

Thanks for the suggestion. The main issue is that I wrote this mostly before DeepStream 4 was released, based on the DeepStream 3 plugin manual and no sample code. As such the app didn’t start from one of your examples and adapting it might be hard as I can’t find an example from NVIDIA quite like mine.

None have an encoder in one branch and inference in another. Most rely on decoding data from IP cameras. However, I’ve taken a look at your examples and ~~I think the problem may be related to how I am linking from my tee to my queues.~~ edit: nope

My pipeline link function is here:

gboolean link_pipeline(PipelineData* p_data) {
#ifdef IS_TEGRA
  // link pipeline beginning
  if (!gst_element_link_many(p_data->camera, p_data->capsfilter, p_data->tee,
                             NULL)) {
    // "Could not link pipeline %s."
    GST_ERROR(ERR_LINK, "beginning");
    return FALSE;
  }
#else  // X86
  // link: camera, converter, capsfilter, tee
#endif
  // link and connect encoder branch
  if (!gst_element_link_many(p_data->enc_queue, p_data->encoder, p_data->parser,
                             p_data->muxer, p_data->filesink, NULL)) {
    GST_ERROR(ERR_LINK, "encoder branch");
    return FALSE;
  }[

  // link and connect inference branch
  if (!gst_element_link_pads(p_data->infer_queue, "src", p_data->streammux,
                             "sink_0")) {
    GST_ERROR(ERR_LINK, "inference queue and stream muxer");
    return FALSE;
  }
  if (!gst_element_link_many(p_data->streammux, p_data->infer, p_data->fakesink,
                             NULL)) {
    GST_ERROR(ERR_LINK, "inference branch");
    return FALSE;
  }

[b]  // link the branches to the tee
  if (!gst_element_link(p_data->tee, p_data->enc_queue)) {
    GST_ERROR(ERR_LINK, "tee and encoder queue");
  }
  if (!gst_element_link(p_data->tee, p_data->infer_queue)) {
    GST_ERROR(ERR_LINK, "tee and inference queue");
  }[/b]

return TRUE;
}

There I’m just using gst_element_link to connect my tee to the two queues. The way you do it in deepstream_test4_app is by getting the pads and connecting them manually. I’m going to try doing it that way and see if that fixes it. The log and graph seems to indicate the pads are being created by and connected anyway, but it’s worth a shot. If It doesn’t fix it, i’ll revert the changes and post my code to GitHub.

sink_pad = gst_element_get_static_pad (queue1, "sink");
  tee_msg_pad = gst_element_get_request_pad (tee, "src_%u");
  tee_render_pad = gst_element_get_request_pad (tee, "src_%u");
  if (!tee_msg_pad || !tee_render_pad) {
    g_printerr ("Unable to get request pads\n");
    return -1;
  }

  if (gst_pad_link (tee_msg_pad, sink_pad) != GST_PAD_LINK_OK) {
    g_printerr ("Unable to link tee and message converter\n");
    gst_object_unref (sink_pad);
    return -1;
  }

  gst_object_unref (sink_pad);

  sink_pad = gst_element_get_static_pad (queue2, "sink");
  if (gst_pad_link (tee_render_pad, sink_pad) != GST_PAD_LINK_OK) {
    g_printerr ("Unable to link tee and render\n");
    gst_object_unref (sink_pad);
    return -1;
  }

  gst_object_unref (sink_pad);

Edit:
Hmm. It wasn’t how it’s linked. Same exact result. I may end up starting from one of your example, but before I do i’m going to polish this up a bit and put it on GitHub.

mdegans · August 23, 2019, 1:49am

So I committed my code in it’s current state here:

It should build and run with no problems, provided cmake and DS4 are installed.

I don’t expect any help (I will eventually figure it out), but any that’s offered is very much welcome.

mdegans · August 23, 2019, 2:28am

hmm. So I guess I should have tested the camera. I am not sure there’s actually anything wrong with my code:

/tmp/tmp.NfPN6bG6K8/cmake-build-debug-remote-nano/samples/oneShot/argus_oneshot
Executing Argus Sample: argus_oneshot
Argus Version: 0.97.3 (multi-process)
Capturing from device 0 using sensor mode 0 (3264x2464)
Failed to create capture session

It seems the buffers aren’t coming downstream for the simplest reason possible. The camera isn’t sending them.

Damn. ~~And that’s a brand new IMX219 based module.~~ Edit: it’s never so simple. see below.

mdegans · August 23, 2019, 2:37am

Ok. So this is strange. I rebooted the nano and it works.

/tmp/tmp.NfPN6bG6K8/generation_path/samples/oneShot/argus_oneshot
Executing Argus Sample: argus_oneshot
Argus Version: 0.97.3 (multi-process)
Capturing from device 0 using sensor mode 0 (3264x2464)
Wrote file: argus_oneShot.jpg

It appears my code breaks Argus. Or something :/

Yup. It breaks it reliably. I run the oneshot test, it works. I run the birbcam, it breaks. I run oneshot again, it’s broken. I restart the daemon with “sudo systemctl restart nvargus-daemon” and it works again. Not a clue why. Going to familiarize myself with the Argus api.