Opening in BLOCKING MODE
0:00:00.176261048 9259 0xaaaade61f400 INFO v4l2 v4l2_calls.c:679:gst_v4l2_open:<main_sony_mp4_enc1:sink> Opened device '' (/dev/v4l2-nvenc) successfully
0:00:00.176302937 9259 0xaaaade61f400 INFO v4l2 v4l2_calls.c:780:gst_v4l2_dup:<main_sony_mp4_enc1:src> Cloned device '' (/dev/v4l2-nvenc) successfully
0:00:00.177084945 9259 0xaaaade61f400 INFO v4l2 gstv4l2object.c:1302:gst_v4l2_object_fill_format_list:<main_sony_mp4_enc1:sink> got 6 format(s):
0:00:00.177108466 9259 0xaaaade61f400 INFO v4l2 gstv4l2object.c:1306:gst_v4l2_object_fill_format_list:<main_sony_mp4_enc1:sink> YM12
0:00:00.177122898 9259 0xaaaade61f400 INFO v4l2 gstv4l2object.c:1306:gst_v4l2_object_fill_format_list:<main_sony_mp4_enc1:sink> PM10
0:00:00.177134386 9259 0xaaaade61f400 INFO v4l2 gstv4l2object.c:1306:gst_v4l2_object_fill_format_list:<main_sony_mp4_enc1:sink> NM24
0:00:00.177145587 9259 0xaaaade61f400 INFO v4l2 gstv4l2object.c:1306:gst_v4l2_object_fill_format_list:<main_sony_mp4_enc1:sink> NM12
0:00:00.177155859 9259 0xaaaade61f400 INFO v4l2 gstv4l2object.c:1306:gst_v4l2_object_fill_format_list:<main_sony_mp4_enc1:sink> NV10
0:00:00.177164307 9259 0xaaaade61f400 INFO v4l2 gstv4l2object.c:1306:gst_v4l2_object_fill_format_list:<main_sony_mp4_enc1:sink> YM24
0:00:00.177293527 9259 0xaaaade61f400 INFO v4l2 gstv4l2object.c:4692:gst_v4l2_object_probe_caps:<main_sony_mp4_enc1: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)NV24, 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:00.177319576 9259 0xaaaade61f400 INFO v4l2 gstv4l2object.c:1302:gst_v4l2_object_fill_format_list:<main_sony_mp4_enc1:src> got 3 format(s):
0:00:00.177333400 9259 0xaaaade61f400 INFO v4l2 gstv4l2object.c:1306:gst_v4l2_object_fill_format_list:<main_sony_mp4_enc1:src> AV10
0:00:00.177344857 9259 0xaaaade61f400 INFO v4l2 gstv4l2object.c:1306:gst_v4l2_object_fill_format_list:<main_sony_mp4_enc1:src> H265
0:00:00.177354265 9259 0xaaaade61f400 INFO v4l2 gstv4l2object.c:1306:gst_v4l2_object_fill_format_list:<main_sony_mp4_enc1:src> H264
0:00:00.177399674 9259 0xaaaade61f400 WARN v4l2 gstv4l2object.c:4634:gst_v4l2_object_probe_caps:<main_sony_mp4_enc1:src> Failed to probe pixel aspect ratio with VIDIOC_CROPCAP: Unknown error -1
0:00:00.177453052 9259 0xaaaade61f400 INFO v4l2 gstv4l2object.c:4692:gst_v4l2_object_probe_caps:<main_sony_mp4_enc1:src> probed caps: video/x-h264, stream-format=(string)byte-stream, alignment=(string)au, width=(int)[ 48, 4096 ], height=(int)[ 48, 4096 ], framerate=(fraction)[ 0/1, 2147483647/1 ]
0:00:00.177476285 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2806:gst_element_continue_state:<main_sony_mp4_enc1> completed state change to READY
0:00:00.177492989 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2706:_priv_gst_element_state_changed:<main_sony_mp4_enc1> notifying about state-changed NULL to READY (VOID_PENDING pending)
0:00:00.177531870 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2928:gst_bin_change_state_func:<main_pipe1> child 'main_sony_mp4_enc1' changed state to 2(READY) successfully
0:00:00.177562879 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2479:gst_bin_element_set_state:<main_enc1> current NULL pending VOID_PENDING, desired next READY
Opening in BLOCKING MODE
0:00:00.213668894 9259 0xaaaade61f400 INFO v4l2 v4l2_calls.c:679:gst_v4l2_open:<main_enc1:sink> Opened device '' (/dev/v4l2-nvenc) successfully
0:00:00.213708863 9259 0xaaaade61f400 INFO v4l2 v4l2_calls.c:780:gst_v4l2_dup:<main_enc1:src> Cloned device '' (/dev/v4l2-nvenc) successfully
0:00:00.213741696 9259 0xaaaade61f400 INFO v4l2 gstv4l2object.c:1302:gst_v4l2_object_fill_format_list:<main_enc1:sink> got 6 format(s):
0:00:00.213762592 9259 0xaaaade61f400 INFO v4l2 gstv4l2object.c:1306:gst_v4l2_object_fill_format_list:<main_enc1:sink> YM12
0:00:00.213774561 9259 0xaaaade61f400 INFO v4l2 gstv4l2object.c:1306:gst_v4l2_object_fill_format_list:<main_enc1:sink> PM10
0:00:00.213784257 9259 0xaaaade61f400 INFO v4l2 gstv4l2object.c:1306:gst_v4l2_object_fill_format_list:<main_enc1:sink> NM24
0:00:00.213793601 9259 0xaaaade61f400 INFO v4l2 gstv4l2object.c:1306:gst_v4l2_object_fill_format_list:<main_enc1:sink> NM12
0:00:00.213802882 9259 0xaaaade61f400 INFO v4l2 gstv4l2object.c:1306:gst_v4l2_object_fill_format_list:<main_enc1:sink> NV10
0:00:00.213812258 9259 0xaaaade61f400 INFO v4l2 gstv4l2object.c:1306:gst_v4l2_object_fill_format_list:<main_enc1:sink> YM24
0:00:00.213979175 9259 0xaaaade61f400 INFO v4l2 gstv4l2object.c:4692:gst_v4l2_object_probe_caps:<main_enc1: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)NV24, 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:00.214005960 9259 0xaaaade61f400 INFO v4l2 gstv4l2object.c:1302:gst_v4l2_object_fill_format_list:<main_enc1:src> got 3 format(s):
0:00:00.214019304 9259 0xaaaade61f400 INFO v4l2 gstv4l2object.c:1306:gst_v4l2_object_fill_format_list:<main_enc1:src> AV10
0:00:00.214030857 9259 0xaaaade61f400 INFO v4l2 gstv4l2object.c:1306:gst_v4l2_object_fill_format_list:<main_enc1:src> H265
0:00:00.214040937 9259 0xaaaade61f400 INFO v4l2 gstv4l2object.c:1306:gst_v4l2_object_fill_format_list:<main_enc1:src> H264
0:00:00.214053641 9259 0xaaaade61f400 WARN v4l2 gstv4l2object.c:4634:gst_v4l2_object_probe_caps:<main_enc1:src> Failed to probe pixel aspect ratio with VIDIOC_CROPCAP: Unknown error -1
0:00:00.214101803 9259 0xaaaade61f400 INFO v4l2 gstv4l2object.c:4692:gst_v4l2_object_probe_caps:<main_enc1:src> probed caps: video/x-h264, stream-format=(string)byte-stream, alignment=(string)au, width=(int)[ 48, 4096 ], height=(int)[ 48, 4096 ], framerate=(fraction)[ 0/1, 2147483647/1 ]
0:00:00.214124555 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2806:gst_element_continue_state:<main_enc1> completed state change to READY
0:00:00.214140364 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2706:_priv_gst_element_state_changed:<main_enc1> notifying about state-changed NULL to READY (VOID_PENDING pending)
0:00:00.214181581 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2928:gst_bin_change_state_func:<main_pipe1> child 'main_enc1' changed state to 2(READY) successfully
0:00:00.214213550 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2479:gst_bin_element_set_state:<main_sony_mp4_caps1> current NULL pending VOID_PENDING, desired next READY
0:00:00.214230735 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2806:gst_element_continue_state:<main_sony_mp4_caps1> completed state change to READY
0:00:00.214241999 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2706:_priv_gst_element_state_changed:<main_sony_mp4_caps1> notifying about state-changed NULL to READY (VOID_PENDING pending)
0:00:00.214257295 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2928:gst_bin_change_state_func:<main_pipe1> child 'main_sony_mp4_caps1' changed state to 2(READY) successfully
0:00:00.214273360 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2479:gst_bin_element_set_state:<main_caps6> current NULL pending VOID_PENDING, desired next READY
0:00:00.214285136 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2806:gst_element_continue_state:<main_caps6> completed state change to READY
0:00:00.214295217 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2706:_priv_gst_element_state_changed:<main_caps6> notifying about state-changed NULL to READY (VOID_PENDING pending)
0:00:00.214308145 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2928:gst_bin_change_state_func:<main_pipe1> child 'main_caps6' changed state to 2(READY) successfully
0:00:00.214326513 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2479:gst_bin_element_set_state:<main_sony_mp4_conv1> current NULL pending VOID_PENDING, desired next READY
0:00:00.214342098 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2806:gst_element_continue_state:<main_sony_mp4_conv1> completed state change to READY
0:00:00.214353138 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2706:_priv_gst_element_state_changed:<main_sony_mp4_conv1> notifying about state-changed NULL to READY (VOID_PENDING pending)
0:00:00.214367699 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2928:gst_bin_change_state_func:<main_pipe1> child 'main_sony_mp4_conv1' changed state to 2(READY) successfully
0:00:00.214381331 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2479:gst_bin_element_set_state:<main_conv3> current NULL pending VOID_PENDING, desired next READY
0:00:00.214392243 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2806:gst_element_continue_state:<main_conv3> completed state change to READY
0:00:00.214402420 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2706:_priv_gst_element_state_changed:<main_conv3> notifying about state-changed NULL to READY (VOID_PENDING pending)
0:00:00.214415892 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2928:gst_bin_change_state_func:<main_pipe1> child 'main_conv3' changed state to 2(READY) successfully
0:00:00.214433909 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2479:gst_bin_element_set_state:<main_sony_mp4_caps2> current NULL pending VOID_PENDING, desired next READY
0:00:00.214444917 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2806:gst_element_continue_state:<main_sony_mp4_caps2> completed state change to READY
0:00:00.214455317 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2706:_priv_gst_element_state_changed:<main_sony_mp4_caps2> notifying about state-changed NULL to READY (VOID_PENDING pending)
0:00:00.214468278 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2928:gst_bin_change_state_func:<main_pipe1> child 'main_sony_mp4_caps2' changed state to 2(READY) successfully
0:00:00.214483414 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2479:gst_bin_element_set_state:<main_caps5> current NULL pending VOID_PENDING, desired next READY
0:00:00.214517303 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2806:gst_element_continue_state:<main_caps5> completed state change to READY
0:00:00.214528248 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2706:_priv_gst_element_state_changed:<main_caps5> notifying about state-changed NULL to READY (VOID_PENDING pending)
0:00:00.214542488 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2928:gst_bin_change_state_func:<main_pipe1> child 'main_caps5' changed state to 2(READY) successfully
0:00:00.214560280 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2479:gst_bin_element_set_state:<main_compositor1> current NULL pending VOID_PENDING, desired next READY
0:00:00.214573657 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2806:gst_element_continue_state:<main_compositor1> completed state change to READY
0:00:00.214583801 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2706:_priv_gst_element_state_changed:<main_compositor1> notifying about state-changed NULL to READY (VOID_PENDING pending)
0:00:00.214597498 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2928:gst_bin_change_state_func:<main_pipe1> child 'main_compositor1' changed state to 2(READY) successfully
0:00:00.214611802 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2479:gst_bin_element_set_state:<main_caps8> current NULL pending VOID_PENDING, desired next READY
0:00:00.214622618 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2806:gst_element_continue_state:<main_caps8> completed state change to READY
0:00:00.214632475 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2706:_priv_gst_element_state_changed:<main_caps8> notifying about state-changed NULL to READY (VOID_PENDING pending)
0:00:00.214646075 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2928:gst_bin_change_state_func:<main_pipe1> child 'main_caps8' changed state to 2(READY) successfully
0:00:00.214658651 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2479:gst_bin_element_set_state:<main_caps7> current NULL pending VOID_PENDING, desired next READY
0:00:00.214671804 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2806:gst_element_continue_state:<main_caps7> completed state change to READY
0:00:00.214682524 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2706:_priv_gst_element_state_changed:<main_caps7> notifying about state-changed NULL to READY (VOID_PENDING pending)
0:00:00.214695773 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2928:gst_bin_change_state_func:<main_pipe1> child 'main_caps7' changed state to 2(READY) successfully
0:00:00.214709245 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2479:gst_bin_element_set_state:<main_iray_mp4_tee> current NULL pending VOID_PENDING, desired next READY
0:00:00.214720541 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2806:gst_element_continue_state:<main_iray_mp4_tee> completed state change to READY
0:00:00.214730846 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2706:_priv_gst_element_state_changed:<main_iray_mp4_tee> notifying about state-changed NULL to READY (VOID_PENDING pending)
0:00:00.214743166 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2928:gst_bin_change_state_func:<main_pipe1> child 'main_iray_mp4_tee' changed state to 2(READY) successfully
0:00:00.214756478 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2479:gst_bin_element_set_state:<main_sony_mp4_tee> current NULL pending VOID_PENDING, desired next READY
0:00:00.214767391 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2806:gst_element_continue_state:<main_sony_mp4_tee> completed state change to READY
0:00:00.214777439 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2706:_priv_gst_element_state_changed:<main_sony_mp4_tee> notifying about state-changed NULL to READY (VOID_PENDING pending)
0:00:00.214790591 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2928:gst_bin_change_state_func:<main_pipe1> child 'main_sony_mp4_tee' changed state to 2(READY) successfully
0:00:00.214803936 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2479:gst_bin_element_set_state:<main_caps4> current NULL pending VOID_PENDING, desired next READY
0:00:00.214814336 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2806:gst_element_continue_state:<main_caps4> completed state change to READY
0:00:00.214824160 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2706:_priv_gst_element_state_changed:<main_caps4> notifying about state-changed NULL to READY (VOID_PENDING pending)
0:00:00.214843617 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2928:gst_bin_change_state_func:<main_pipe1> child 'main_caps4' changed state to 2(READY) successfully
0:00:00.214858977 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2479:gst_bin_element_set_state:<main_caps2> current NULL pending VOID_PENDING, desired next READY
0:00:00.214869474 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2806:gst_element_continue_state:<main_caps2> completed state change to READY
0:00:00.214879746 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2706:_priv_gst_element_state_changed:<main_caps2> notifying about state-changed NULL to READY (VOID_PENDING pending)
0:00:00.214892130 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2928:gst_bin_change_state_func:<main_pipe1> child 'main_caps2' changed state to 2(READY) successfully
0:00:00.214907875 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2479:gst_bin_element_set_state:<main_conv2> current NULL pending VOID_PENDING, desired next READY
0:00:00.214919971 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2806:gst_element_continue_state:<main_conv2> completed state change to READY
0:00:00.214929924 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2706:_priv_gst_element_state_changed:<main_conv2> notifying about state-changed NULL to READY (VOID_PENDING pending)
0:00:00.214942244 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2928:gst_bin_change_state_func:<main_pipe1> child 'main_conv2' changed state to 2(READY) successfully
0:00:00.214957828 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2479:gst_bin_element_set_state:<main_conv1> current NULL pending VOID_PENDING, desired next READY
0:00:00.214969413 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2806:gst_element_continue_state:<main_conv1> completed state change to READY
0:00:00.214979205 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2706:_priv_gst_element_state_changed:<main_conv1> notifying about state-changed NULL to READY (VOID_PENDING pending)
0:00:00.214992485 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2928:gst_bin_change_state_func:<main_pipe1> child 'main_conv1' changed state to 2(READY) successfully
0:00:00.215007206 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2479:gst_bin_element_set_state:<main_caps3> current NULL pending VOID_PENDING, desired next READY
0:00:00.215017702 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2806:gst_element_continue_state:<main_caps3> completed state change to READY
0:00:00.215027399 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2706:_priv_gst_element_state_changed:<main_caps3> notifying about state-changed NULL to READY (VOID_PENDING pending)
0:00:00.215039783 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2928:gst_bin_change_state_func:<main_pipe1> child 'main_caps3' changed state to 2(READY) successfully
0:00:00.215052807 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2479:gst_bin_element_set_state:<main_caps1> current NULL pending VOID_PENDING, desired next READY
0:00:00.215064968 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2806:gst_element_continue_state:<main_caps1> completed state change to READY
0:00:00.215075688 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2706:_priv_gst_element_state_changed:<main_caps1> notifying about state-changed NULL to READY (VOID_PENDING pending)
0:00:00.215089192 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2928:gst_bin_change_state_func:<main_pipe1> child 'main_caps1' changed state to 2(READY) successfully
0:00:00.215100617 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2479:gst_bin_element_set_state:<main_src2> current NULL pending VOID_PENDING, desired next READY
0:00:00.215114089 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2806:gst_element_continue_state:<main_src2> completed state change to READY
0:00:00.215125033 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2706:_priv_gst_element_state_changed:<main_src2> notifying about state-changed NULL to READY (VOID_PENDING pending)
0:00:00.215138730 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2928:gst_bin_change_state_func:<main_pipe1> child 'main_src2' changed state to 2(READY) successfully
0:00:00.215152778 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2479:gst_bin_element_set_state:<main_src1> current NULL pending VOID_PENDING, desired next READY
0:00:00.215164011 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2806:gst_element_continue_state:<main_src1> completed state change to READY
0:00:00.215173835 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2706:_priv_gst_element_state_changed:<main_src1> notifying about state-changed NULL to READY (VOID_PENDING pending)
0:00:00.215186699 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2928:gst_bin_change_state_func:<main_pipe1> child 'main_src1' changed state to 2(READY) successfully
0:00:00.215204556 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2479:gst_bin_element_set_state:<main_queue2> current NULL pending VOID_PENDING, desired next READY
0:00:00.215217548 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2806:gst_element_continue_state:<main_queue2> completed state change to READY
0:00:00.215228557 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2706:_priv_gst_element_state_changed:<main_queue2> notifying about state-changed NULL to READY (VOID_PENDING pending)
0:00:00.215241357 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2928:gst_bin_change_state_func:<main_pipe1> child 'main_queue2' changed state to 2(READY) successfully
0:00:00.215255149 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2479:gst_bin_element_set_state:<main_queue1> current NULL pending VOID_PENDING, desired next READY
0:00:00.215265582 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2806:gst_element_continue_state:<main_queue1> completed state change to READY
0:00:00.215275758 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2706:_priv_gst_element_state_changed:<main_queue1> notifying about state-changed NULL to READY (VOID_PENDING pending)
0:00:00.215288366 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2928:gst_bin_change_state_func:<main_pipe1> child 'main_queue1' changed state to 2(READY) successfully
0:00:00.215312911 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2778:gst_element_continue_state:<main_pipe1> committing state from NULL to READY, pending PLAYING, next PAUSED
0:00:00.215324591 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2706:_priv_gst_element_state_changed:<main_pipe1> notifying about state-changed NULL to READY (PLAYING pending)
0:00:00.215338448 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2786:gst_element_continue_state:<main_pipe1> continue state change READY to PAUSED, final PLAYING
0:00:00.215398706 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2479:gst_bin_element_set_state:<main_sony_mp4_sink1> current READY pending VOID_PENDING, desired next PAUSED
0:00:00.215450899 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2935:gst_bin_change_state_func:<main_pipe1> child 'main_sony_mp4_sink1' is changing state asynchronously to PAUSED
0:00:00.215467732 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2479:gst_bin_element_set_state:<main_sink1> current READY pending VOID_PENDING, desired next PAUSED
0:00:00.215490292 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2935:gst_bin_change_state_func:<main_pipe1> child 'main_sink1' is changing state asynchronously to PAUSED
0:00:00.215504469 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2479:gst_bin_element_set_state:<main_sony_mp4_parse1> current READY pending VOID_PENDING, desired next PAUSED
0:00:00.215830623 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2806:gst_element_continue_state:<main_sony_mp4_parse1> completed state change to PAUSED
0:00:00.215851615 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2706:_priv_gst_element_state_changed:<main_sony_mp4_parse1> notifying about state-changed READY to PAUSED (VOID_PENDING pending)
0:00:00.215870496 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2928:gst_bin_change_state_func:<main_pipe1> child 'main_sony_mp4_parse1' changed state to 3(PAUSED) successfully
0:00:00.215888800 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2479:gst_bin_element_set_state:<main_parse1> current READY pending VOID_PENDING, desired next PAUSED
0:00:00.216081222 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2806:gst_element_continue_state:<main_parse1> completed state change to PAUSED
0:00:00.216099335 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2706:_priv_gst_element_state_changed:<main_parse1> notifying about state-changed READY to PAUSED (VOID_PENDING pending)
0:00:00.216117479 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2928:gst_bin_change_state_func:<main_pipe1> child 'main_parse1' changed state to 3(PAUSED) successfully
0:00:00.216134536 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2479:gst_bin_element_set_state:<main_sony_mp4_enc1> current READY pending VOID_PENDING, desired next PAUSED
0:00:00.216161449 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2806:gst_element_continue_state:<main_sony_mp4_enc1> completed state change to PAUSED
0:00:00.216174153 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2706:_priv_gst_element_state_changed:<main_sony_mp4_enc1> notifying about state-changed READY to PAUSED (VOID_PENDING pending)
0:00:00.216190122 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2928:gst_bin_change_state_func:<main_pipe1> child 'main_sony_mp4_enc1' changed state to 3(PAUSED) successfully
0:00:00.216203530 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2479:gst_bin_element_set_state:<main_enc1> current READY pending VOID_PENDING, desired next PAUSED
0:00:00.216223275 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2806:gst_element_continue_state:<main_enc1> completed state change to PAUSED
0:00:00.216234571 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2706:_priv_gst_element_state_changed:<main_enc1> notifying about state-changed READY to PAUSED (VOID_PENDING pending)
0:00:00.216248843 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2928:gst_bin_change_state_func:<main_pipe1> child 'main_enc1' changed state to 3(PAUSED) successfully
0:00:00.216266316 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2479:gst_bin_element_set_state:<main_sony_mp4_caps1> current READY pending VOID_PENDING, desired next PAUSED
0:00:00.216289901 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2806:gst_element_continue_state:<main_sony_mp4_caps1> completed state change to PAUSED
0:00:00.216301421 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2706:_priv_gst_element_state_changed:<main_sony_mp4_caps1> notifying about state-changed READY to PAUSED (VOID_PENDING pending)
0:00:00.216316173 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2928:gst_bin_change_state_func:<main_pipe1> child 'main_sony_mp4_caps1' changed state to 3(PAUSED) successfully
0:00:00.216329390 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2479:gst_bin_element_set_state:<main_caps6> current READY pending VOID_PENDING, desired next PAUSED
0:00:00.216346510 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2806:gst_element_continue_state:<main_caps6> completed state change to PAUSED
0:00:00.216357167 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2706:_priv_gst_element_state_changed:<main_caps6> notifying about state-changed READY to PAUSED (VOID_PENDING pending)
0:00:00.216370607 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2928:gst_bin_change_state_func:<main_pipe1> child 'main_caps6' changed state to 3(PAUSED) successfully
0:00:00.216385551 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2479:gst_bin_element_set_state:<main_sony_mp4_conv1> current READY pending VOID_PENDING, desired next PAUSED
0:00:00.216404976 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2806:gst_element_continue_state:<main_sony_mp4_conv1> completed state change to PAUSED
0:00:00.216416112 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2706:_priv_gst_element_state_changed:<main_sony_mp4_conv1> notifying about state-changed READY to PAUSED (VOID_PENDING pending)
0:00:00.216430257 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2928:gst_bin_change_state_func:<main_pipe1> child 'main_sony_mp4_conv1' changed state to 3(PAUSED) successfully
0:00:00.216443185 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2479:gst_bin_element_set_state:<main_conv3> current READY pending VOID_PENDING, desired next PAUSED
0:00:00.216459794 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2806:gst_element_continue_state:<main_conv3> completed state change to PAUSED
0:00:00.216470834 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2706:_priv_gst_element_state_changed:<main_conv3> notifying about state-changed READY to PAUSED (VOID_PENDING pending)
0:00:00.216483762 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2928:gst_bin_change_state_func:<main_pipe1> child 'main_conv3' changed state to 3(PAUSED) successfully
0:00:00.216498995 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2479:gst_bin_element_set_state:<main_sony_mp4_caps2> current READY pending VOID_PENDING, desired next PAUSED
0:00:00.216517267 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2806:gst_element_continue_state:<main_sony_mp4_caps2> completed state change to PAUSED
0:00:00.216529396 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2706:_priv_gst_element_state_changed:<main_sony_mp4_caps2> notifying about state-changed READY to PAUSED (VOID_PENDING pending)
0:00:00.216548404 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2928:gst_bin_change_state_func:<main_pipe1> child 'main_sony_mp4_caps2' changed state to 3(PAUSED) successfully
0:00:00.216562549 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2479:gst_bin_element_set_state:<main_caps5> current READY pending VOID_PENDING, desired next PAUSED
0:00:00.216579317 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2806:gst_element_continue_state:<main_caps5> completed state change to PAUSED
0:00:00.216590230 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2706:_priv_gst_element_state_changed:<main_caps5> notifying about state-changed READY to PAUSED (VOID_PENDING pending)
0:00:00.216603798 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2928:gst_bin_change_state_func:<main_pipe1> child 'main_caps5' changed state to 3(PAUSED) successfully
0:00:00.216619478 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2479:gst_bin_element_set_state:<main_compositor1> current READY pending VOID_PENDING, desired next PAUSED
0:00:00.216639895 9259 0xaaaade61f400 INFO aggregator gstaggregator.c:2488:gst_aggregator_src_pad_activate_mode_func:<main_compositor1:src> Activating pad!
0:00:00.216650199 9259 0xaaaade61f400 INFO aggregator gstaggregator.c:1511:gst_aggregator_start_srcpad_task:<main_compositor1> Starting srcpad task
0:00:00.216681464 9259 0xaaaade61f400 INFO task gsttask.c:516:gst_task_set_lock: setting stream lock 0xaaaade6328d0 on task 0xaaaade98b710
0:00:00.216694713 9259 0xaaaade61f400 INFO GST_PADS gstpad.c:6291:gst_pad_start_task:<main_compositor1:src> created task 0xaaaade98b710
0:00:00.216841533 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2806:gst_element_continue_state:<main_compositor1> completed state change to PAUSED
0:00:00.216867838 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2706:_priv_gst_element_state_changed:<main_compositor1> notifying about state-changed READY to PAUSED (VOID_PENDING pending)
0:00:00.216886174 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2928:gst_bin_change_state_func:<main_pipe1> child 'main_compositor1' changed state to 3(PAUSED) successfully
0:00:00.216929312 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2479:gst_bin_element_set_state:<main_caps8> current READY pending VOID_PENDING, desired next PAUSED
0:00:00.216954241 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2806:gst_element_continue_state:<main_caps8> completed state change to PAUSED
0:00:00.216967105 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2706:_priv_gst_element_state_changed:<main_caps8> notifying about state-changed READY to PAUSED (VOID_PENDING pending)
0:00:00.216982145 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2928:gst_bin_change_state_func:<main_pipe1> child 'main_caps8' changed state to 3(PAUSED) successfully
0:00:00.216999138 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2479:gst_bin_element_set_state:<main_caps7> current READY pending VOID_PENDING, desired next PAUSED
0:00:00.217020227 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2806:gst_element_continue_state:<main_caps7> completed state change to PAUSED
0:00:00.217033315 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2706:_priv_gst_element_state_changed:<main_caps7> notifying about state-changed READY to PAUSED (VOID_PENDING pending)
0:00:00.217049891 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2928:gst_bin_change_state_func:<main_pipe1> child 'main_caps7' changed state to 3(PAUSED) successfully
0:00:00.217065892 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2479:gst_bin_element_set_state:<main_iray_mp4_tee> current READY pending VOID_PENDING, desired next PAUSED
0:00:00.217083940 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2806:gst_element_continue_state:<main_iray_mp4_tee> completed state change to PAUSED
0:00:00.217095621 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2706:_priv_gst_element_state_changed:<main_iray_mp4_tee> notifying about state-changed READY to PAUSED (VOID_PENDING pending)
0:00:00.217125094 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2928:gst_bin_change_state_func:<main_pipe1> child 'main_iray_mp4_tee' changed state to 3(PAUSED) successfully
0:00:00.217141926 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2479:gst_bin_element_set_state:<main_sony_mp4_tee> current READY pending VOID_PENDING, desired next PAUSED
0:00:00.217160807 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2806:gst_element_continue_state:<main_sony_mp4_tee> completed state change to PAUSED
0:00:00.217172039 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2706:_priv_gst_element_state_changed:<main_sony_mp4_tee> notifying about state-changed READY to PAUSED (VOID_PENDING pending)
0:00:00.217186024 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2928:gst_bin_change_state_func:<main_pipe1> child 'main_sony_mp4_tee' changed state to 3(PAUSED) successfully
0:00:00.217199432 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2479:gst_bin_element_set_state:<main_caps4> current READY pending VOID_PENDING, desired next PAUSED
0:00:00.217215912 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2806:gst_element_continue_state:<main_caps4> completed state change to PAUSED
0:00:00.217226185 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2706:_priv_gst_element_state_changed:<main_caps4> notifying about state-changed READY to PAUSED (VOID_PENDING pending)
0:00:00.217239113 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2928:gst_bin_change_state_func:<main_pipe1> child 'main_caps4' changed state to 3(PAUSED) successfully
0:00:00.217251657 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2479:gst_bin_element_set_state:<main_caps2> current READY pending VOID_PENDING, desired next PAUSED
0:00:00.217265834 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2806:gst_element_continue_state:<main_caps2> completed state change to PAUSED
0:00:00.217277034 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2706:_priv_gst_element_state_changed:<main_caps2> notifying about state-changed READY to PAUSED (VOID_PENDING pending)
0:00:00.217290475 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2928:gst_bin_change_state_func:<main_pipe1> child 'main_caps2' changed state to 3(PAUSED) successfully
0:00:00.217303563 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2479:gst_bin_element_set_state:<main_conv2> current READY pending VOID_PENDING, desired next PAUSED
0:00:00.217321644 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2806:gst_element_continue_state:<main_conv2> completed state change to PAUSED
0:00:00.217343788 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2706:_priv_gst_element_state_changed:<main_conv2> notifying about state-changed READY to PAUSED (VOID_PENDING pending)
0:00:00.217359533 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2928:gst_bin_change_state_func:<main_pipe1> child 'main_conv2' changed state to 3(PAUSED) successfully
0:00:00.217374285 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2479:gst_bin_element_set_state:<main_conv1> current READY pending VOID_PENDING, desired next PAUSED
0:00:00.217391374 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2806:gst_element_continue_state:<main_conv1> completed state change to PAUSED
0:00:00.217401294 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2706:_priv_gst_element_state_changed:<main_conv1> notifying about state-changed READY to PAUSED (VOID_PENDING pending)
0:00:00.217416078 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2928:gst_bin_change_state_func:<main_pipe1> child 'main_conv1' changed state to 3(PAUSED) successfully
0:00:00.217440623 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2479:gst_bin_element_set_state:<main_caps3> current READY pending VOID_PENDING, desired next PAUSED
0:00:00.217458256 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2806:gst_element_continue_state:<main_caps3> completed state change to PAUSED
0:00:00.217469296 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2706:_priv_gst_element_state_changed:<main_caps3> notifying about state-changed READY to PAUSED (VOID_PENDING pending)
0:00:00.217482416 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2928:gst_bin_change_state_func:<main_pipe1> child 'main_caps3' changed state to 3(PAUSED) successfully
0:00:00.217496241 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2479:gst_bin_element_set_state:<main_caps1> current READY pending VOID_PENDING, desired next PAUSED
0:00:00.217513969 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2806:gst_element_continue_state:<main_caps1> completed state change to PAUSED
0:00:00.217525586 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2706:_priv_gst_element_state_changed:<main_caps1> notifying about state-changed READY to PAUSED (VOID_PENDING pending)
0:00:00.217538642 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2928:gst_bin_change_state_func:<main_pipe1> child 'main_caps1' changed state to 3(PAUSED) successfully
0:00:00.217552499 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2479:gst_bin_element_set_state:<main_src2> current READY pending VOID_PENDING, desired next PAUSED
0:00:00.217689335 9259 0xaaaade61f400 INFO basesrc gstbasesrc.c:1430:gst_base_src_do_seek:<main_src2> 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:00.217717784 9259 0xaaaade61f400 INFO task gsttask.c:516:gst_task_set_lock: setting stream lock 0xaaaade96e180 on task 0xaaaade98b830
0:00:00.217733368 9259 0xaaaade61f400 INFO GST_PADS gstpad.c:6291:gst_pad_start_task:<main_src2:src> created task 0xaaaade98b830
0:00:00.217843547 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2806:gst_element_continue_state:<main_src2> completed state change to PAUSED
0:00:00.217861500 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2706:_priv_gst_element_state_changed:<main_src2> notifying about state-changed READY to PAUSED (VOID_PENDING pending)
0:00:00.217879580 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2971:gst_bin_change_state_func:<main_pipe1> child 'main_src2' changed state to 3(PAUSED) successfully without preroll
0:00:00.217895229 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2479:gst_bin_element_set_state:<main_src1> current READY pending VOID_PENDING, desired next PAUSED
0:00:00.217938398 9259 0xaaaade8b3d80 INFO GST_ELEMENT_PADS gstelement.c:1013:gst_element_get_static_pad: no such pad 'sink' in element "main_src2"
0:00:00.217973631 9259 0xaaaade61f400 INFO basesrc gstbasesrc.c:1430:gst_base_src_do_seek:<main_src1> 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:00.217985728 9259 0xaaaade8b3d80 FIXME default gstutils.c:4025:gst_pad_create_stream_id_internal:<main_src2:src> Creating random stream-id, consider implementing a deterministic way of creating a stream-id
0:00:00.217999936 9259 0xaaaade61f400 INFO task gsttask.c:516:gst_task_set_lock: setting stream lock 0xaaaade8dc0d0 on task 0xaaaade98b950
0:00:00.218013216 9259 0xaaaade61f400 INFO GST_PADS gstpad.c:6291:gst_pad_start_task:<main_src1:src> created task 0xaaaade98b950
0:00:00.218128644 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2806:gst_element_continue_state:<main_src1> completed state change to PAUSED
0:00:00.218149028 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2706:_priv_gst_element_state_changed:<main_src1> notifying about state-changed READY to PAUSED (VOID_PENDING pending)
0:00:00.218187206 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2971:gst_bin_change_state_func:<main_pipe1> child 'main_src1' changed state to 3(PAUSED) successfully without preroll
0:00:00.218202310 9259 0xaaaade8b3de0 INFO GST_ELEMENT_PADS gstelement.c:1013:gst_element_get_static_pad: no such pad 'sink' in element "main_src1"
0:00:00.218247719 9259 0xaaaade8b3de0 FIXME default gstutils.c:4025:gst_pad_create_stream_id_internal:<main_src1:src> Creating random stream-id, consider implementing a deterministic way of creating a stream-id
0:00:00.218274184 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2479:gst_bin_element_set_state:<main_queue2> current READY pending VOID_PENDING, desired next PAUSED
0:00:00.218306601 9259 0xaaaade61f400 INFO task gsttask.c:516:gst_task_set_lock: setting stream lock 0xaaaade8ddc90 on task 0xaaaade98ba70
0:00:00.218329802 9259 0xaaaade61f400 INFO GST_PADS gstpad.c:6291:gst_pad_start_task:<main_queue2:src> created task 0xaaaade98ba70
0:00:00.218438989 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2806:gst_element_continue_state:<main_queue2> completed state change to PAUSED
0:00:00.218458830 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2706:_priv_gst_element_state_changed:<main_queue2> notifying about state-changed READY to PAUSED (VOID_PENDING pending)
0:00:00.218517104 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2928:gst_bin_change_state_func:<main_pipe1> child 'main_queue2' changed state to 3(PAUSED) successfully
0:00:00.218540656 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2479:gst_bin_element_set_state:<main_queue1> current READY pending VOID_PENDING, desired next PAUSED
0:00:00.218552849 9259 0xaaaade8b3d80 WARN nvv4l2camerasrc gstnvv4l2camerasrc.cpp:684:gst_nv_v4l2_camera_fixate:<main_src2> Unable to fixate caps structure
0:00:00.218573073 9259 0xaaaade61f400 INFO task gsttask.c:516:gst_task_set_lock: setting stream lock 0xaaaade8dd7f0 on task 0xaaaade98bb90
0:00:00.218607186 9259 0xaaaade61f400 INFO GST_PADS gstpad.c:6291:gst_pad_start_task:<main_queue1:src> created task 0xaaaade98bb90
0:00:00.218733334 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2806:gst_element_continue_state:<main_queue1> completed state change to PAUSED
0:00:00.218754455 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2706:_priv_gst_element_state_changed:<main_queue1> notifying about state-changed READY to PAUSED (VOID_PENDING pending)
0:00:00.218777239 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2928:gst_bin_change_state_func:<main_pipe1> child 'main_queue1' changed state to 3(PAUSED) successfully
0:00:00.218799096 9259 0xaaaade61f400 INFO pipeline gstpipeline.c:533:gst_pipeline_change_state:<main_pipe1> pipeline is live
0:00:00.218814489 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2778:gst_element_continue_state:<main_pipe1> committing state from READY to PAUSED, pending PLAYING, next PLAYING
0:00:00.218827833 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2706:_priv_gst_element_state_changed:<main_pipe1> notifying about state-changed READY to PAUSED (PLAYING pending)
0:00:00.218843065 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2786:gst_element_continue_state:<main_pipe1> continue state change PAUSED to PLAYING, final PLAYING
0:00:00.218869338 9259 0xaaaade8b3de0 WARN nvv4l2camerasrc gstnvv4l2camerasrc.cpp:684:gst_nv_v4l2_camera_fixate:<main_src1> Unable to fixate caps structure
0:00:00.218970173 9259 0xaaaade61f400 INFO GST_EVENT gstevent.c:1530:gst_event_new_latency: creating latency event 0:00:00.000000000
0:00:00.219017567 9259 0xaaaade61f400 INFO bin gstbin.c:2759:gst_bin_do_latency_func:<main_pipe1> configured latency of 0:00:00.000000000
0:00:00.219068128 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2479:gst_bin_element_set_state:<main_sony_mp4_sink1> current READY pending PAUSED, desired next PLAYING
0:00:00.219082113 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2935:gst_bin_change_state_func:<main_pipe1> child 'main_sony_mp4_sink1' is changing state asynchronously to PLAYING
0:00:00.219096321 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2479:gst_bin_element_set_state:<main_sink1> current READY pending PAUSED, desired next PLAYING
0:00:00.219106721 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2935:gst_bin_change_state_func:<main_pipe1> child 'main_sink1' is changing state asynchronously to PLAYING
0:00:00.219119490 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2479:gst_bin_element_set_state:<main_sony_mp4_parse1> current PAUSED pending VOID_PENDING, desired next PLAYING
0:00:00.219130946 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2806:gst_element_continue_state:<main_sony_mp4_parse1> completed state change to PLAYING
0:00:00.219141762 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2706:_priv_gst_element_state_changed:<main_sony_mp4_parse1> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)
0:00:00.219156867 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2928:gst_bin_change_state_func:<main_pipe1> child 'main_sony_mp4_parse1' changed state to 4(PLAYING) successfully
0:00:00.219170275 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2479:gst_bin_element_set_state:<main_parse1> current PAUSED pending VOID_PENDING, desired next PLAYING
0:00:00.219180292 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2806:gst_element_continue_state:<main_parse1> completed state change to PLAYING
0:00:00.219190628 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2706:_priv_gst_element_state_changed:<main_parse1> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)
0:00:00.219203940 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2928:gst_bin_change_state_func:<main_pipe1> child 'main_parse1' changed state to 4(PLAYING) successfully
0:00:00.219217029 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2479:gst_bin_element_set_state:<main_sony_mp4_enc1> current PAUSED pending VOID_PENDING, desired next PLAYING
0:00:00.219229893 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2806:gst_element_continue_state:<main_sony_mp4_enc1> completed state change to PLAYING
0:00:00.219240005 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2706:_priv_gst_element_state_changed:<main_sony_mp4_enc1> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)
0:00:00.219254342 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2928:gst_bin_change_state_func:<main_pipe1> child 'main_sony_mp4_enc1' changed state to 4(PLAYING) successfully
0:00:00.219267110 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2479:gst_bin_element_set_state:<main_enc1> current PAUSED pending VOID_PENDING, desired next PLAYING
0:00:00.219277638 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2806:gst_element_continue_state:<main_enc1> completed state change to PLAYING
0:00:00.219307239 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2706:_priv_gst_element_state_changed:<main_enc1> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)
0:00:00.219323048 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2928:gst_bin_change_state_func:<main_pipe1> child 'main_enc1' changed state to 4(PLAYING) successfully
0:00:00.219336616 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2479:gst_bin_element_set_state:<main_sony_mp4_caps1> current PAUSED pending VOID_PENDING, desired next PLAYING
0:00:00.219346953 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2806:gst_element_continue_state:<main_sony_mp4_caps1> completed state change to PLAYING
0:00:00.219356233 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2706:_priv_gst_element_state_changed:<main_sony_mp4_caps1> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)
0:00:00.219369161 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2928:gst_bin_change_state_func:<main_pipe1> child 'main_sony_mp4_caps1' changed state to 4(PLAYING) successfully
0:00:00.219384970 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2479:gst_bin_element_set_state:<main_caps6> current PAUSED pending VOID_PENDING, desired next PLAYING
0:00:00.219397034 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2806:gst_element_continue_state:<main_caps6> completed state change to PLAYING
0:00:00.219407274 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2706:_priv_gst_element_state_changed:<main_caps6> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)
0:00:00.219420299 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2928:gst_bin_change_state_func:<main_pipe1> child 'main_caps6' changed state to 4(PLAYING) successfully
0:00:00.219432971 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2479:gst_bin_element_set_state:<main_sony_mp4_conv1> current PAUSED pending VOID_PENDING, desired next PLAYING
0:00:00.219444747 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2806:gst_element_continue_state:<main_sony_mp4_conv1> completed state change to PLAYING
0:00:00.219455084 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2706:_priv_gst_element_state_changed:<main_sony_mp4_conv1> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)
0:00:00.219468140 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2928:gst_bin_change_state_func:<main_pipe1> child 'main_sony_mp4_conv1' changed state to 4(PLAYING) successfully
0:00:00.219480525 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2479:gst_bin_element_set_state:<main_conv3> current PAUSED pending VOID_PENDING, desired next PLAYING
0:00:00.219491149 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2806:gst_element_continue_state:<main_conv3> completed state change to PLAYING
0:00:00.219500941 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2706:_priv_gst_element_state_changed:<main_conv3> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)
0:00:00.219513582 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2928:gst_bin_change_state_func:<main_pipe1> child 'main_conv3' changed state to 4(PLAYING) successfully
0:00:00.219526542 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2479:gst_bin_element_set_state:<main_sony_mp4_caps2> current PAUSED pending VOID_PENDING, desired next PLAYING
0:00:00.219537198 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2806:gst_element_continue_state:<main_sony_mp4_caps2> completed state change to PLAYING
0:00:00.219546991 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2706:_priv_gst_element_state_changed:<main_sony_mp4_caps2> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)
0:00:00.219559663 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2928:gst_bin_change_state_func:<main_pipe1> child 'main_sony_mp4_caps2' changed state to 4(PLAYING) successfully
0:00:00.219572207 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2479:gst_bin_element_set_state:<main_caps5> current PAUSED pending VOID_PENDING, desired next PLAYING
0:00:00.219582576 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2806:gst_element_continue_state:<main_caps5> completed state change to PLAYING
0:00:00.219592432 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2706:_priv_gst_element_state_changed:<main_caps5> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)
0:00:00.219605328 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2928:gst_bin_change_state_func:<main_pipe1> child 'main_caps5' changed state to 4(PLAYING) successfully
0:00:00.219618577 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2479:gst_bin_element_set_state:<main_compositor1> current PAUSED pending VOID_PENDING, desired next PLAYING
0:00:00.219635217 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2806:gst_element_continue_state:<main_compositor1> completed state change to PLAYING
0:00:00.219650194 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2706:_priv_gst_element_state_changed:<main_compositor1> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)
0:00:00.219688595 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2928:gst_bin_change_state_func:<main_pipe1> child 'main_compositor1' changed state to 4(PLAYING) successfully
0:00:00.219705651 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2479:gst_bin_element_set_state:<main_caps8> current PAUSED pending VOID_PENDING, desired next PLAYING
0:00:00.219718420 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2806:gst_element_continue_state:<main_caps8> completed state change to PLAYING
0:00:00.219741492 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2706:_priv_gst_element_state_changed:<main_caps8> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)
0:00:00.219758037 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2928:gst_bin_change_state_func:<main_pipe1> child 'main_caps8' changed state to 4(PLAYING) successfully
0:00:00.219771413 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2479:gst_bin_element_set_state:<main_caps7> current PAUSED pending VOID_PENDING, desired next PLAYING
0:00:00.219783766 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2806:gst_element_continue_state:<main_caps7> completed state change to PLAYING
0:00:00.219794678 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2706:_priv_gst_element_state_changed:<main_caps7> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)
0:00:00.219809078 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2928:gst_bin_change_state_func:<main_pipe1> child 'main_caps7' changed state to 4(PLAYING) successfully
0:00:00.219821527 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2479:gst_bin_element_set_state:<main_iray_mp4_tee> current PAUSED pending VOID_PENDING, desired next PLAYING
0:00:00.219833975 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2806:gst_element_continue_state:<main_iray_mp4_tee> completed state change to PLAYING
0:00:00.219845240 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2706:_priv_gst_element_state_changed:<main_iray_mp4_tee> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)
0:00:00.219860408 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2928:gst_bin_change_state_func:<main_pipe1> child 'main_iray_mp4_tee' changed state to 4(PLAYING) successfully
0:00:00.219874424 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2479:gst_bin_element_set_state:<main_sony_mp4_tee> current PAUSED pending VOID_PENDING, desired next PLAYING
0:00:00.219887193 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2806:gst_element_continue_state:<main_sony_mp4_tee> completed state change to PLAYING
0:00:00.219898553 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2706:_priv_gst_element_state_changed:<main_sony_mp4_tee> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)
0:00:00.219913658 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2928:gst_bin_change_state_func:<main_pipe1> child 'main_sony_mp4_tee' changed state to 4(PLAYING) successfully
0:00:00.219906905 9259 0xaaaade8b38c0 WARN videoaggregator gstvideoaggregator.c:1140:gst_video_aggregator_find_best_format:<main_compositor1> Nothing compatible with video/x-raw(memory:NVMM), format=(string)RGBA, width=(int)1920, height=(int)1080, framerate=(fraction)30/1
0:00:00.219933690 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2479:gst_bin_element_set_state:<main_caps4> current PAUSED pending VOID_PENDING, desired next PLAYING
0:00:00.219989596 9259 0xaaaade8b38c0 WARN nvcompositor gstnvcompositor.c:776:gst_nvcompositor_fixate_caps:<main_compositor1> This pad is invalid
0:00:00.220008828 9259 0xaaaade8b38c0 WARN nvcompositor gstnvcompositor.c:776:gst_nvcompositor_fixate_caps:<main_compositor1> This pad is invalid
0:00:00.220047518 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2806:gst_element_continue_state:<main_caps4> completed state change to PLAYING
0:00:00.220080767 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2706:_priv_gst_element_state_changed:<main_caps4> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)
0:00:00.220107487 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2928:gst_bin_change_state_func:<main_pipe1> child 'main_caps4' changed state to 4(PLAYING) successfully
0:00:00.220045918 9259 0xaaaade8b38c0 INFO videoaggregator gstvideoaggregator.c:1301:gst_video_aggregator_default_negotiated_src_caps:<main_compositor1:src> set src caps: video/x-raw(memory:NVMM), format=(string)RGBA, width=(int)1920, height=(int)1080, framerate=(fraction)30/1, colorimetry=(string)sRGB
0:00:00.220127136 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2479:gst_bin_element_set_state:<main_caps2> current PAUSED pending VOID_PENDING, desired next PLAYING
0:00:00.220163073 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2806:gst_element_continue_state:<main_caps2> completed state change to PLAYING
0:00:00.220168225 9259 0xaaaade8b38c0 INFO aggregator gstaggregator.c:610:gst_aggregator_push_mandatory_events:<main_compositor1> pushing stream start
0:00:00.220175809 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2706:_priv_gst_element_state_changed:<main_caps2> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)
0:00:00.220222275 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2928:gst_bin_change_state_func:<main_pipe1> child 'main_caps2' changed state to 4(PLAYING) successfully
0:00:00.220243876 9259 0xaaaade8b38c0 INFO aggregator gstaggregator.c:621:gst_aggregator_push_mandatory_events:<main_compositor1> pushing caps: video/x-raw(memory:NVMM), format=(string)RGBA, width=(int)1920, height=(int)1080, framerate=(fraction)30/1, colorimetry=(string)sRGB
0:00:00.220254116 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2479:gst_bin_element_set_state:<main_conv2> current PAUSED pending VOID_PENDING, desired next PLAYING
0:00:00.220277125 9259 0xaaaade8b38c0 INFO GST_EVENT gstevent.c:892:gst_event_new_caps: creating caps event video/x-raw(memory:NVMM), format=(string)RGBA, width=(int)1920, height=(int)1080, framerate=(fraction)30/1, colorimetry=(string)sRGB
0:00:00.220318502 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2806:gst_element_continue_state:<main_conv2> completed state change to PLAYING
0:00:00.220336518 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2706:_priv_gst_element_state_changed:<main_conv2> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)
0:00:00.220349383 9259 0xaaaade8b38c0 INFO basetransform gstbasetransform.c:1325:gst_base_transform_setcaps:<main_caps5> reuse caps
0:00:00.220371143 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2928:gst_bin_change_state_func:<main_pipe1> child 'main_conv2' changed state to 4(PLAYING) successfully
0:00:00.220373703 9259 0xaaaade8b38c0 INFO GST_EVENT gstevent.c:892:gst_event_new_caps: creating caps event video/x-raw(memory:NVMM), format=(string)RGBA, width=(int)1920, height=(int)1080, framerate=(fraction)30/1, colorimetry=(string)sRGB
0:00:00.220395784 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2479:gst_bin_element_set_state:<main_conv1> current PAUSED pending VOID_PENDING, desired next PLAYING
0:00:00.220439433 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2806:gst_element_continue_state:<main_conv1> completed state change to PLAYING
0:00:00.220460330 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2706:_priv_gst_element_state_changed:<main_conv1> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)
0:00:00.220482059 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2928:gst_bin_change_state_func:<main_pipe1> child 'main_conv1' changed state to 4(PLAYING) successfully
0:00:00.220505259 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2479:gst_bin_element_set_state:<main_caps3> current PAUSED pending VOID_PENDING, desired next PLAYING
0:00:00.220526028 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2806:gst_element_continue_state:<main_caps3> completed state change to PLAYING
0:00:00.220545037 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2706:_priv_gst_element_state_changed:<main_caps3> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)
0:00:00.220569741 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2928:gst_bin_change_state_func:<main_pipe1> child 'main_caps3' changed state to 4(PLAYING) successfully
0:00:00.220595246 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2479:gst_bin_element_set_state:<main_caps1> current PAUSED pending VOID_PENDING, desired next PLAYING
0:00:00.220615471 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2806:gst_element_continue_state:<main_caps1> completed state change to PLAYING
0:00:00.220631887 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2706:_priv_gst_element_state_changed:<main_caps1> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)
0:00:00.220650992 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2928:gst_bin_change_state_func:<main_pipe1> child 'main_caps1' changed state to 4(PLAYING) successfully
0:00:00.220674352 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2806:gst_element_continue_state:<main_src2> completed state change to PLAYING
0:00:00.220696561 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2706:_priv_gst_element_state_changed:<main_src2> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)
0:00:00.220717394 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2928:gst_bin_change_state_func:<main_pipe1> child 'main_src2' changed state to 4(PLAYING) successfully
0:00:00.220737906 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2806:gst_element_continue_state:<main_src1> completed state change to PLAYING
0:00:00.220754835 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2706:_priv_gst_element_state_changed:<main_src1> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)
0:00:00.220752339 9259 0xaaaade8b38c0 INFO GST_EVENT gstevent.c:892:gst_event_new_caps: creating caps event video/x-raw(memory:NVMM), width=(int)1920, height=(int)1080, framerate=(fraction)30/1, format=(string)NV12
0:00:00.220897943 9259 0xaaaade8b38c0 INFO basetransform gstbasetransform.c:1325:gst_base_transform_setcaps:<main_caps6> reuse caps
0:00:00.220925624 9259 0xaaaade8b38c0 INFO GST_EVENT gstevent.c:892:gst_event_new_caps: creating caps event video/x-raw(memory:NVMM), width=(int)1920, height=(int)1080, framerate=(fraction)30/1, format=(string)NV12
0:00:00.221096797 9259 0xaaaade8b38c0 FIXME basesink gstbasesink.c:3395:gst_base_sink_default_event:<main_sink1> stream-start event without group-id. Consider implementing group-id handling in the upstream elements
0:00:00.221168735 9259 0xaaaade8b38c0 INFO GST_EVENT gstevent.c:892:gst_event_new_caps: creating caps event video/x-h264, stream-format=(string)byte-stream, alignment=(string)au, profile=(string)NULL, level=(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:00.221248642 9259 0xaaaade8b38c0 INFO GST_EVENT gstevent.c:892:gst_event_new_caps: creating caps event video/x-h264, stream-format=(string)byte-stream, alignment=(string)au, profile=(string)NULL, level=(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, parsed=(boolean)true
0:00:00.221290915 9259 0xaaaade8b38c0 INFO GST_EVENT gstevent.c:892:gst_event_new_caps: creating caps event video/x-h264, stream-format=(string)byte-stream, alignment=(string)au, profile=(string)NULL, level=(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, parsed=(boolean)true
0:00:00.221362309 9259 0xaaaade8b38c0 INFO v4l2 gstv4l2object.c:3211:gst_v4l2_object_setup_pool:<main_enc1:src> accessing buffers via mode 2
0:00:00.221535850 9259 0xaaaade8b38c0 INFO v4l2bufferpool gstv4l2bufferpool.c:827:gst_v4l2_buffer_pool_set_config:<main_enc1:pool:src> increasing minimum buffers to 2
0:00:00.221556395 9259 0xaaaade8b38c0 INFO v4l2bufferpool gstv4l2bufferpool.c:841:gst_v4l2_buffer_pool_set_config:<main_enc1:pool:src> reducing maximum buffers to 64
0:00:00.221567691 9259 0xaaaade8b38c0 INFO v4l2bufferpool gstv4l2bufferpool.c:859:gst_v4l2_buffer_pool_set_config:<main_enc1:pool:src> can't allocate, setting maximum to minimum
0:00:00.221638285 9259 0xaaaade8b38c0 INFO v4l2bufferpool gstv4l2bufferpool.c:841:gst_v4l2_buffer_pool_set_config:<main_enc1:pool:src> reducing maximum buffers to 64
0:00:00.221652046 9259 0xaaaade8b38c0 INFO v4l2bufferpool gstv4l2bufferpool.c:859:gst_v4l2_buffer_pool_set_config:<main_enc1:pool:src> can't allocate, setting maximum to minimum
NvMMLiteOpen : Block : BlockType = 4
===== NvVideo: NVENC =====
NvMMLiteBlockCreate : Block : BlockType = 4
0:00:00.223107930 9259 0xaaaade8b38c0 INFO v4l2 gstv4l2object.c:4185:gst_v4l2_object_set_format_full:<main_enc1:sink> Set output framerate to 30/1
0:00:00.223146171 9259 0xaaaade8b38c0 INFO v4l2 gstv4l2object.c:3211:gst_v4l2_object_setup_pool:<main_enc1:sink> accessing buffers via mode 5
0:00:00.223279839 9259 0xaaaade8b38c0 INFO v4l2bufferpool gstv4l2bufferpool.c:827:gst_v4l2_buffer_pool_set_config:<main_enc1:pool:sink> increasing minimum buffers to 2
0:00:00.223299391 9259 0xaaaade8b38c0 INFO v4l2bufferpool gstv4l2bufferpool.c:834:gst_v4l2_buffer_pool_set_config:<main_enc1:pool:sink> increasing minimum buffers to 4
0:00:00.223309696 9259 0xaaaade8b38c0 INFO v4l2bufferpool gstv4l2bufferpool.c:841:gst_v4l2_buffer_pool_set_config:<main_enc1:pool:sink> reducing maximum buffers to 64
0:00:00.223319136 9259 0xaaaade8b38c0 INFO v4l2bufferpool gstv4l2bufferpool.c:859:gst_v4l2_buffer_pool_set_config:<main_enc1:pool:sink> can't allocate, setting maximum to minimum
0:00:00.223328416 9259 0xaaaade8b38c0 INFO v4l2bufferpool gstv4l2bufferpool.c:864:gst_v4l2_buffer_pool_set_config:<main_enc1:pool:sink> adding needed video meta
0:00:00.220789588 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2928:gst_bin_change_state_func:<main_pipe1> child 'main_src1' changed state to 4(PLAYING) successfully
0:00:00.223592808 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2479:gst_bin_element_set_state:<main_queue2> current PAUSED pending VOID_PENDING, desired next PLAYING
0:00:00.223644746 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2806:gst_element_continue_state:<main_queue2> completed state change to PLAYING
0:00:00.223996212 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2706:_priv_gst_element_state_changed:<main_queue2> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)
0:00:00.224072151 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2928:gst_bin_change_state_func:<main_pipe1> child 'main_queue2' changed state to 4(PLAYING) successfully
0:00:00.224117208 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2479:gst_bin_element_set_state:<main_queue1> current PAUSED pending VOID_PENDING, desired next PLAYING
0:00:00.224144729 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2806:gst_element_continue_state:<main_queue1> completed state change to PLAYING
0:00:00.224163609 9259 0xaaaade61f400 INFO GST_STATES gstelement.c:2706:_priv_gst_element_state_changed:<main_queue1> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)
0:00:00.224188634 9259 0xaaaade61f400 INFO GST_STATES gstbin.c:2928:gst_bin_change_state_func:<main_pipe1> child 'main_queue1' changed state to 4(PLAYING) successfully
start main_pipe
0:00:00.225550659 9259 0xaaaade8b38c0 WARN v4l2bufferpool gstv4l2bufferpool.c:1114:gst_v4l2_buffer_pool_start:<main_enc1:pool:src> Uncertain or not enough buffers, enabling copy threshold
0:00:00.232365104 9259 0xaaaade8b38c0 INFO GST_EVENT gstevent.c:972: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 99:99:99.999999999, duration 99:99:99.999999999
usb is run in the system.
usb start open ok.
0:00:00.235174693 9259 0xaaaade8b38c0 INFO task gsttask.c:516:gst_task_set_lock: setting stream lock 0xaaaade97a920 on task 0xffff5c021cb0
0:00:00.235218982 9259 0xaaaade8b38c0 INFO GST_PADS gstpad.c:6291:gst_pad_start_task:<main_enc1:src> created task 0xffff5c021cb0
H264: Profile = 66, Level = 0
NVMEDIA: Need to set EMC bandwidth : 846000
0:00:00.257063959 9259 0xaaaadea18cc0 WARN v4l2bufferpool gstv4l2bufferpool.c:1565:gst_v4l2_buffer_pool_dqbuf:<main_enc1:pool:src> Driver should never set v4l2_buffer.field to ANY
0:00:00.257311071 9259 0xaaaadea18cc0 INFO GST_EVENT gstevent.c:972: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 99:99:99.999999999, duration 99:99:99.999999999
0:00:00.257579783 9259 0xaaaadea18cc0 INFO baseparse gstbaseparse.c:4088:gst_base_parse_set_latency:<main_parse1> min/max latency 0:00:00.000000000, 0:00:00.000000000
0:00:00.257691626 9259 0xaaaadea18cc0 INFO GST_EVENT gstevent.c:892:gst_event_new_caps: creating caps event video/x-h264, stream-format=(string)byte-stream, alignment=(string)au, profile=(string)constrained-baseline, level=(string)5, 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, chroma-format=(string)4:2:0, bit-depth-luma=(uint)8, bit-depth-chroma=(uint)8, parsed=(boolean)true
0:00:00.257769005 9259 0xaaaadea18cc0 INFO GST_EVENT gstevent.c:892:gst_event_new_caps: creating caps event video/x-h264, stream-format=(string)byte-stream, alignment=(string)au, profile=(string)constrained-baseline, level=(string)5, 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, chroma-format=(string)4:2:0, bit-depth-luma=(uint)8, bit-depth-chroma=(uint)8, parsed=(boolean)true
0:00:00.258107543 9259 0xaaaadea18cc0 INFO videometa gstvideometa.c:1072:gst_video_time_code_meta_api_get_type: registering
FOUND TAG : found by element main_sink1
video codec: H.264 (Constrained Baseline Profile)
0:00:00.497276627 9259 0xaaaade8b3d80 INFO GST_EVENT gstevent.c:892:gst_event_new_caps: creating caps event video/x-raw(memory:NVMM), width=(int)640, height=(int)360, format=(string)YUY2, interlace-mode=(string)progressive, framerate=(fraction)30/1
0:00:00.497456825 9259 0xaaaade8b3d80 INFO basetransform gstbasetransform.c:1325:gst_base_transform_setcaps:<main_caps3> reuse caps
0:00:00.497504698 9259 0xaaaade8b3d80 INFO GST_EVENT gstevent.c:892:gst_event_new_caps: creating caps event video/x-raw(memory:NVMM), width=(int)640, height=(int)360, format=(string)YUY2, interlace-mode=(string)progressive, framerate=(fraction)30/1
0:00:00.498056267 9259 0xaaaade8b3d80 INFO GST_EVENT gstevent.c:892:gst_event_new_caps: creating caps event video/x-raw(memory:NVMM), width=(int)1920, height=(int)1080, interlace-mode=(string)progressive, framerate=(fraction)30/1, format=(string)RGBA
0:00:00.498117453 9259 0xaaaade8b3d80 INFO basetransform gstbasetransform.c:1325:gst_base_transform_setcaps:<main_caps4> reuse caps
0:00:00.498145165 9259 0xaaaade8b3d80 INFO GST_EVENT gstevent.c:892:gst_event_new_caps: creating caps event video/x-raw(memory:NVMM), width=(int)1920, height=(int)1080, interlace-mode=(string)progressive, framerate=(fraction)30/1, format=(string)RGBA
0:00:00.498214224 9259 0xaaaade8b3d80 INFO basetransform gstbasetransform.c:1325:gst_base_transform_setcaps:<main_caps8> reuse caps
0:00:00.498246961 9259 0xaaaade8b3d80 INFO GST_EVENT gstevent.c:892:gst_event_new_caps: creating caps event video/x-raw(memory:NVMM), width=(int)1920, height=(int)1080, interlace-mode=(string)progressive, framerate=(fraction)30/1, format=(string)RGBA
0:00:00.709628297 9259 0xaaaade8b3de0 INFO GST_EVENT gstevent.c:892:gst_event_new_caps: creating caps event video/x-raw(memory:NVMM), width=(int)640, height=(int)360, format=(string)YUY2, interlace-mode=(string)progressive, framerate=(fraction)30/1
0:00:00.709825615 9259 0xaaaade8b3de0 INFO basetransform gstbasetransform.c:1325:gst_base_transform_setcaps:<main_caps1> reuse caps
0:00:00.709903569 9259 0xaaaade8b3de0 INFO GST_EVENT gstevent.c:892:gst_event_new_caps: creating caps event video/x-raw(memory:NVMM), width=(int)640, height=(int)360, format=(string)YUY2, interlace-mode=(string)progressive, framerate=(fraction)30/1
0:00:00.710836493 9259 0xaaaade8b3de0 INFO GST_EVENT gstevent.c:892:gst_event_new_caps: creating caps event video/x-raw(memory:NVMM), width=(int)1920, height=(int)1080, interlace-mode=(string)progressive, framerate=(fraction)30/1, format=(string)RGBA
0:00:00.710917840 9259 0xaaaade8b3de0 INFO basetransform gstbasetransform.c:1325:gst_base_transform_setcaps:<main_caps2> reuse caps
0:00:00.710953201 9259 0xaaaade8b3de0 INFO GST_EVENT gstevent.c:892:gst_event_new_caps: creating caps event video/x-raw(memory:NVMM), width=(int)1920, height=(int)1080, interlace-mode=(string)progressive, framerate=(fraction)30/1, format=(string)RGBA
0:00:00.711035827 9259 0xaaaade8b3de0 INFO basetransform gstbasetransform.c:1325:gst_base_transform_setcaps:<main_caps7> reuse caps
0:00:00.711078133 9259 0xaaaade8b3de0 INFO GST_EVENT gstevent.c:892:gst_event_new_caps: creating caps event video/x-raw(memory:NVMM), width=(int)1920, height=(int)1080, interlace-mode=(string)progressive, framerate=(fraction)30/1, format=(string)RGBA
0:00:00.711158839 9259 0xaaaade8b3de0 INFO basetransform gstbasetransform.c:1325:gst_base_transform_setcaps:<main_sony_mp4_caps2> reuse caps
0:00:00.711188568 9259 0xaaaade8b3de0 INFO GST_EVENT gstevent.c:892:gst_event_new_caps: creating caps event video/x-raw(memory:NVMM), width=(int)1920, height=(int)1080, interlace-mode=(string)progressive, framerate=(fraction)30/1, format=(string)RGBA
0:00:00.711489633 9259 0xaaaade8b3de0 INFO GST_EVENT gstevent.c:892:gst_event_new_caps: creating caps event video/x-raw(memory:NVMM), width=(int)1920, height=(int)1080, interlace-mode=(string)progressive, framerate=(fraction)30/1, format=(string)NV12
0:00:00.711604580 9259 0xaaaade8b3de0 INFO basetransform gstbasetransform.c:1325:gst_base_transform_setcaps:<main_sony_mp4_caps1> reuse caps
0:00:00.711639429 9259 0xaaaade8b3de0 INFO GST_EVENT gstevent.c:892:gst_event_new_caps: creating caps event video/x-raw(memory:NVMM), width=(int)1920, height=(int)1080, interlace-mode=(string)progressive, framerate=(fraction)30/1, format=(string)NV12
0:00:00.711907566 9259 0xaaaade8b3de0 INFO GST_EVENT gstevent.c:892:gst_event_new_caps: creating caps event video/x-h264, stream-format=(string)byte-stream, alignment=(string)au, profile=(string)NULL, level=(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:00.712014449 9259 0xaaaade8b3de0 INFO GST_EVENT gstevent.c:892:gst_event_new_caps: creating caps event video/x-h264, stream-format=(string)byte-stream, alignment=(string)au, profile=(string)NULL, level=(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, parsed=(boolean)true
0:00:00.712057202 9259 0xaaaade8b3de0 INFO GST_EVENT gstevent.c:892:gst_event_new_caps: creating caps event video/x-h264, stream-format=(string)byte-stream, alignment=(string)au, profile=(string)NULL, level=(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, parsed=(boolean)true
0:00:00.712135924 9259 0xaaaade8b3de0 INFO v4l2 gstv4l2object.c:3211:gst_v4l2_object_setup_pool:<main_sony_mp4_enc1:src> accessing buffers via mode 2
0:00:00.712246168 9259 0xaaaade8b3de0 INFO v4l2bufferpool gstv4l2bufferpool.c:827:gst_v4l2_buffer_pool_set_config:<main_sony_mp4_enc1:pool:src> increasing minimum buffers to 2
0:00:00.712264184 9259 0xaaaade8b3de0 INFO v4l2bufferpool gstv4l2bufferpool.c:841:gst_v4l2_buffer_pool_set_config:<main_sony_mp4_enc1:pool:src> reducing maximum buffers to 64
0:00:00.712276121 9259 0xaaaade8b3de0 INFO v4l2bufferpool gstv4l2bufferpool.c:859:gst_v4l2_buffer_pool_set_config:<main_sony_mp4_enc1:pool:src> can't allocate, setting maximum to minimum
0:00:00.712311002 9259 0xaaaade8b3de0 INFO v4l2bufferpool gstv4l2bufferpool.c:841:gst_v4l2_buffer_pool_set_config:<main_sony_mp4_enc1:pool:src> reducing maximum buffers to 64
0:00:00.712322682 9259 0xaaaade8b3de0 INFO v4l2bufferpool gstv4l2bufferpool.c:859:gst_v4l2_buffer_pool_set_config:<main_sony_mp4_enc1:pool:src> can't allocate, setting maximum to minimum
NvMMLiteOpen : Block : BlockType = 4
===== NvVideo: NVENC =====
NvMMLiteBlockCreate : Block : BlockType = 4
0:00:00.713723940 9259 0xaaaade8b3de0 INFO v4l2 gstv4l2object.c:4185:gst_v4l2_object_set_format_full:<main_sony_mp4_enc1:sink> Set output framerate to 30/1
0:00:00.713754853 9259 0xaaaade8b3de0 INFO v4l2 gstv4l2object.c:3211:gst_v4l2_object_setup_pool:<main_sony_mp4_enc1:sink> accessing buffers via mode 5
0:00:00.713860392 9259 0xaaaade8b3de0 INFO v4l2bufferpool gstv4l2bufferpool.c:827:gst_v4l2_buffer_pool_set_config:<main_sony_mp4_enc1:pool:sink> increasing minimum buffers to 2
0:00:00.713878345 9259 0xaaaade8b3de0 INFO v4l2bufferpool gstv4l2bufferpool.c:834:gst_v4l2_buffer_pool_set_config:<main_sony_mp4_enc1:pool:sink> increasing minimum buffers to 4
0:00:00.713889641 9259 0xaaaade8b3de0 INFO v4l2bufferpool gstv4l2bufferpool.c:841:gst_v4l2_buffer_pool_set_config:<main_sony_mp4_enc1:pool:sink> reducing maximum buffers to 64
0:00:00.713899113 9259 0xaaaade8b3de0 INFO v4l2bufferpool gstv4l2bufferpool.c:859:gst_v4l2_buffer_pool_set_config:<main_sony_mp4_enc1:pool:sink> can't allocate, setting maximum to minimum
0:00:00.713908426 9259 0xaaaade8b3de0 INFO v4l2bufferpool gstv4l2bufferpool.c:864:gst_v4l2_buffer_pool_set_config:<main_sony_mp4_enc1:pool:sink> adding needed video meta
0:00:00.717318448 9259 0xaaaade8b3de0 WARN v4l2bufferpool gstv4l2bufferpool.c:1114:gst_v4l2_buffer_pool_start:<main_sony_mp4_enc1:pool:src> Uncertain or not enough buffers, enabling copy threshold