Hi,
I am just got a SOM-RK3399v2 Dev Kit and install the friendlycore-bionic-4.4-arm64-20200623. When I use the HDMI-IN with rkisp as input I found that it'll hang in gstreamer restarting.
Here is my gstreamer pipeline:
"rkisp device=/dev/video0 io-mode=1 ! capsfilter caps=\"video/x-raw,format=NV12,video/x-raw,format=NV12,framerate=30/1,width=1920,height=1080\" ! appsink"
And here is the stack trace of relative thread:
Log:
0:00:38.829919919 [334m 5601[00m 0x7fa0012520 [37mDEBUG [00m [00m appsink gstappsink.c:821:dequeue_buffer:<appsink0>[00m dequeued buffer/list 0x7fa8016680
0:00:38.829933335 [334m 5601[00m 0x7fa0012520 [37mDEBUG [00m [00m appsink gstappsink.c:1654:gst_app_sink_try_pull_sample:<appsink0>[00m we have a buffer 0x7fa8016680
0:00:38.833251130 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesink gstbasesink.c:3577:gst_base_sink_chain_unlocked:<appsink0>[00m object unref after render 0x7fa8016680
0:00:38.833504585 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;35m GST_SCHEDULING gstpad.c:4326:gst_pad_chain_data_unchecked:<appsink0:sink>[00m called chainfunction &gst_base_sink_chain with buffer 0x7fa8016680, returned ok
0:00:38.833754832 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;35m GST_SCHEDULING gstpad.c:4326:gst_pad_chain_data_unchecked:<capsfilter0:sink>[00m called chainfunction &gst_base_transform_chain with buffer 0x7fa8016680, returned ok
0:00:38.833905039 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesrc gstbasesrc.c:2506:gst_base_src_get_range:<xcamsrc0>[00m calling create offset 18446744073709551615 length 4096, time 0
0:00:38.835273106 [334m 5601[00m 0x7fa0012520 [37mDEBUG [00m [00m appsink gstappsink.c:1146:gst_app_sink_is_eos:<appsink0>[00m we are not yet EOS
0:00:38.835331147 [334m 5601[00m 0x7fa0012520 [37mDEBUG [00m [00m appsink gstappsink.c:1630:gst_app_sink_try_pull_sample:<appsink0>[00m trying to grab a buffer
0:00:38.835342813 [334m 5601[00m 0x7fa0012520 [37mDEBUG [00m [00m appsink gstappsink.c:1641:gst_app_sink_try_pull_sample:<appsink0>[00m waiting for a buffer
0:00:38.838304070 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;34m GST_MEMORY gstmemory.c:139:gst_memory_init:[00m new memory 0x7fa8314f30, maxsize:3110407 offset:0 size:3110400
0:00:38.845948856 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;33m GST_CLOCK gstclock.c:1046:gst_clock_get_internal_time:<GstSystemClock>[00m internal time 7:39:42.353344591
0:00:38.845974814 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;33m GST_CLOCK gstclock.c:1091:gst_clock_get_time:<GstSystemClock>[00m adjusted time 7:39:42.353344591
0:00:38.845989105 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesrc gstbasesrc.c:2360:gst_base_src_do_sync:<xcamsrc0>[00m no sync needed
0:00:38.846003105 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesrc gstbasesrc.c:2597:gst_base_src_get_range:<xcamsrc0>[00m buffer ok
0:00:38.846035188 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;35m GST_SCHEDULING gstpad.c:4320:gst_pad_chain_data_unchecked:<capsfilter0:sink>[00m calling chainfunction &gst_base_transform_chain with buffer buffer: 0x7fa8016ce0, pts 0:00:38.435625339, dts 0:00:38.435625339, dur 99:99:99.999999999, size 3110400, offset 2303, offset_end 2304, flags 0x0
0:00:38.846058813 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basetransform gstbasetransform.c:1985:default_submit_input_buffer:<capsfilter0>[00m handling buffer 0x7fa8016ce0 of size 3110400, PTS 0:00:38.435625339 and offset 2303
0:00:38.846072812 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basetransform gstbasetransform.c:2102:default_generate_output:<capsfilter0>[00m calling prepare buffer
0:00:38.846087687 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basetransform gstbasetransform.c:2109:default_generate_output:<capsfilter0>[00m using allocated buffer in 0x7fa8016ce0, out 0x7fa8016ce0
0:00:38.846099354 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basetransform gstbasetransform.c:2126:default_generate_output:<capsfilter0>[00m doing inplace transform
0:00:38.846122687 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;35m GST_SCHEDULING gstpad.c:4320:gst_pad_chain_data_unchecked:<appsink0:sink>[00m calling chainfunction &gst_base_sink_chain with buffer buffer: 0x7fa8016ce0, pts 0:00:38.435625339, dts 0:00:38.435625339, dur 99:99:99.999999999, size 3110400, offset 2303, offset_end 2304, flags 0x0
0:00:38.846147770 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesink gstbasesink.c:3421:gst_base_sink_chain_unlocked:<appsink0>[00m got times start: 0:00:38.435625339, end: 99:99:99.999999999
0:00:38.846170228 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesink gstbasesink.c:2006:gst_base_sink_get_sync_times:<appsink0>[00m got times start: 0:00:38.435625339, stop: 99:99:99.999999999, do_sync 1
0:00:38.846181895 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;04m default gstsegment.c:737:gst_segment_to_running_time_full:[00m invalid position (-1)
0:00:38.846201728 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesink gstbasesink.c:2591:gst_base_sink_do_sync:<appsink0>[00m reset rc_time to time 0:00:38.435625339
0:00:38.846220686 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesink gstbasesink.c:2603:gst_base_sink_do_sync:<appsink0>[00m possibly waiting for clock to reach 0:00:38.435625339, adjusted 0:00:38.435625339
0:00:38.846235269 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;33m GST_CLOCK gstclock.c:537:gst_clock_id_wait:<GstSystemClock>[00m waiting on clock entry 0x7fa8006480
0:00:38.846252769 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;33m GST_CLOCK gstclock.c:1046:gst_clock_get_internal_time:<GstSystemClock>[00m internal time 7:39:42.353653754
0:00:38.846268227 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;33m GST_CLOCK gstclock.c:1091:gst_clock_get_time:<GstSystemClock>[00m adjusted time 7:39:42.353653754
0:00:38.846302351 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;33m GST_CLOCK gstsystemclock.c:719:gst_system_clock_id_wait_jitter_unlocked:[00m entry 0x7fa8006480 time 7:39:42.353344591 now 7:39:42.353653754 diff (time-now) -309163
0:00:38.846319268 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;33m GST_CLOCK gstclock.c:547:gst_clock_id_wait:<GstSystemClock>[00m done waiting entry 0x7fa8006480, res: 1 (early)
0:00:38.846337351 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesink gstbasesink.c:2610:gst_base_sink_do_sync:<appsink0>[00m clock returned 1, jitter 0:00:00.000309163
0:00:38.846349018 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesink gstbasesink.c:2926:gst_base_sink_is_too_late:<appsink0>[00m frame dropping disabled
0:00:38.846361851 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesink gstbasesink.c:3538:gst_base_sink_chain_unlocked:<appsink0>[00m rendering object 0x7fa8016ce0
0:00:38.846374684 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesink gstbasesink.c:994:gst_base_sink_set_last_buffer_unlocked:<appsink0>[00m setting last buffer to 0x7fa8016ce0
0:00:38.846390434 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;34m GST_MEMORY gstmemory.c:88:_gst_memory_free:[00m free memory 0x7fa801d700
0:00:38.846409975 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m appsink gstappsink.c:876:gst_app_sink_render_common:<appsink0>[00m pushing render buffer/list 0x7fa8016ce0 on queue (0)
0:00:38.846456350 [334m 5601[00m 0x7fa0012520 [37mDEBUG [00m [00m appsink gstappsink.c:1630:gst_app_sink_try_pull_sample:<appsink0>[00m trying to grab a buffer
0:00:38.846474433 [334m 5601[00m 0x7fa0012520 [37mDEBUG [00m [00m appsink gstappsink.c:821:dequeue_buffer:<appsink0>[00m dequeued buffer/list 0x7fa8016ce0
0:00:38.846487558 [334m 5601[00m 0x7fa0012520 [37mDEBUG [00m [00m appsink gstappsink.c:1654:gst_app_sink_try_pull_sample:<appsink0>[00m we have a buffer 0x7fa8016ce0
0:00:38.847173091 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesink gstbasesink.c:3577:gst_base_sink_chain_unlocked:<appsink0>[00m object unref after render 0x7fa8016ce0
0:00:38.847373172 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;35m GST_SCHEDULING gstpad.c:4326:gst_pad_chain_data_unchecked:<appsink0:sink>[00m called chainfunction &gst_base_sink_chain with buffer 0x7fa8016ce0, returned ok
0:00:38.847494212 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;35m GST_SCHEDULING gstpad.c:4326:gst_pad_chain_data_unchecked:<capsfilter0:sink>[00m called chainfunction &gst_base_transform_chain with buffer 0x7fa8016ce0, returned ok
0:00:38.847703918 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesrc gstbasesrc.c:2506:gst_base_src_get_range:<xcamsrc0>[00m calling create offset 18446744073709551615 length 4096, time 0
0:00:38.851831703 [334m 5601[00m 0x7fa0012520 [37mDEBUG [00m [00m appsink gstappsink.c:1146:gst_app_sink_is_eos:<appsink0>[00m we are not yet EOS
0:00:38.851881869 [334m 5601[00m 0x7fa0012520 [37mDEBUG [00m [00m appsink gstappsink.c:1630:gst_app_sink_try_pull_sample:<appsink0>[00m trying to grab a buffer
0:00:38.851893827 [334m 5601[00m 0x7fa0012520 [37mDEBUG [00m [00m appsink gstappsink.c:1641:gst_app_sink_try_pull_sample:<appsink0>[00m waiting for a buffer
0:00:38.854970000 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;34m GST_MEMORY gstmemory.c:139:gst_memory_init:[00m new memory 0x7fa801d700, maxsize:3110407 offset:0 size:3110400
0:00:38.862231539 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;33m GST_CLOCK gstclock.c:1046:gst_clock_get_internal_time:<GstSystemClock>[00m internal time 7:39:42.369628150
0:00:38.862280830 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;33m GST_CLOCK gstclock.c:1091:gst_clock_get_time:<GstSystemClock>[00m adjusted time 7:39:42.369628150
0:00:38.862295997 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesrc gstbasesrc.c:2360:gst_base_src_do_sync:<xcamsrc0>[00m no sync needed
0:00:38.862309705 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesrc gstbasesrc.c:2597:gst_base_src_get_range:<xcamsrc0>[00m buffer ok
0:00:38.862342663 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;35m GST_SCHEDULING gstpad.c:4320:gst_pad_chain_data_unchecked:<capsfilter0:sink>[00m calling chainfunction &gst_base_transform_chain with buffer buffer: 0x7fa8016680, pts 0:00:38.451908898, dts 0:00:38.451908898, dur 99:99:99.999999999, size 3110400, offset 2304, offset_end 2305, flags 0x0
0:00:38.862365996 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basetransform gstbasetransform.c:1985:default_submit_input_buffer:<capsfilter0>[00m handling buffer 0x7fa8016680 of size 3110400, PTS 0:00:38.451908898 and offset 2304
0:00:38.862379996 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basetransform gstbasetransform.c:2102:default_generate_output:<capsfilter0>[00m calling prepare buffer
0:00:38.862394871 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basetransform gstbasetransform.c:2109:default_generate_output:<capsfilter0>[00m using allocated buffer in 0x7fa8016680, out 0x7fa8016680
0:00:38.862406537 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basetransform gstbasetransform.c:2126:default_generate_output:<capsfilter0>[00m doing inplace transform
0:00:38.862429870 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;35m GST_SCHEDULING gstpad.c:4320:gst_pad_chain_data_unchecked:<appsink0:sink>[00m calling chainfunction &gst_base_sink_chain with buffer buffer: 0x7fa8016680, pts 0:00:38.451908898, dts 0:00:38.451908898, dur 99:99:99.999999999, size 3110400, offset 2304, offset_end 2305, flags 0x0
0:00:38.862454078 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesink gstbasesink.c:3421:gst_base_sink_chain_unlocked:<appsink0>[00m got times start: 0:00:38.451908898, end: 99:99:99.999999999
0:00:38.862476537 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesink gstbasesink.c:2006:gst_base_sink_get_sync_times:<appsink0>[00m got times start: 0:00:38.451908898, stop: 99:99:99.999999999, do_sync 1
0:00:38.862488203 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;04m default gstsegment.c:737:gst_segment_to_running_time_full:[00m invalid position (-1)
0:00:38.862507161 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesink gstbasesink.c:2591:gst_base_sink_do_sync:<appsink0>[00m reset rc_time to time 0:00:38.451908898
0:00:38.862526411 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesink gstbasesink.c:2603:gst_base_sink_do_sync:<appsink0>[00m possibly waiting for clock to reach 0:00:38.451908898, adjusted 0:00:38.451908898
0:00:38.862540994 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;33m GST_CLOCK gstclock.c:537:gst_clock_id_wait:<GstSystemClock>[00m waiting on clock entry 0x7fa8006480
0:00:38.862558202 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;33m GST_CLOCK gstclock.c:1046:gst_clock_get_internal_time:<GstSystemClock>[00m internal time 7:39:42.369959479
0:00:38.862573952 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;33m GST_CLOCK gstclock.c:1091:gst_clock_get_time:<GstSystemClock>[00m adjusted time 7:39:42.369959479
0:00:38.862602827 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;33m GST_CLOCK gstsystemclock.c:719:gst_system_clock_id_wait_jitter_unlocked:[00m entry 0x7fa8006480 time 7:39:42.369628150 now 7:39:42.369959479 diff (time-now) -331329
0:00:38.862620910 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;33m GST_CLOCK gstclock.c:547:gst_clock_id_wait:<GstSystemClock>[00m done waiting entry 0x7fa8006480, res: 1 (early)
0:00:38.862647160 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesink gstbasesink.c:2610:gst_base_sink_do_sync:<appsink0>[00m clock returned 1, jitter 0:00:00.000331329
0:00:38.862659701 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesink gstbasesink.c:2926:gst_base_sink_is_too_late:<appsink0>[00m frame dropping disabled
0:00:38.862671951 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesink gstbasesink.c:3538:gst_base_sink_chain_unlocked:<appsink0>[00m rendering object 0x7fa8016680
0:00:38.862685076 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesink gstbasesink.c:994:gst_base_sink_set_last_buffer_unlocked:<appsink0>[00m setting last buffer to 0x7fa8016680
0:00:38.862700826 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;34m GST_MEMORY gstmemory.c:88:_gst_memory_free:[00m free memory 0x7fa8314f30
0:00:38.862719492 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m appsink gstappsink.c:876:gst_app_sink_render_common:<appsink0>[00m pushing render buffer/list 0x7fa8016680 on queue (0)
0:00:38.862762658 [334m 5601[00m 0x7fa0012520 [37mDEBUG [00m [00m appsink gstappsink.c:1630:gst_app_sink_try_pull_sample:<appsink0>[00m trying to grab a buffer
0:00:38.862779283 [334m 5601[00m 0x7fa0012520 [37mDEBUG [00m [00m appsink gstappsink.c:821:dequeue_buffer:<appsink0>[00m dequeued buffer/list 0x7fa8016680
0:00:38.862792699 [334m 5601[00m 0x7fa0012520 [37mDEBUG [00m [00m appsink gstappsink.c:1654:gst_app_sink_try_pull_sample:<appsink0>[00m we have a buffer 0x7fa8016680
0:00:38.864135059 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesink gstbasesink.c:3577:gst_base_sink_chain_unlocked:<appsink0>[00m object unref after render 0x7fa8016680
0:00:38.864350306 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;35m GST_SCHEDULING gstpad.c:4326:gst_pad_chain_data_unchecked:<appsink0:sink>[00m called chainfunction &gst_base_sink_chain with buffer 0x7fa8016680, returned ok
0:00:38.864476013 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;35m GST_SCHEDULING gstpad.c:4326:gst_pad_chain_data_unchecked:<capsfilter0:sink>[00m called chainfunction &gst_base_transform_chain with buffer 0x7fa8016680, returned ok
0:00:38.864673761 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesrc gstbasesrc.c:2506:gst_base_src_get_range:<xcamsrc0>[00m calling create offset 18446744073709551615 length 4096, time 0
0:00:38.868128095 [334m 5601[00m 0x7fa0012520 [37mDEBUG [00m [00m appsink gstappsink.c:1146:gst_app_sink_is_eos:<appsink0>[00m we are not yet EOS
0:00:38.868186136 [334m 5601[00m 0x7fa0012520 [37mDEBUG [00m [00m appsink gstappsink.c:1630:gst_app_sink_try_pull_sample:<appsink0>[00m trying to grab a buffer
0:00:38.868197803 [334m 5601[00m 0x7fa0012520 [37mDEBUG [00m [00m appsink gstappsink.c:1641:gst_app_sink_try_pull_sample:<appsink0>[00m waiting for a buffer
0:00:38.871669470 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;34m GST_MEMORY gstmemory.c:139:gst_memory_init:[00m new memory 0x7fa8314f30, maxsize:3110407 offset:0 size:3110400
0:00:38.879280714 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;33m GST_CLOCK gstclock.c:1046:gst_clock_get_internal_time:<GstSystemClock>[00m internal time 7:39:42.386678491
0:00:38.879305214 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;33m GST_CLOCK gstclock.c:1091:gst_clock_get_time:<GstSystemClock>[00m adjusted time 7:39:42.386678491
0:00:38.879320089 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesrc gstbasesrc.c:2360:gst_base_src_do_sync:<xcamsrc0>[00m no sync needed
0:00:38.879333505 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesrc gstbasesrc.c:2597:gst_base_src_get_range:<xcamsrc0>[00m buffer ok
0:00:38.879392421 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;35m GST_SCHEDULING gstpad.c:4320:gst_pad_chain_data_unchecked:<capsfilter0:sink>[00m calling chainfunction &gst_base_transform_chain with buffer buffer: 0x7fa8016df0, pts 0:00:38.468959239, dts 0:00:38.468959239, dur 99:99:99.999999999, size 3110400, offset 2305, offset_end 2306, flags 0x0
0:00:38.879416338 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basetransform gstbasetransform.c:1985:default_submit_input_buffer:<capsfilter0>[00m handling buffer 0x7fa8016df0 of size 3110400, PTS 0:00:38.468959239 and offset 2305
0:00:38.879430629 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basetransform gstbasetransform.c:2102:default_generate_output:<capsfilter0>[00m calling prepare buffer
0:00:38.879445504 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basetransform gstbasetransform.c:2109:default_generate_output:<capsfilter0>[00m using allocated buffer in 0x7fa8016df0, out 0x7fa8016df0
0:00:38.879457170 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basetransform gstbasetransform.c:2126:default_generate_output:<capsfilter0>[00m doing inplace transform
0:00:38.879480504 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;35m GST_SCHEDULING gstpad.c:4320:gst_pad_chain_data_unchecked:<appsink0:sink>[00m calling chainfunction &gst_base_sink_chain with buffer buffer: 0x7fa8016df0, pts 0:00:38.468959239, dts 0:00:38.468959239, dur 99:99:99.999999999, size 3110400, offset 2305, offset_end 2306, flags 0x0
0:00:38.879505878 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesink gstbasesink.c:3421:gst_base_sink_chain_unlocked:<appsink0>[00m got times start: 0:00:38.468959239, end: 99:99:99.999999999
0:00:38.879528336 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesink gstbasesink.c:2006:gst_base_sink_get_sync_times:<appsink0>[00m got times start: 0:00:38.468959239, stop: 99:99:99.999999999, do_sync 1
0:00:38.879540003 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;04m default gstsegment.c:737:gst_segment_to_running_time_full:[00m invalid position (-1)
0:00:38.879560128 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesink gstbasesink.c:2591:gst_base_sink_do_sync:<appsink0>[00m reset rc_time to time 0:00:38.468959239
0:00:38.879579377 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesink gstbasesink.c:2603:gst_base_sink_do_sync:<appsink0>[00m possibly waiting for clock to reach 0:00:38.468959239, adjusted 0:00:38.468959239
0:00:38.879604460 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;33m GST_CLOCK gstclock.c:537:gst_clock_id_wait:<GstSystemClock>[00m waiting on clock entry 0x7fa8006480
0:00:38.879624585 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;33m GST_CLOCK gstclock.c:1046:gst_clock_get_internal_time:<GstSystemClock>[00m internal time 7:39:42.387025279
0:00:38.879640335 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;33m GST_CLOCK gstclock.c:1091:gst_clock_get_time:<GstSystemClock>[00m adjusted time 7:39:42.387025279
0:00:38.879660751 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;33m GST_CLOCK gstsystemclock.c:719:gst_system_clock_id_wait_jitter_unlocked:[00m entry 0x7fa8006480 time 7:39:42.386678491 now 7:39:42.387025279 diff (time-now) -346788
0:00:38.879676501 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;33m GST_CLOCK gstclock.c:547:gst_clock_id_wait:<GstSystemClock>[00m done waiting entry 0x7fa8006480, res: 1 (early)
0:00:38.879694876 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesink gstbasesink.c:2610:gst_base_sink_do_sync:<appsink0>[00m clock returned 1, jitter 0:00:00.000346788
0:00:38.879706543 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesink gstbasesink.c:2926:gst_base_sink_is_too_late:<appsink0>[00m frame dropping disabled
0:00:38.879727542 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesink gstbasesink.c:3538:gst_base_sink_chain_unlocked:<appsink0>[00m rendering object 0x7fa8016df0
0:00:38.879741542 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesink gstbasesink.c:994:gst_base_sink_set_last_buffer_unlocked:<appsink0>[00m setting last buffer to 0x7fa8016df0
0:00:38.879757584 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;34m GST_MEMORY gstmemory.c:88:_gst_memory_free:[00m free memory 0x7fa801d700
0:00:38.879776833 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m appsink gstappsink.c:876:gst_app_sink_render_common:<appsink0>[00m pushing render buffer/list 0x7fa8016df0 on queue (0)
0:00:38.879822041 [334m 5601[00m 0x7fa0012520 [37mDEBUG [00m [00m appsink gstappsink.c:1630:gst_app_sink_try_pull_sample:<appsink0>[00m trying to grab a buffer
0:00:38.879838666 [334m 5601[00m 0x7fa0012520 [37mDEBUG [00m [00m appsink gstappsink.c:821:dequeue_buffer:<appsink0>[00m dequeued buffer/list 0x7fa8016df0
0:00:38.879851791 [334m 5601[00m 0x7fa0012520 [37mDEBUG [00m [00m appsink gstappsink.c:1654:gst_app_sink_try_pull_sample:<appsink0>[00m we have a buffer 0x7fa8016df0
0:00:38.881221858 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesink gstbasesink.c:3577:gst_base_sink_chain_unlocked:<appsink0>[00m object unref after render 0x7fa8016df0
0:00:38.881454897 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;35m GST_SCHEDULING gstpad.c:4326:gst_pad_chain_data_unchecked:<appsink0:sink>[00m called chainfunction &gst_base_sink_chain with buffer 0x7fa8016df0, returned ok
0:00:38.881585854 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;35m GST_SCHEDULING gstpad.c:4326:gst_pad_chain_data_unchecked:<capsfilter0:sink>[00m called chainfunction &gst_base_transform_chain with buffer 0x7fa8016df0, returned ok
0:00:38.882059223 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesrc gstbasesrc.c:2506:gst_base_src_get_range:<xcamsrc0>[00m calling create offset 18446744073709551615 length 4096, time 0
0:00:38.885299185 [334m 5601[00m 0x7fa0012520 [37mDEBUG [00m [00m appsink gstappsink.c:1146:gst_app_sink_is_eos:<appsink0>[00m we are not yet EOS
0:00:38.885357810 [334m 5601[00m 0x7fa0012520 [37mDEBUG [00m [00m appsink gstappsink.c:1630:gst_app_sink_try_pull_sample:<appsink0>[00m trying to grab a buffer
0:00:38.885369476 [334m 5601[00m 0x7fa0012520 [37mDEBUG [00m [00m appsink gstappsink.c:1641:gst_app_sink_try_pull_sample:<appsink0>[00m waiting for a buffer
0:00:38.888152818 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;34m GST_MEMORY gstmemory.c:139:gst_memory_init:[00m new memory 0x7fa801d700, maxsize:3110407 offset:0 size:3110400
0:00:38.895581481 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;33m GST_CLOCK gstclock.c:1046:gst_clock_get_internal_time:<GstSystemClock>[00m internal time 7:39:42.402977508
0:00:38.895613856 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;33m GST_CLOCK gstclock.c:1091:gst_clock_get_time:<GstSystemClock>[00m adjusted time 7:39:42.402977508
0:00:38.895629897 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesrc gstbasesrc.c:2360:gst_base_src_do_sync:<xcamsrc0>[00m no sync needed
0:00:38.895643605 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesrc gstbasesrc.c:2597:gst_base_src_get_range:<xcamsrc0>[00m buffer ok
0:00:38.895676272 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;35m GST_SCHEDULING gstpad.c:4320:gst_pad_chain_data_unchecked:<capsfilter0:sink>[00m calling chainfunction &gst_base_transform_chain with buffer buffer: 0x7fa8016790, pts 0:00:38.485258256, dts 0:00:38.485258256, dur 99:99:99.999999999, size 3110400, offset 2306, offset_end 2307, flags 0x0
0:00:38.895699313 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basetransform gstbasetransform.c:1985:default_submit_input_buffer:<capsfilter0>[00m handling buffer 0x7fa8016790 of size 3110400, PTS 0:00:38.485258256 and offset 2306
0:00:38.895736646 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basetransform gstbasetransform.c:2102:default_generate_output:<capsfilter0>[00m calling prepare buffer
0:00:38.895752396 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basetransform gstbasetransform.c:2109:default_generate_output:<capsfilter0>[00m using allocated buffer in 0x7fa8016790, out 0x7fa8016790
0:00:38.895764354 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basetransform gstbasetransform.c:2126:default_generate_output:<capsfilter0>[00m doing inplace transform
0:00:38.895788270 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;35m GST_SCHEDULING gstpad.c:4320:gst_pad_chain_data_unchecked:<appsink0:sink>[00m calling chainfunction &gst_base_sink_chain with buffer buffer: 0x7fa8016790, pts 0:00:38.485258256, dts 0:00:38.485258256, dur 99:99:99.999999999, size 3110400, offset 2306, offset_end 2307, flags 0x0
0:00:38.895812478 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesink gstbasesink.c:3421:gst_base_sink_chain_unlocked:<appsink0>[00m got times start: 0:00:38.485258256, end: 99:99:99.999999999
0:00:38.895835520 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesink gstbasesink.c:2006:gst_base_sink_get_sync_times:<appsink0>[00m got times start: 0:00:38.485258256, stop: 99:99:99.999999999, do_sync 1
0:00:38.895846895 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;04m default gstsegment.c:737:gst_segment_to_running_time_full:[00m invalid position (-1)
0:00:38.895866436 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesink gstbasesink.c:2591:gst_base_sink_do_sync:<appsink0>[00m reset rc_time to time 0:00:38.485258256
0:00:38.895885686 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesink gstbasesink.c:2603:gst_base_sink_do_sync:<appsink0>[00m possibly waiting for clock to reach 0:00:38.485258256, adjusted 0:00:38.485258256
0:00:38.895899977 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;33m GST_CLOCK gstclock.c:537:gst_clock_id_wait:<GstSystemClock>[00m waiting on clock entry 0x7fa8006480
0:00:38.895916894 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;33m GST_CLOCK gstclock.c:1046:gst_clock_get_internal_time:<GstSystemClock>[00m internal time 7:39:42.403318462
0:00:38.895932352 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;33m GST_CLOCK gstclock.c:1091:gst_clock_get_time:<GstSystemClock>[00m adjusted time 7:39:42.403318462
0:00:38.895952477 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;33m GST_CLOCK gstsystemclock.c:719:gst_system_clock_id_wait_jitter_unlocked:[00m entry 0x7fa8006480 time 7:39:42.402977508 now 7:39:42.403318462 diff (time-now) -340954
0:00:38.895968518 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;33m GST_CLOCK gstclock.c:547:gst_clock_id_wait:<GstSystemClock>[00m done waiting entry 0x7fa8006480, res: 1 (early)
0:00:38.895986601 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesink gstbasesink.c:2610:gst_base_sink_do_sync:<appsink0>[00m clock returned 1, jitter 0:00:00.000340954
0:00:38.895998268 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesink gstbasesink.c:2926:gst_base_sink_is_too_late:<appsink0>[00m frame dropping disabled
0:00:38.896010809 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesink gstbasesink.c:3538:gst_base_sink_chain_unlocked:<appsink0>[00m rendering object 0x7fa8016790
0:00:38.896023643 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesink gstbasesink.c:994:gst_base_sink_set_last_buffer_unlocked:<appsink0>[00m setting last buffer to 0x7fa8016790
0:00:38.896038809 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;34m GST_MEMORY gstmemory.c:88:_gst_memory_free:[00m free memory 0x7fa8314f30
0:00:38.896065350 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m appsink gstappsink.c:876:gst_app_sink_render_common:<appsink0>[00m pushing render buffer/list 0x7fa8016790 on queue (0)
0:00:38.896111433 [334m 5601[00m 0x7fa0012520 [37mDEBUG [00m [00m appsink gstappsink.c:1630:gst_app_sink_try_pull_sample:<appsink0>[00m trying to grab a buffer
0:00:38.896128933 [334m 5601[00m 0x7fa0012520 [37mDEBUG [00m [00m appsink gstappsink.c:821:dequeue_buffer:<appsink0>[00m dequeued buffer/list 0x7fa8016790
0:00:38.896142350 [334m 5601[00m 0x7fa0012520 [37mDEBUG [00m [00m appsink gstappsink.c:1654:gst_app_sink_try_pull_sample:<appsink0>[00m we have a buffer 0x7fa8016790
0:00:38.897057172 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesink gstbasesink.c:3577:gst_base_sink_chain_unlocked:<appsink0>[00m object unref after render 0x7fa8016790
0:00:38.897174421 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;35m GST_SCHEDULING gstpad.c:4326:gst_pad_chain_data_unchecked:<appsink0:sink>[00m called chainfunction &gst_base_sink_chain with buffer 0x7fa8016790, returned ok
0:00:38.897228670 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;35m GST_SCHEDULING gstpad.c:4326:gst_pad_chain_data_unchecked:<capsfilter0:sink>[00m called chainfunction &gst_base_transform_chain with buffer 0x7fa8016790, returned ok
0:00:38.897283211 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesrc gstbasesrc.c:2506:gst_base_src_get_range:<xcamsrc0>[00m calling create offset 18446744073709551615 length 4096, time 0
0:00:38.901468995 [334m 5601[00m 0x7fa0012520 [37mDEBUG [00m [00m appsink gstappsink.c:1146:gst_app_sink_is_eos:<appsink0>[00m we are not yet EOS
0:00:38.901523828 [334m 5601[00m 0x7fa0012520 [37mDEBUG [00m [00m appsink gstappsink.c:1630:gst_app_sink_try_pull_sample:<appsink0>[00m trying to grab a buffer
0:00:38.901535203 [334m 5601[00m 0x7fa0012520 [37mDEBUG [00m [00m appsink gstappsink.c:1641:gst_app_sink_try_pull_sample:<appsink0>[00m waiting for a buffer
0:00:38.904928705 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;34m GST_MEMORY gstmemory.c:139:gst_memory_init:[00m new memory 0x7fa8314f30, maxsize:3110407 offset:0 size:3110400
0:00:38.912152912 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;33m GST_CLOCK gstclock.c:1046:gst_clock_get_internal_time:<GstSystemClock>[00m internal time 7:39:42.419548938
0:00:38.912177703 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;33m GST_CLOCK gstclock.c:1091:gst_clock_get_time:<GstSystemClock>[00m adjusted time 7:39:42.419548938
0:00:38.912192578 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesrc gstbasesrc.c:2360:gst_base_src_do_sync:<xcamsrc0>[00m no sync needed
0:00:38.912206286 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesrc gstbasesrc.c:2597:gst_base_src_get_range:<xcamsrc0>[00m buffer ok
0:00:38.912238077 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;35m GST_SCHEDULING gstpad.c:4320:gst_pad_chain_data_unchecked:<capsfilter0:sink>[00m calling chainfunction &gst_base_transform_chain with buffer buffer: 0x7fa80168a0, pts 0:00:38.501829686, dts 0:00:38.501829686, dur 99:99:99.999999999, size 3110400, offset 2307, offset_end 2308, flags 0x0
0:00:38.912261119 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basetransform gstbasetransform.c:1985:default_submit_input_buffer:<capsfilter0>[00m handling buffer 0x7fa80168a0 of size 3110400, PTS 0:00:38.501829686 and offset 2307
0:00:38.912275118 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basetransform gstbasetransform.c:2102:default_generate_output:<capsfilter0>[00m calling prepare buffer
0:00:38.912289993 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basetransform gstbasetransform.c:2109:default_generate_output:<capsfilter0>[00m using allocated buffer in 0x7fa80168a0, out 0x7fa80168a0
0:00:38.912330826 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basetransform gstbasetransform.c:2126:default_generate_output:<capsfilter0>[00m doing inplace transform
0:00:38.912355326 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;35m GST_SCHEDULING gstpad.c:4320:gst_pad_chain_data_unchecked:<appsink0:sink>[00m calling chainfunction &gst_base_sink_chain with buffer buffer: 0x7fa80168a0, pts 0:00:38.501829686, dts 0:00:38.501829686, dur 99:99:99.999999999, size 3110400, offset 2307, offset_end 2308, flags 0x0
0:00:38.912380409 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesink gstbasesink.c:3421:gst_base_sink_chain_unlocked:<appsink0>[00m got times start: 0:00:38.501829686, end: 99:99:99.999999999
0:00:38.912402284 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesink gstbasesink.c:2006:gst_base_sink_get_sync_times:<appsink0>[00m got times start: 0:00:38.501829686, stop: 99:99:99.999999999, do_sync 1
0:00:38.912413950 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;04m default gstsegment.c:737:gst_segment_to_running_time_full:[00m invalid position (-1)
0:00:38.912433783 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesink gstbasesink.c:2591:gst_base_sink_do_sync:<appsink0>[00m reset rc_time to time 0:00:38.501829686
0:00:38.912452741 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesink gstbasesink.c:2603:gst_base_sink_do_sync:<appsink0>[00m possibly waiting for clock to reach 0:00:38.501829686, adjusted 0:00:38.501829686
0:00:38.912466741 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;33m GST_CLOCK gstclock.c:537:gst_clock_id_wait:<GstSystemClock>[00m waiting on clock entry 0x7fa8006480
0:00:38.912484241 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;33m GST_CLOCK gstclock.c:1046:gst_clock_get_internal_time:<GstSystemClock>[00m internal time 7:39:42.419885518
0:00:38.912499699 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;33m GST_CLOCK gstclock.c:1091:gst_clock_get_time:<GstSystemClock>[00m adjusted time 7:39:42.419885518
0:00:38.912520116 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;33m GST_CLOCK gstsystemclock.c:719:gst_system_clock_id_wait_jitter_unlocked:[00m entry 0x7fa8006480 time 7:39:42.419548938 now 7:39:42.419885518 diff (time-now) -336580
0:00:38.912536157 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;33m GST_CLOCK gstclock.c:547:gst_clock_id_wait:<GstSystemClock>[00m done waiting entry 0x7fa8006480, res: 1 (early)
0:00:38.912553948 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesink gstbasesink.c:2610:gst_base_sink_do_sync:<appsink0>[00m clock returned 1, jitter 0:00:00.000336580
0:00:38.912565615 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesink gstbasesink.c:2926:gst_base_sink_is_too_late:<appsink0>[00m frame dropping disabled
0:00:38.912578157 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesink gstbasesink.c:3538:gst_base_sink_chain_unlocked:<appsink0>[00m rendering object 0x7fa80168a0
0:00:38.912591281 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesink gstbasesink.c:994:gst_base_sink_set_last_buffer_unlocked:<appsink0>[00m setting last buffer to 0x7fa80168a0
0:00:38.912618406 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;34m GST_MEMORY gstmemory.c:88:_gst_memory_free:[00m free memory 0x7fa801d700
0:00:38.912638531 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m appsink gstappsink.c:876:gst_app_sink_render_common:<appsink0>[00m pushing render buffer/list 0x7fa80168a0 on queue (0)
0:00:38.912683155 [334m 5601[00m 0x7fa0012520 [37mDEBUG [00m [00m appsink gstappsink.c:1630:gst_app_sink_try_pull_sample:<appsink0>[00m trying to grab a buffer
0:00:38.912699780 [334m 5601[00m 0x7fa0012520 [37mDEBUG [00m [00m appsink gstappsink.c:821:dequeue_buffer:<appsink0>[00m dequeued buffer/list 0x7fa80168a0
0:00:38.912722530 [334m 5601[00m 0x7fa0012520 [37mDEBUG [00m [00m appsink gstappsink.c:1654:gst_app_sink_try_pull_sample:<appsink0>[00m we have a buffer 0x7fa80168a0
0:00:38.914088430 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesink gstbasesink.c:3577:gst_base_sink_chain_unlocked:<appsink0>[00m object unref after render 0x7fa80168a0
0:00:38.914228720 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;35m GST_SCHEDULING gstpad.c:4326:gst_pad_chain_data_unchecked:<appsink0:sink>[00m called chainfunction &gst_base_sink_chain with buffer 0x7fa80168a0, returned ok
0:00:38.914285303 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;35m GST_SCHEDULING gstpad.c:4326:gst_pad_chain_data_unchecked:<capsfilter0:sink>[00m called chainfunction &gst_base_transform_chain with buffer 0x7fa80168a0, returned ok
0:00:38.914340428 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesrc gstbasesrc.c:2506:gst_base_src_get_range:<xcamsrc0>[00m calling create offset 18446744073709551615 length 4096, time 0
0:00:38.918062884 [334m 5601[00m 0x7fa0012520 [37mDEBUG [00m [00m appsink gstappsink.c:1146:gst_app_sink_is_eos:<appsink0>[00m we are not yet EOS
0:00:38.918120925 [334m 5601[00m 0x7fa0012520 [37mDEBUG [00m [00m appsink gstappsink.c:1630:gst_app_sink_try_pull_sample:<appsink0>[00m trying to grab a buffer
0:00:38.918132591 [334m 5601[00m 0x7fa0012520 [37mDEBUG [00m [00m appsink gstappsink.c:1641:gst_app_sink_try_pull_sample:<appsink0>[00m waiting for a buffer
0:00:39.418246385 [334m 5601[00m 0x7fa0012520 [37mDEBUG [00m [00m appsink gstappsink.c:1674:gst_app_sink_try_pull_sample:<appsink0>[00m timeout expired, return NULL
0:00:39.419157833 [334m 5601[00m 0x7fa0012520 [37mDEBUG [00m [00m appsink gstappsink.c:1146:gst_app_sink_is_eos:<appsink0>[00m we are not yet EOS
0:00:39.419250290 [334m 5601[00m 0x55ac20dc00 [37mDEBUG [00m [00;01;31m GST_STATES gstelement.c:2827:gst_element_set_state_func:<xcamsrc0>[00m set_state to NULL
0:00:39.419274498 [334m 5601[00m 0x55ac20dc00 [37mDEBUG [00m [00;01;31m GST_STATES gstelement.c:2852:gst_element_set_state_func:<xcamsrc0>[00m setting target state to NULL
0:00:39.419294915 [334m 5601[00m 0x55ac20dc00 [37mDEBUG [00m [00;01;31m GST_STATES gstelement.c:2865:gst_element_set_state_func:<xcamsrc0>[00m current PLAYING, old_pending VOID_PENDING, next VOID_PENDING, old return SUCCESS
0:00:39.419312706 [334m 5601[00m 0x55ac20dc00 [37mDEBUG [00m [00;01;31m GST_STATES gstelement.c:2899:gst_element_set_state_func:<xcamsrc0>[00m intermediate: setting state from PLAYING to PAUSED
0:00:39.419330498 [334m 5601[00m 0x55ac20dc00 [37mDEBUG [00m [00m basesrc gstbasesrc.c:3910:gst_base_src_change_state:<xcamsrc0>[00m PLAYING->PAUSED
0:00:39.419344498 [334m 5601[00m 0x55ac20dc00 [37mDEBUG [00m [00m basesrc gstbasesrc.c:3742:gst_base_src_set_playing:<xcamsrc0>[00m unschedule clock
0:00:39.419358206 [334m 5601[00m 0x55ac20dc00 [37mDEBUG [00m [00m basesrc gstbasesrc.c:3749:gst_base_src_set_playing:<xcamsrc0>[00m live running 0
0:00:39.419370456 [334m 5601[00m 0x55ac20dc00 [37mDEBUG [00m [00;01;31m GST_STATES gstelement.c:2995:gst_element_change_state:<xcamsrc0>[00m element changed state NO_PREROLL
0:00:39.419388247 [334m 5601[00m 0x55ac20dc00 [36mINFO [00m [00;01;31m GST_STATES gstelement.c:2651:gst_element_continue_state:<xcamsrc0>[00m committing state from PLAYING to PAUSED, pending NULL, next READY
0:00:39.419405455 [334m 5601[00m 0x55ac20dc00 [36mINFO [00m [00;01;31m GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<xcamsrc0>[00m notifying about state-changed PLAYING to PAUSED (NULL pending)
0:00:39.419463205 [334m 5601[00m 0x55ac20dc00 [37mDEBUG [00m [00;43m GST_BUS gstbus.c:318:gst_bus_post:<bus0>[00m [msg 0x55ac46ad30] posting on bus state-changed message: 0x55ac46ad30, time 99:99:99.999999999, seq-num 39, element 'xcamsrc0', GstMessageStateChanged, old-state=(GstState)GST_STATE_PLAYING, new-state=(GstState)GST_STATE_PAUSED, pending-state=(GstState)GST_STATE_NULL;
0:00:39.419509287 [334m 5601[00m 0x55ac20dc00 [37mDEBUG [00m [00;01m bin gstbin.c:3717:gst_bin_handle_message_func:<pipeline0>[00m [msg 0x55ac46ad30] handling child xcamsrc0 message of type state-changed
0:00:39.419524162 [334m 5601[00m 0x55ac20dc00 [37mDEBUG [00m [00;01m bin gstbin.c:4054:gst_bin_handle_message_func:<pipeline0>[00m posting message upward
0:00:39.419550995 [334m 5601[00m 0x55ac20dc00 [37mDEBUG [00m [00;43m GST_BUS gstbus.c:318:gst_bus_post:<bus1>[00m [msg 0x55ac46ad30] posting on bus state-changed message: 0x55ac46ad30, time 99:99:99.999999999, seq-num 39, element 'xcamsrc0', GstMessageStateChanged, old-state=(GstState)GST_STATE_PLAYING, new-state=(GstState)GST_STATE_PAUSED, pending-state=(GstState)GST_STATE_NULL;
0:00:39.419565578 [334m 5601[00m 0x55ac20dc00 [37mDEBUG [00m [00;43m GST_BUS gstbus.c:357:gst_bus_post:<bus1>[00m [msg 0x55ac46ad30] pushing on async queue
0:00:39.419591245 [334m 5601[00m 0x55ac20dc00 [37mDEBUG [00m [00;43m GST_BUS gstbus.c:360:gst_bus_post:<bus1>[00m [msg 0x55ac46ad30] pushed on async queue
0:00:39.419629744 [334m 5601[00m 0x55ac20dc00 [37mDEBUG [00m [00;43m GST_BUS gstbus.c:353:gst_bus_post:<bus0>[00m [msg 0x55ac46ad30] dropped
0:00:39.419645786 [334m 5601[00m 0x55ac20dc00 [36mINFO [00m [00;01;31m GST_STATES gstelement.c:2658:gst_element_continue_state:<xcamsrc0>[00m continue state change PAUSED to READY, final NULL
0:00:39.419660077 [334m 5601[00m 0x55ac20dc00 [37mDEBUG [00m [00;01;37;41m GST_ELEMENT_PADS gstelement.c:3097:gst_element_pads_activate:<xcamsrc0>[00m deactivate pads
0:00:39.419683702 [334m 5601[00m 0x55ac20dc00 [37mDEBUG [00m [00;01;31;41m GST_PADS gstpad.c:1121:gst_pad_set_active:<xcamsrc0:src>[00m deactivating pad from push mode
0:00:39.419698285 [334m 5601[00m 0x55ac20dc00 [37mDEBUG [00m [00;01;31;41m GST_PADS gstpad.c:991:pre_activate:<xcamsrc0:src>[00m setting PAD_MODE NONE, set flushing
0:00:39.419714910 [334m 5601[00m 0x55ac20dc00 [37mDEBUG [00m [00m basesrc gstbasesrc.c:3858:gst_base_src_activate_mode:<xcamsrc0:src>[00m activating in mode 1
0:00:39.419726868 [334m 5601[00m 0x55ac20dc00 [37mDEBUG [00m [00m basesrc gstbasesrc.c:3792:gst_base_src_activate_push:<xcamsrc0>[00m Deactivating in push mode
0:00:39.419738243 [334m 5601[00m 0x55ac20dc00 [37mDEBUG [00m [00m basesrc gstbasesrc.c:3629:gst_base_src_stop:<xcamsrc0>[00m stopping source
0:00:39.419750201 [334m 5601[00m 0x55ac20dc00 [37mDEBUG [00m [00m basesrc gstbasesrc.c:3679:gst_base_src_set_flushing:<xcamsrc0>[00m flushing 1
0:00:39.419775868 [334m 5601[00m 0x55ac20dc00 [37mDEBUG [00m [00;01;31;41m GST_PADS gstpad.c:6288:gst_pad_stop_task:<xcamsrc0:src>[00m stop task
0:00:39.419793951 [334m 5601[00m 0x55ac20dc00 [37mDEBUG [00m [00m task gsttask.c:688:gst_task_set_state:<xcamsrc0:src>[00m Changing task 0x55ac48e050 to state 1
0:01:24.000659198 [334m 5601[00m 0x55ac20dc00 [36mINFO [00m [00;01;31m GST_INIT gst.c:1083:gst_deinit:[00m deinitializing GStreamer
I am just got a SOM-RK3399v2 Dev Kit and install the friendlycore-bionic-4.4-arm64-20200623. When I use the HDMI-IN with rkisp as input I found that it'll hang in gstreamer restarting.
Here is my gstreamer pipeline:
"rkisp device=/dev/video0 io-mode=1 ! capsfilter caps=\"video/x-raw,format=NV12,video/x-raw,format=NV12,framerate=30/1,width=1920,height=1080\" ! appsink"
And here is the stack trace of relative thread:
Log:
0:00:38.829919919 [334m 5601[00m 0x7fa0012520 [37mDEBUG [00m [00m appsink gstappsink.c:821:dequeue_buffer:<appsink0>[00m dequeued buffer/list 0x7fa8016680
0:00:38.829933335 [334m 5601[00m 0x7fa0012520 [37mDEBUG [00m [00m appsink gstappsink.c:1654:gst_app_sink_try_pull_sample:<appsink0>[00m we have a buffer 0x7fa8016680
0:00:38.833251130 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesink gstbasesink.c:3577:gst_base_sink_chain_unlocked:<appsink0>[00m object unref after render 0x7fa8016680
0:00:38.833504585 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;35m GST_SCHEDULING gstpad.c:4326:gst_pad_chain_data_unchecked:<appsink0:sink>[00m called chainfunction &gst_base_sink_chain with buffer 0x7fa8016680, returned ok
0:00:38.833754832 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;35m GST_SCHEDULING gstpad.c:4326:gst_pad_chain_data_unchecked:<capsfilter0:sink>[00m called chainfunction &gst_base_transform_chain with buffer 0x7fa8016680, returned ok
0:00:38.833905039 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesrc gstbasesrc.c:2506:gst_base_src_get_range:<xcamsrc0>[00m calling create offset 18446744073709551615 length 4096, time 0
0:00:38.835273106 [334m 5601[00m 0x7fa0012520 [37mDEBUG [00m [00m appsink gstappsink.c:1146:gst_app_sink_is_eos:<appsink0>[00m we are not yet EOS
0:00:38.835331147 [334m 5601[00m 0x7fa0012520 [37mDEBUG [00m [00m appsink gstappsink.c:1630:gst_app_sink_try_pull_sample:<appsink0>[00m trying to grab a buffer
0:00:38.835342813 [334m 5601[00m 0x7fa0012520 [37mDEBUG [00m [00m appsink gstappsink.c:1641:gst_app_sink_try_pull_sample:<appsink0>[00m waiting for a buffer
0:00:38.838304070 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;34m GST_MEMORY gstmemory.c:139:gst_memory_init:[00m new memory 0x7fa8314f30, maxsize:3110407 offset:0 size:3110400
0:00:38.845948856 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;33m GST_CLOCK gstclock.c:1046:gst_clock_get_internal_time:<GstSystemClock>[00m internal time 7:39:42.353344591
0:00:38.845974814 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;33m GST_CLOCK gstclock.c:1091:gst_clock_get_time:<GstSystemClock>[00m adjusted time 7:39:42.353344591
0:00:38.845989105 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesrc gstbasesrc.c:2360:gst_base_src_do_sync:<xcamsrc0>[00m no sync needed
0:00:38.846003105 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesrc gstbasesrc.c:2597:gst_base_src_get_range:<xcamsrc0>[00m buffer ok
0:00:38.846035188 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;35m GST_SCHEDULING gstpad.c:4320:gst_pad_chain_data_unchecked:<capsfilter0:sink>[00m calling chainfunction &gst_base_transform_chain with buffer buffer: 0x7fa8016ce0, pts 0:00:38.435625339, dts 0:00:38.435625339, dur 99:99:99.999999999, size 3110400, offset 2303, offset_end 2304, flags 0x0
0:00:38.846058813 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basetransform gstbasetransform.c:1985:default_submit_input_buffer:<capsfilter0>[00m handling buffer 0x7fa8016ce0 of size 3110400, PTS 0:00:38.435625339 and offset 2303
0:00:38.846072812 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basetransform gstbasetransform.c:2102:default_generate_output:<capsfilter0>[00m calling prepare buffer
0:00:38.846087687 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basetransform gstbasetransform.c:2109:default_generate_output:<capsfilter0>[00m using allocated buffer in 0x7fa8016ce0, out 0x7fa8016ce0
0:00:38.846099354 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basetransform gstbasetransform.c:2126:default_generate_output:<capsfilter0>[00m doing inplace transform
0:00:38.846122687 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;35m GST_SCHEDULING gstpad.c:4320:gst_pad_chain_data_unchecked:<appsink0:sink>[00m calling chainfunction &gst_base_sink_chain with buffer buffer: 0x7fa8016ce0, pts 0:00:38.435625339, dts 0:00:38.435625339, dur 99:99:99.999999999, size 3110400, offset 2303, offset_end 2304, flags 0x0
0:00:38.846147770 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesink gstbasesink.c:3421:gst_base_sink_chain_unlocked:<appsink0>[00m got times start: 0:00:38.435625339, end: 99:99:99.999999999
0:00:38.846170228 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesink gstbasesink.c:2006:gst_base_sink_get_sync_times:<appsink0>[00m got times start: 0:00:38.435625339, stop: 99:99:99.999999999, do_sync 1
0:00:38.846181895 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;04m default gstsegment.c:737:gst_segment_to_running_time_full:[00m invalid position (-1)
0:00:38.846201728 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesink gstbasesink.c:2591:gst_base_sink_do_sync:<appsink0>[00m reset rc_time to time 0:00:38.435625339
0:00:38.846220686 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesink gstbasesink.c:2603:gst_base_sink_do_sync:<appsink0>[00m possibly waiting for clock to reach 0:00:38.435625339, adjusted 0:00:38.435625339
0:00:38.846235269 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;33m GST_CLOCK gstclock.c:537:gst_clock_id_wait:<GstSystemClock>[00m waiting on clock entry 0x7fa8006480
0:00:38.846252769 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;33m GST_CLOCK gstclock.c:1046:gst_clock_get_internal_time:<GstSystemClock>[00m internal time 7:39:42.353653754
0:00:38.846268227 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;33m GST_CLOCK gstclock.c:1091:gst_clock_get_time:<GstSystemClock>[00m adjusted time 7:39:42.353653754
0:00:38.846302351 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;33m GST_CLOCK gstsystemclock.c:719:gst_system_clock_id_wait_jitter_unlocked:[00m entry 0x7fa8006480 time 7:39:42.353344591 now 7:39:42.353653754 diff (time-now) -309163
0:00:38.846319268 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;33m GST_CLOCK gstclock.c:547:gst_clock_id_wait:<GstSystemClock>[00m done waiting entry 0x7fa8006480, res: 1 (early)
0:00:38.846337351 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesink gstbasesink.c:2610:gst_base_sink_do_sync:<appsink0>[00m clock returned 1, jitter 0:00:00.000309163
0:00:38.846349018 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesink gstbasesink.c:2926:gst_base_sink_is_too_late:<appsink0>[00m frame dropping disabled
0:00:38.846361851 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesink gstbasesink.c:3538:gst_base_sink_chain_unlocked:<appsink0>[00m rendering object 0x7fa8016ce0
0:00:38.846374684 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesink gstbasesink.c:994:gst_base_sink_set_last_buffer_unlocked:<appsink0>[00m setting last buffer to 0x7fa8016ce0
0:00:38.846390434 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;34m GST_MEMORY gstmemory.c:88:_gst_memory_free:[00m free memory 0x7fa801d700
0:00:38.846409975 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m appsink gstappsink.c:876:gst_app_sink_render_common:<appsink0>[00m pushing render buffer/list 0x7fa8016ce0 on queue (0)
0:00:38.846456350 [334m 5601[00m 0x7fa0012520 [37mDEBUG [00m [00m appsink gstappsink.c:1630:gst_app_sink_try_pull_sample:<appsink0>[00m trying to grab a buffer
0:00:38.846474433 [334m 5601[00m 0x7fa0012520 [37mDEBUG [00m [00m appsink gstappsink.c:821:dequeue_buffer:<appsink0>[00m dequeued buffer/list 0x7fa8016ce0
0:00:38.846487558 [334m 5601[00m 0x7fa0012520 [37mDEBUG [00m [00m appsink gstappsink.c:1654:gst_app_sink_try_pull_sample:<appsink0>[00m we have a buffer 0x7fa8016ce0
0:00:38.847173091 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesink gstbasesink.c:3577:gst_base_sink_chain_unlocked:<appsink0>[00m object unref after render 0x7fa8016ce0
0:00:38.847373172 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;35m GST_SCHEDULING gstpad.c:4326:gst_pad_chain_data_unchecked:<appsink0:sink>[00m called chainfunction &gst_base_sink_chain with buffer 0x7fa8016ce0, returned ok
0:00:38.847494212 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;35m GST_SCHEDULING gstpad.c:4326:gst_pad_chain_data_unchecked:<capsfilter0:sink>[00m called chainfunction &gst_base_transform_chain with buffer 0x7fa8016ce0, returned ok
0:00:38.847703918 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesrc gstbasesrc.c:2506:gst_base_src_get_range:<xcamsrc0>[00m calling create offset 18446744073709551615 length 4096, time 0
0:00:38.851831703 [334m 5601[00m 0x7fa0012520 [37mDEBUG [00m [00m appsink gstappsink.c:1146:gst_app_sink_is_eos:<appsink0>[00m we are not yet EOS
0:00:38.851881869 [334m 5601[00m 0x7fa0012520 [37mDEBUG [00m [00m appsink gstappsink.c:1630:gst_app_sink_try_pull_sample:<appsink0>[00m trying to grab a buffer
0:00:38.851893827 [334m 5601[00m 0x7fa0012520 [37mDEBUG [00m [00m appsink gstappsink.c:1641:gst_app_sink_try_pull_sample:<appsink0>[00m waiting for a buffer
0:00:38.854970000 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;34m GST_MEMORY gstmemory.c:139:gst_memory_init:[00m new memory 0x7fa801d700, maxsize:3110407 offset:0 size:3110400
0:00:38.862231539 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;33m GST_CLOCK gstclock.c:1046:gst_clock_get_internal_time:<GstSystemClock>[00m internal time 7:39:42.369628150
0:00:38.862280830 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;33m GST_CLOCK gstclock.c:1091:gst_clock_get_time:<GstSystemClock>[00m adjusted time 7:39:42.369628150
0:00:38.862295997 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesrc gstbasesrc.c:2360:gst_base_src_do_sync:<xcamsrc0>[00m no sync needed
0:00:38.862309705 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesrc gstbasesrc.c:2597:gst_base_src_get_range:<xcamsrc0>[00m buffer ok
0:00:38.862342663 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;35m GST_SCHEDULING gstpad.c:4320:gst_pad_chain_data_unchecked:<capsfilter0:sink>[00m calling chainfunction &gst_base_transform_chain with buffer buffer: 0x7fa8016680, pts 0:00:38.451908898, dts 0:00:38.451908898, dur 99:99:99.999999999, size 3110400, offset 2304, offset_end 2305, flags 0x0
0:00:38.862365996 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basetransform gstbasetransform.c:1985:default_submit_input_buffer:<capsfilter0>[00m handling buffer 0x7fa8016680 of size 3110400, PTS 0:00:38.451908898 and offset 2304
0:00:38.862379996 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basetransform gstbasetransform.c:2102:default_generate_output:<capsfilter0>[00m calling prepare buffer
0:00:38.862394871 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basetransform gstbasetransform.c:2109:default_generate_output:<capsfilter0>[00m using allocated buffer in 0x7fa8016680, out 0x7fa8016680
0:00:38.862406537 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basetransform gstbasetransform.c:2126:default_generate_output:<capsfilter0>[00m doing inplace transform
0:00:38.862429870 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;35m GST_SCHEDULING gstpad.c:4320:gst_pad_chain_data_unchecked:<appsink0:sink>[00m calling chainfunction &gst_base_sink_chain with buffer buffer: 0x7fa8016680, pts 0:00:38.451908898, dts 0:00:38.451908898, dur 99:99:99.999999999, size 3110400, offset 2304, offset_end 2305, flags 0x0
0:00:38.862454078 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesink gstbasesink.c:3421:gst_base_sink_chain_unlocked:<appsink0>[00m got times start: 0:00:38.451908898, end: 99:99:99.999999999
0:00:38.862476537 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesink gstbasesink.c:2006:gst_base_sink_get_sync_times:<appsink0>[00m got times start: 0:00:38.451908898, stop: 99:99:99.999999999, do_sync 1
0:00:38.862488203 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;04m default gstsegment.c:737:gst_segment_to_running_time_full:[00m invalid position (-1)
0:00:38.862507161 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesink gstbasesink.c:2591:gst_base_sink_do_sync:<appsink0>[00m reset rc_time to time 0:00:38.451908898
0:00:38.862526411 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesink gstbasesink.c:2603:gst_base_sink_do_sync:<appsink0>[00m possibly waiting for clock to reach 0:00:38.451908898, adjusted 0:00:38.451908898
0:00:38.862540994 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;33m GST_CLOCK gstclock.c:537:gst_clock_id_wait:<GstSystemClock>[00m waiting on clock entry 0x7fa8006480
0:00:38.862558202 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;33m GST_CLOCK gstclock.c:1046:gst_clock_get_internal_time:<GstSystemClock>[00m internal time 7:39:42.369959479
0:00:38.862573952 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;33m GST_CLOCK gstclock.c:1091:gst_clock_get_time:<GstSystemClock>[00m adjusted time 7:39:42.369959479
0:00:38.862602827 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;33m GST_CLOCK gstsystemclock.c:719:gst_system_clock_id_wait_jitter_unlocked:[00m entry 0x7fa8006480 time 7:39:42.369628150 now 7:39:42.369959479 diff (time-now) -331329
0:00:38.862620910 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;33m GST_CLOCK gstclock.c:547:gst_clock_id_wait:<GstSystemClock>[00m done waiting entry 0x7fa8006480, res: 1 (early)
0:00:38.862647160 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesink gstbasesink.c:2610:gst_base_sink_do_sync:<appsink0>[00m clock returned 1, jitter 0:00:00.000331329
0:00:38.862659701 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesink gstbasesink.c:2926:gst_base_sink_is_too_late:<appsink0>[00m frame dropping disabled
0:00:38.862671951 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesink gstbasesink.c:3538:gst_base_sink_chain_unlocked:<appsink0>[00m rendering object 0x7fa8016680
0:00:38.862685076 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesink gstbasesink.c:994:gst_base_sink_set_last_buffer_unlocked:<appsink0>[00m setting last buffer to 0x7fa8016680
0:00:38.862700826 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;34m GST_MEMORY gstmemory.c:88:_gst_memory_free:[00m free memory 0x7fa8314f30
0:00:38.862719492 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m appsink gstappsink.c:876:gst_app_sink_render_common:<appsink0>[00m pushing render buffer/list 0x7fa8016680 on queue (0)
0:00:38.862762658 [334m 5601[00m 0x7fa0012520 [37mDEBUG [00m [00m appsink gstappsink.c:1630:gst_app_sink_try_pull_sample:<appsink0>[00m trying to grab a buffer
0:00:38.862779283 [334m 5601[00m 0x7fa0012520 [37mDEBUG [00m [00m appsink gstappsink.c:821:dequeue_buffer:<appsink0>[00m dequeued buffer/list 0x7fa8016680
0:00:38.862792699 [334m 5601[00m 0x7fa0012520 [37mDEBUG [00m [00m appsink gstappsink.c:1654:gst_app_sink_try_pull_sample:<appsink0>[00m we have a buffer 0x7fa8016680
0:00:38.864135059 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesink gstbasesink.c:3577:gst_base_sink_chain_unlocked:<appsink0>[00m object unref after render 0x7fa8016680
0:00:38.864350306 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;35m GST_SCHEDULING gstpad.c:4326:gst_pad_chain_data_unchecked:<appsink0:sink>[00m called chainfunction &gst_base_sink_chain with buffer 0x7fa8016680, returned ok
0:00:38.864476013 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;35m GST_SCHEDULING gstpad.c:4326:gst_pad_chain_data_unchecked:<capsfilter0:sink>[00m called chainfunction &gst_base_transform_chain with buffer 0x7fa8016680, returned ok
0:00:38.864673761 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesrc gstbasesrc.c:2506:gst_base_src_get_range:<xcamsrc0>[00m calling create offset 18446744073709551615 length 4096, time 0
0:00:38.868128095 [334m 5601[00m 0x7fa0012520 [37mDEBUG [00m [00m appsink gstappsink.c:1146:gst_app_sink_is_eos:<appsink0>[00m we are not yet EOS
0:00:38.868186136 [334m 5601[00m 0x7fa0012520 [37mDEBUG [00m [00m appsink gstappsink.c:1630:gst_app_sink_try_pull_sample:<appsink0>[00m trying to grab a buffer
0:00:38.868197803 [334m 5601[00m 0x7fa0012520 [37mDEBUG [00m [00m appsink gstappsink.c:1641:gst_app_sink_try_pull_sample:<appsink0>[00m waiting for a buffer
0:00:38.871669470 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;34m GST_MEMORY gstmemory.c:139:gst_memory_init:[00m new memory 0x7fa8314f30, maxsize:3110407 offset:0 size:3110400
0:00:38.879280714 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;33m GST_CLOCK gstclock.c:1046:gst_clock_get_internal_time:<GstSystemClock>[00m internal time 7:39:42.386678491
0:00:38.879305214 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;33m GST_CLOCK gstclock.c:1091:gst_clock_get_time:<GstSystemClock>[00m adjusted time 7:39:42.386678491
0:00:38.879320089 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesrc gstbasesrc.c:2360:gst_base_src_do_sync:<xcamsrc0>[00m no sync needed
0:00:38.879333505 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesrc gstbasesrc.c:2597:gst_base_src_get_range:<xcamsrc0>[00m buffer ok
0:00:38.879392421 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;35m GST_SCHEDULING gstpad.c:4320:gst_pad_chain_data_unchecked:<capsfilter0:sink>[00m calling chainfunction &gst_base_transform_chain with buffer buffer: 0x7fa8016df0, pts 0:00:38.468959239, dts 0:00:38.468959239, dur 99:99:99.999999999, size 3110400, offset 2305, offset_end 2306, flags 0x0
0:00:38.879416338 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basetransform gstbasetransform.c:1985:default_submit_input_buffer:<capsfilter0>[00m handling buffer 0x7fa8016df0 of size 3110400, PTS 0:00:38.468959239 and offset 2305
0:00:38.879430629 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basetransform gstbasetransform.c:2102:default_generate_output:<capsfilter0>[00m calling prepare buffer
0:00:38.879445504 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basetransform gstbasetransform.c:2109:default_generate_output:<capsfilter0>[00m using allocated buffer in 0x7fa8016df0, out 0x7fa8016df0
0:00:38.879457170 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basetransform gstbasetransform.c:2126:default_generate_output:<capsfilter0>[00m doing inplace transform
0:00:38.879480504 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;35m GST_SCHEDULING gstpad.c:4320:gst_pad_chain_data_unchecked:<appsink0:sink>[00m calling chainfunction &gst_base_sink_chain with buffer buffer: 0x7fa8016df0, pts 0:00:38.468959239, dts 0:00:38.468959239, dur 99:99:99.999999999, size 3110400, offset 2305, offset_end 2306, flags 0x0
0:00:38.879505878 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesink gstbasesink.c:3421:gst_base_sink_chain_unlocked:<appsink0>[00m got times start: 0:00:38.468959239, end: 99:99:99.999999999
0:00:38.879528336 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesink gstbasesink.c:2006:gst_base_sink_get_sync_times:<appsink0>[00m got times start: 0:00:38.468959239, stop: 99:99:99.999999999, do_sync 1
0:00:38.879540003 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;04m default gstsegment.c:737:gst_segment_to_running_time_full:[00m invalid position (-1)
0:00:38.879560128 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesink gstbasesink.c:2591:gst_base_sink_do_sync:<appsink0>[00m reset rc_time to time 0:00:38.468959239
0:00:38.879579377 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesink gstbasesink.c:2603:gst_base_sink_do_sync:<appsink0>[00m possibly waiting for clock to reach 0:00:38.468959239, adjusted 0:00:38.468959239
0:00:38.879604460 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;33m GST_CLOCK gstclock.c:537:gst_clock_id_wait:<GstSystemClock>[00m waiting on clock entry 0x7fa8006480
0:00:38.879624585 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;33m GST_CLOCK gstclock.c:1046:gst_clock_get_internal_time:<GstSystemClock>[00m internal time 7:39:42.387025279
0:00:38.879640335 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;33m GST_CLOCK gstclock.c:1091:gst_clock_get_time:<GstSystemClock>[00m adjusted time 7:39:42.387025279
0:00:38.879660751 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;33m GST_CLOCK gstsystemclock.c:719:gst_system_clock_id_wait_jitter_unlocked:[00m entry 0x7fa8006480 time 7:39:42.386678491 now 7:39:42.387025279 diff (time-now) -346788
0:00:38.879676501 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;33m GST_CLOCK gstclock.c:547:gst_clock_id_wait:<GstSystemClock>[00m done waiting entry 0x7fa8006480, res: 1 (early)
0:00:38.879694876 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesink gstbasesink.c:2610:gst_base_sink_do_sync:<appsink0>[00m clock returned 1, jitter 0:00:00.000346788
0:00:38.879706543 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesink gstbasesink.c:2926:gst_base_sink_is_too_late:<appsink0>[00m frame dropping disabled
0:00:38.879727542 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesink gstbasesink.c:3538:gst_base_sink_chain_unlocked:<appsink0>[00m rendering object 0x7fa8016df0
0:00:38.879741542 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesink gstbasesink.c:994:gst_base_sink_set_last_buffer_unlocked:<appsink0>[00m setting last buffer to 0x7fa8016df0
0:00:38.879757584 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;34m GST_MEMORY gstmemory.c:88:_gst_memory_free:[00m free memory 0x7fa801d700
0:00:38.879776833 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m appsink gstappsink.c:876:gst_app_sink_render_common:<appsink0>[00m pushing render buffer/list 0x7fa8016df0 on queue (0)
0:00:38.879822041 [334m 5601[00m 0x7fa0012520 [37mDEBUG [00m [00m appsink gstappsink.c:1630:gst_app_sink_try_pull_sample:<appsink0>[00m trying to grab a buffer
0:00:38.879838666 [334m 5601[00m 0x7fa0012520 [37mDEBUG [00m [00m appsink gstappsink.c:821:dequeue_buffer:<appsink0>[00m dequeued buffer/list 0x7fa8016df0
0:00:38.879851791 [334m 5601[00m 0x7fa0012520 [37mDEBUG [00m [00m appsink gstappsink.c:1654:gst_app_sink_try_pull_sample:<appsink0>[00m we have a buffer 0x7fa8016df0
0:00:38.881221858 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesink gstbasesink.c:3577:gst_base_sink_chain_unlocked:<appsink0>[00m object unref after render 0x7fa8016df0
0:00:38.881454897 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;35m GST_SCHEDULING gstpad.c:4326:gst_pad_chain_data_unchecked:<appsink0:sink>[00m called chainfunction &gst_base_sink_chain with buffer 0x7fa8016df0, returned ok
0:00:38.881585854 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;35m GST_SCHEDULING gstpad.c:4326:gst_pad_chain_data_unchecked:<capsfilter0:sink>[00m called chainfunction &gst_base_transform_chain with buffer 0x7fa8016df0, returned ok
0:00:38.882059223 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesrc gstbasesrc.c:2506:gst_base_src_get_range:<xcamsrc0>[00m calling create offset 18446744073709551615 length 4096, time 0
0:00:38.885299185 [334m 5601[00m 0x7fa0012520 [37mDEBUG [00m [00m appsink gstappsink.c:1146:gst_app_sink_is_eos:<appsink0>[00m we are not yet EOS
0:00:38.885357810 [334m 5601[00m 0x7fa0012520 [37mDEBUG [00m [00m appsink gstappsink.c:1630:gst_app_sink_try_pull_sample:<appsink0>[00m trying to grab a buffer
0:00:38.885369476 [334m 5601[00m 0x7fa0012520 [37mDEBUG [00m [00m appsink gstappsink.c:1641:gst_app_sink_try_pull_sample:<appsink0>[00m waiting for a buffer
0:00:38.888152818 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;34m GST_MEMORY gstmemory.c:139:gst_memory_init:[00m new memory 0x7fa801d700, maxsize:3110407 offset:0 size:3110400
0:00:38.895581481 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;33m GST_CLOCK gstclock.c:1046:gst_clock_get_internal_time:<GstSystemClock>[00m internal time 7:39:42.402977508
0:00:38.895613856 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;33m GST_CLOCK gstclock.c:1091:gst_clock_get_time:<GstSystemClock>[00m adjusted time 7:39:42.402977508
0:00:38.895629897 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesrc gstbasesrc.c:2360:gst_base_src_do_sync:<xcamsrc0>[00m no sync needed
0:00:38.895643605 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesrc gstbasesrc.c:2597:gst_base_src_get_range:<xcamsrc0>[00m buffer ok
0:00:38.895676272 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;35m GST_SCHEDULING gstpad.c:4320:gst_pad_chain_data_unchecked:<capsfilter0:sink>[00m calling chainfunction &gst_base_transform_chain with buffer buffer: 0x7fa8016790, pts 0:00:38.485258256, dts 0:00:38.485258256, dur 99:99:99.999999999, size 3110400, offset 2306, offset_end 2307, flags 0x0
0:00:38.895699313 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basetransform gstbasetransform.c:1985:default_submit_input_buffer:<capsfilter0>[00m handling buffer 0x7fa8016790 of size 3110400, PTS 0:00:38.485258256 and offset 2306
0:00:38.895736646 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basetransform gstbasetransform.c:2102:default_generate_output:<capsfilter0>[00m calling prepare buffer
0:00:38.895752396 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basetransform gstbasetransform.c:2109:default_generate_output:<capsfilter0>[00m using allocated buffer in 0x7fa8016790, out 0x7fa8016790
0:00:38.895764354 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basetransform gstbasetransform.c:2126:default_generate_output:<capsfilter0>[00m doing inplace transform
0:00:38.895788270 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;35m GST_SCHEDULING gstpad.c:4320:gst_pad_chain_data_unchecked:<appsink0:sink>[00m calling chainfunction &gst_base_sink_chain with buffer buffer: 0x7fa8016790, pts 0:00:38.485258256, dts 0:00:38.485258256, dur 99:99:99.999999999, size 3110400, offset 2306, offset_end 2307, flags 0x0
0:00:38.895812478 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesink gstbasesink.c:3421:gst_base_sink_chain_unlocked:<appsink0>[00m got times start: 0:00:38.485258256, end: 99:99:99.999999999
0:00:38.895835520 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesink gstbasesink.c:2006:gst_base_sink_get_sync_times:<appsink0>[00m got times start: 0:00:38.485258256, stop: 99:99:99.999999999, do_sync 1
0:00:38.895846895 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;04m default gstsegment.c:737:gst_segment_to_running_time_full:[00m invalid position (-1)
0:00:38.895866436 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesink gstbasesink.c:2591:gst_base_sink_do_sync:<appsink0>[00m reset rc_time to time 0:00:38.485258256
0:00:38.895885686 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesink gstbasesink.c:2603:gst_base_sink_do_sync:<appsink0>[00m possibly waiting for clock to reach 0:00:38.485258256, adjusted 0:00:38.485258256
0:00:38.895899977 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;33m GST_CLOCK gstclock.c:537:gst_clock_id_wait:<GstSystemClock>[00m waiting on clock entry 0x7fa8006480
0:00:38.895916894 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;33m GST_CLOCK gstclock.c:1046:gst_clock_get_internal_time:<GstSystemClock>[00m internal time 7:39:42.403318462
0:00:38.895932352 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;33m GST_CLOCK gstclock.c:1091:gst_clock_get_time:<GstSystemClock>[00m adjusted time 7:39:42.403318462
0:00:38.895952477 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;33m GST_CLOCK gstsystemclock.c:719:gst_system_clock_id_wait_jitter_unlocked:[00m entry 0x7fa8006480 time 7:39:42.402977508 now 7:39:42.403318462 diff (time-now) -340954
0:00:38.895968518 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;33m GST_CLOCK gstclock.c:547:gst_clock_id_wait:<GstSystemClock>[00m done waiting entry 0x7fa8006480, res: 1 (early)
0:00:38.895986601 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesink gstbasesink.c:2610:gst_base_sink_do_sync:<appsink0>[00m clock returned 1, jitter 0:00:00.000340954
0:00:38.895998268 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesink gstbasesink.c:2926:gst_base_sink_is_too_late:<appsink0>[00m frame dropping disabled
0:00:38.896010809 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesink gstbasesink.c:3538:gst_base_sink_chain_unlocked:<appsink0>[00m rendering object 0x7fa8016790
0:00:38.896023643 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesink gstbasesink.c:994:gst_base_sink_set_last_buffer_unlocked:<appsink0>[00m setting last buffer to 0x7fa8016790
0:00:38.896038809 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;34m GST_MEMORY gstmemory.c:88:_gst_memory_free:[00m free memory 0x7fa8314f30
0:00:38.896065350 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m appsink gstappsink.c:876:gst_app_sink_render_common:<appsink0>[00m pushing render buffer/list 0x7fa8016790 on queue (0)
0:00:38.896111433 [334m 5601[00m 0x7fa0012520 [37mDEBUG [00m [00m appsink gstappsink.c:1630:gst_app_sink_try_pull_sample:<appsink0>[00m trying to grab a buffer
0:00:38.896128933 [334m 5601[00m 0x7fa0012520 [37mDEBUG [00m [00m appsink gstappsink.c:821:dequeue_buffer:<appsink0>[00m dequeued buffer/list 0x7fa8016790
0:00:38.896142350 [334m 5601[00m 0x7fa0012520 [37mDEBUG [00m [00m appsink gstappsink.c:1654:gst_app_sink_try_pull_sample:<appsink0>[00m we have a buffer 0x7fa8016790
0:00:38.897057172 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesink gstbasesink.c:3577:gst_base_sink_chain_unlocked:<appsink0>[00m object unref after render 0x7fa8016790
0:00:38.897174421 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;35m GST_SCHEDULING gstpad.c:4326:gst_pad_chain_data_unchecked:<appsink0:sink>[00m called chainfunction &gst_base_sink_chain with buffer 0x7fa8016790, returned ok
0:00:38.897228670 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;35m GST_SCHEDULING gstpad.c:4326:gst_pad_chain_data_unchecked:<capsfilter0:sink>[00m called chainfunction &gst_base_transform_chain with buffer 0x7fa8016790, returned ok
0:00:38.897283211 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesrc gstbasesrc.c:2506:gst_base_src_get_range:<xcamsrc0>[00m calling create offset 18446744073709551615 length 4096, time 0
0:00:38.901468995 [334m 5601[00m 0x7fa0012520 [37mDEBUG [00m [00m appsink gstappsink.c:1146:gst_app_sink_is_eos:<appsink0>[00m we are not yet EOS
0:00:38.901523828 [334m 5601[00m 0x7fa0012520 [37mDEBUG [00m [00m appsink gstappsink.c:1630:gst_app_sink_try_pull_sample:<appsink0>[00m trying to grab a buffer
0:00:38.901535203 [334m 5601[00m 0x7fa0012520 [37mDEBUG [00m [00m appsink gstappsink.c:1641:gst_app_sink_try_pull_sample:<appsink0>[00m waiting for a buffer
0:00:38.904928705 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;34m GST_MEMORY gstmemory.c:139:gst_memory_init:[00m new memory 0x7fa8314f30, maxsize:3110407 offset:0 size:3110400
0:00:38.912152912 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;33m GST_CLOCK gstclock.c:1046:gst_clock_get_internal_time:<GstSystemClock>[00m internal time 7:39:42.419548938
0:00:38.912177703 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;33m GST_CLOCK gstclock.c:1091:gst_clock_get_time:<GstSystemClock>[00m adjusted time 7:39:42.419548938
0:00:38.912192578 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesrc gstbasesrc.c:2360:gst_base_src_do_sync:<xcamsrc0>[00m no sync needed
0:00:38.912206286 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesrc gstbasesrc.c:2597:gst_base_src_get_range:<xcamsrc0>[00m buffer ok
0:00:38.912238077 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;35m GST_SCHEDULING gstpad.c:4320:gst_pad_chain_data_unchecked:<capsfilter0:sink>[00m calling chainfunction &gst_base_transform_chain with buffer buffer: 0x7fa80168a0, pts 0:00:38.501829686, dts 0:00:38.501829686, dur 99:99:99.999999999, size 3110400, offset 2307, offset_end 2308, flags 0x0
0:00:38.912261119 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basetransform gstbasetransform.c:1985:default_submit_input_buffer:<capsfilter0>[00m handling buffer 0x7fa80168a0 of size 3110400, PTS 0:00:38.501829686 and offset 2307
0:00:38.912275118 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basetransform gstbasetransform.c:2102:default_generate_output:<capsfilter0>[00m calling prepare buffer
0:00:38.912289993 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basetransform gstbasetransform.c:2109:default_generate_output:<capsfilter0>[00m using allocated buffer in 0x7fa80168a0, out 0x7fa80168a0
0:00:38.912330826 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basetransform gstbasetransform.c:2126:default_generate_output:<capsfilter0>[00m doing inplace transform
0:00:38.912355326 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;35m GST_SCHEDULING gstpad.c:4320:gst_pad_chain_data_unchecked:<appsink0:sink>[00m calling chainfunction &gst_base_sink_chain with buffer buffer: 0x7fa80168a0, pts 0:00:38.501829686, dts 0:00:38.501829686, dur 99:99:99.999999999, size 3110400, offset 2307, offset_end 2308, flags 0x0
0:00:38.912380409 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesink gstbasesink.c:3421:gst_base_sink_chain_unlocked:<appsink0>[00m got times start: 0:00:38.501829686, end: 99:99:99.999999999
0:00:38.912402284 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesink gstbasesink.c:2006:gst_base_sink_get_sync_times:<appsink0>[00m got times start: 0:00:38.501829686, stop: 99:99:99.999999999, do_sync 1
0:00:38.912413950 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;04m default gstsegment.c:737:gst_segment_to_running_time_full:[00m invalid position (-1)
0:00:38.912433783 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesink gstbasesink.c:2591:gst_base_sink_do_sync:<appsink0>[00m reset rc_time to time 0:00:38.501829686
0:00:38.912452741 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesink gstbasesink.c:2603:gst_base_sink_do_sync:<appsink0>[00m possibly waiting for clock to reach 0:00:38.501829686, adjusted 0:00:38.501829686
0:00:38.912466741 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;33m GST_CLOCK gstclock.c:537:gst_clock_id_wait:<GstSystemClock>[00m waiting on clock entry 0x7fa8006480
0:00:38.912484241 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;33m GST_CLOCK gstclock.c:1046:gst_clock_get_internal_time:<GstSystemClock>[00m internal time 7:39:42.419885518
0:00:38.912499699 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;33m GST_CLOCK gstclock.c:1091:gst_clock_get_time:<GstSystemClock>[00m adjusted time 7:39:42.419885518
0:00:38.912520116 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;33m GST_CLOCK gstsystemclock.c:719:gst_system_clock_id_wait_jitter_unlocked:[00m entry 0x7fa8006480 time 7:39:42.419548938 now 7:39:42.419885518 diff (time-now) -336580
0:00:38.912536157 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;33m GST_CLOCK gstclock.c:547:gst_clock_id_wait:<GstSystemClock>[00m done waiting entry 0x7fa8006480, res: 1 (early)
0:00:38.912553948 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesink gstbasesink.c:2610:gst_base_sink_do_sync:<appsink0>[00m clock returned 1, jitter 0:00:00.000336580
0:00:38.912565615 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesink gstbasesink.c:2926:gst_base_sink_is_too_late:<appsink0>[00m frame dropping disabled
0:00:38.912578157 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesink gstbasesink.c:3538:gst_base_sink_chain_unlocked:<appsink0>[00m rendering object 0x7fa80168a0
0:00:38.912591281 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesink gstbasesink.c:994:gst_base_sink_set_last_buffer_unlocked:<appsink0>[00m setting last buffer to 0x7fa80168a0
0:00:38.912618406 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;34m GST_MEMORY gstmemory.c:88:_gst_memory_free:[00m free memory 0x7fa801d700
0:00:38.912638531 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m appsink gstappsink.c:876:gst_app_sink_render_common:<appsink0>[00m pushing render buffer/list 0x7fa80168a0 on queue (0)
0:00:38.912683155 [334m 5601[00m 0x7fa0012520 [37mDEBUG [00m [00m appsink gstappsink.c:1630:gst_app_sink_try_pull_sample:<appsink0>[00m trying to grab a buffer
0:00:38.912699780 [334m 5601[00m 0x7fa0012520 [37mDEBUG [00m [00m appsink gstappsink.c:821:dequeue_buffer:<appsink0>[00m dequeued buffer/list 0x7fa80168a0
0:00:38.912722530 [334m 5601[00m 0x7fa0012520 [37mDEBUG [00m [00m appsink gstappsink.c:1654:gst_app_sink_try_pull_sample:<appsink0>[00m we have a buffer 0x7fa80168a0
0:00:38.914088430 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesink gstbasesink.c:3577:gst_base_sink_chain_unlocked:<appsink0>[00m object unref after render 0x7fa80168a0
0:00:38.914228720 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;35m GST_SCHEDULING gstpad.c:4326:gst_pad_chain_data_unchecked:<appsink0:sink>[00m called chainfunction &gst_base_sink_chain with buffer 0x7fa80168a0, returned ok
0:00:38.914285303 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00;01;35m GST_SCHEDULING gstpad.c:4326:gst_pad_chain_data_unchecked:<capsfilter0:sink>[00m called chainfunction &gst_base_transform_chain with buffer 0x7fa80168a0, returned ok
0:00:38.914340428 [334m 5601[00m 0x55ac4678a0 [37mDEBUG [00m [00m basesrc gstbasesrc.c:2506:gst_base_src_get_range:<xcamsrc0>[00m calling create offset 18446744073709551615 length 4096, time 0
0:00:38.918062884 [334m 5601[00m 0x7fa0012520 [37mDEBUG [00m [00m appsink gstappsink.c:1146:gst_app_sink_is_eos:<appsink0>[00m we are not yet EOS
0:00:38.918120925 [334m 5601[00m 0x7fa0012520 [37mDEBUG [00m [00m appsink gstappsink.c:1630:gst_app_sink_try_pull_sample:<appsink0>[00m trying to grab a buffer
0:00:38.918132591 [334m 5601[00m 0x7fa0012520 [37mDEBUG [00m [00m appsink gstappsink.c:1641:gst_app_sink_try_pull_sample:<appsink0>[00m waiting for a buffer
0:00:39.418246385 [334m 5601[00m 0x7fa0012520 [37mDEBUG [00m [00m appsink gstappsink.c:1674:gst_app_sink_try_pull_sample:<appsink0>[00m timeout expired, return NULL
0:00:39.419157833 [334m 5601[00m 0x7fa0012520 [37mDEBUG [00m [00m appsink gstappsink.c:1146:gst_app_sink_is_eos:<appsink0>[00m we are not yet EOS
0:00:39.419250290 [334m 5601[00m 0x55ac20dc00 [37mDEBUG [00m [00;01;31m GST_STATES gstelement.c:2827:gst_element_set_state_func:<xcamsrc0>[00m set_state to NULL
0:00:39.419274498 [334m 5601[00m 0x55ac20dc00 [37mDEBUG [00m [00;01;31m GST_STATES gstelement.c:2852:gst_element_set_state_func:<xcamsrc0>[00m setting target state to NULL
0:00:39.419294915 [334m 5601[00m 0x55ac20dc00 [37mDEBUG [00m [00;01;31m GST_STATES gstelement.c:2865:gst_element_set_state_func:<xcamsrc0>[00m current PLAYING, old_pending VOID_PENDING, next VOID_PENDING, old return SUCCESS
0:00:39.419312706 [334m 5601[00m 0x55ac20dc00 [37mDEBUG [00m [00;01;31m GST_STATES gstelement.c:2899:gst_element_set_state_func:<xcamsrc0>[00m intermediate: setting state from PLAYING to PAUSED
0:00:39.419330498 [334m 5601[00m 0x55ac20dc00 [37mDEBUG [00m [00m basesrc gstbasesrc.c:3910:gst_base_src_change_state:<xcamsrc0>[00m PLAYING->PAUSED
0:00:39.419344498 [334m 5601[00m 0x55ac20dc00 [37mDEBUG [00m [00m basesrc gstbasesrc.c:3742:gst_base_src_set_playing:<xcamsrc0>[00m unschedule clock
0:00:39.419358206 [334m 5601[00m 0x55ac20dc00 [37mDEBUG [00m [00m basesrc gstbasesrc.c:3749:gst_base_src_set_playing:<xcamsrc0>[00m live running 0
0:00:39.419370456 [334m 5601[00m 0x55ac20dc00 [37mDEBUG [00m [00;01;31m GST_STATES gstelement.c:2995:gst_element_change_state:<xcamsrc0>[00m element changed state NO_PREROLL
0:00:39.419388247 [334m 5601[00m 0x55ac20dc00 [36mINFO [00m [00;01;31m GST_STATES gstelement.c:2651:gst_element_continue_state:<xcamsrc0>[00m committing state from PLAYING to PAUSED, pending NULL, next READY
0:00:39.419405455 [334m 5601[00m 0x55ac20dc00 [36mINFO [00m [00;01;31m GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<xcamsrc0>[00m notifying about state-changed PLAYING to PAUSED (NULL pending)
0:00:39.419463205 [334m 5601[00m 0x55ac20dc00 [37mDEBUG [00m [00;43m GST_BUS gstbus.c:318:gst_bus_post:<bus0>[00m [msg 0x55ac46ad30] posting on bus state-changed message: 0x55ac46ad30, time 99:99:99.999999999, seq-num 39, element 'xcamsrc0', GstMessageStateChanged, old-state=(GstState)GST_STATE_PLAYING, new-state=(GstState)GST_STATE_PAUSED, pending-state=(GstState)GST_STATE_NULL;
0:00:39.419509287 [334m 5601[00m 0x55ac20dc00 [37mDEBUG [00m [00;01m bin gstbin.c:3717:gst_bin_handle_message_func:<pipeline0>[00m [msg 0x55ac46ad30] handling child xcamsrc0 message of type state-changed
0:00:39.419524162 [334m 5601[00m 0x55ac20dc00 [37mDEBUG [00m [00;01m bin gstbin.c:4054:gst_bin_handle_message_func:<pipeline0>[00m posting message upward
0:00:39.419550995 [334m 5601[00m 0x55ac20dc00 [37mDEBUG [00m [00;43m GST_BUS gstbus.c:318:gst_bus_post:<bus1>[00m [msg 0x55ac46ad30] posting on bus state-changed message: 0x55ac46ad30, time 99:99:99.999999999, seq-num 39, element 'xcamsrc0', GstMessageStateChanged, old-state=(GstState)GST_STATE_PLAYING, new-state=(GstState)GST_STATE_PAUSED, pending-state=(GstState)GST_STATE_NULL;
0:00:39.419565578 [334m 5601[00m 0x55ac20dc00 [37mDEBUG [00m [00;43m GST_BUS gstbus.c:357:gst_bus_post:<bus1>[00m [msg 0x55ac46ad30] pushing on async queue
0:00:39.419591245 [334m 5601[00m 0x55ac20dc00 [37mDEBUG [00m [00;43m GST_BUS gstbus.c:360:gst_bus_post:<bus1>[00m [msg 0x55ac46ad30] pushed on async queue
0:00:39.419629744 [334m 5601[00m 0x55ac20dc00 [37mDEBUG [00m [00;43m GST_BUS gstbus.c:353:gst_bus_post:<bus0>[00m [msg 0x55ac46ad30] dropped
0:00:39.419645786 [334m 5601[00m 0x55ac20dc00 [36mINFO [00m [00;01;31m GST_STATES gstelement.c:2658:gst_element_continue_state:<xcamsrc0>[00m continue state change PAUSED to READY, final NULL
0:00:39.419660077 [334m 5601[00m 0x55ac20dc00 [37mDEBUG [00m [00;01;37;41m GST_ELEMENT_PADS gstelement.c:3097:gst_element_pads_activate:<xcamsrc0>[00m deactivate pads
0:00:39.419683702 [334m 5601[00m 0x55ac20dc00 [37mDEBUG [00m [00;01;31;41m GST_PADS gstpad.c:1121:gst_pad_set_active:<xcamsrc0:src>[00m deactivating pad from push mode
0:00:39.419698285 [334m 5601[00m 0x55ac20dc00 [37mDEBUG [00m [00;01;31;41m GST_PADS gstpad.c:991:pre_activate:<xcamsrc0:src>[00m setting PAD_MODE NONE, set flushing
0:00:39.419714910 [334m 5601[00m 0x55ac20dc00 [37mDEBUG [00m [00m basesrc gstbasesrc.c:3858:gst_base_src_activate_mode:<xcamsrc0:src>[00m activating in mode 1
0:00:39.419726868 [334m 5601[00m 0x55ac20dc00 [37mDEBUG [00m [00m basesrc gstbasesrc.c:3792:gst_base_src_activate_push:<xcamsrc0>[00m Deactivating in push mode
0:00:39.419738243 [334m 5601[00m 0x55ac20dc00 [37mDEBUG [00m [00m basesrc gstbasesrc.c:3629:gst_base_src_stop:<xcamsrc0>[00m stopping source
0:00:39.419750201 [334m 5601[00m 0x55ac20dc00 [37mDEBUG [00m [00m basesrc gstbasesrc.c:3679:gst_base_src_set_flushing:<xcamsrc0>[00m flushing 1
0:00:39.419775868 [334m 5601[00m 0x55ac20dc00 [37mDEBUG [00m [00;01;31;41m GST_PADS gstpad.c:6288:gst_pad_stop_task:<xcamsrc0:src>[00m stop task
0:00:39.419793951 [334m 5601[00m 0x55ac20dc00 [37mDEBUG [00m [00m task gsttask.c:688:gst_task_set_state:<xcamsrc0:src>[00m Changing task 0x55ac48e050 to state 1
0:01:24.000659198 [334m 5601[00m 0x55ac20dc00 [36mINFO [00m [00;01;31m GST_INIT gst.c:1083:gst_deinit:[00m deinitializing GStreamer