xvimagesink "waiting in preroll for flush or PLAYING"
iain
iain at sleepfive.com
Tue Sep 25 05:39:33 PDT 2012
Hi
I've got the following pipeline
|- - [queue] - [ffmpegcolorspace] -
[xvimagesink]
[src] - [capsfilter] - [tee]
|- - [valve] - [queue] - [encoder] -
[muxer] - [filesink]
When the valve is set drop:FALSE the pipeline can change to PLAYING
state fine.
When the valve is set drop:TRUE changing the state to PLAYING will
preroll and then just sit, with the debug log saying "waiting in preroll
for flush or PLAYING"
The same thing happens if I completely remove the encoder half of the
pipeline.
What am I missing?
I've attached a log of GST_STATES:5,*sink*:5
thanks,
iain
-------------- next part --------------
0:00:00.016982572 17846 0xa8f600 INFO filesink gstfilesink.c:301:gst_file_sink_set_location: filename : test-file-iain.webm
0:00:00.017008229 17846 0xa8f600 INFO filesink gstfilesink.c:302:gst_file_sink_set_location: uri : file:///home/iain/Projects/sleep5/gst-camera/test-file-iain.webm
0:00:00.026950370 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2638:gst_element_set_state_func:<capture> set_state to PLAYING
0:00:00.026964050 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2663:gst_element_set_state_func:<capture> setting target state to PLAYING
0:00:00.026969953 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2676:gst_element_set_state_func:<capture> current NULL, old_pending VOID_PENDING, next VOID_PENDING, old return SUCCESS
0:00:00.026976106 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2710:gst_element_set_state_func:<capture> intermediate: setting state from NULL to READY
0:00:00.026984119 17846 0xa8f600 DEBUG GST_STATES gstbin.c:2437:gst_bin_change_state_func:<capture> changing state of children from NULL to READY
0:00:00.027004672 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2638:gst_element_set_state_func:<video_filesink> set_state to READY
0:00:00.027010965 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2663:gst_element_set_state_func:<video_filesink> setting target state to READY
0:00:00.027016061 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2676:gst_element_set_state_func:<video_filesink> current NULL, old_pending VOID_PENDING, next VOID_PENDING, old return SUCCESS
0:00:00.027021612 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2710:gst_element_set_state_func:<video_filesink> final: setting state from NULL to READY
0:00:00.027040990 17846 0xa8f600 DEBUG filesink gstfilesink.c:517:gst_file_sink_do_seek:<video_filesink> Seeking to offset 0 using fseeko
0:00:00.027053341 17846 0xa8f600 DEBUG filesink gstfilesink.c:419:gst_file_sink_open_file:<video_filesink> opened file test-file-iain.webm, seekable 1
0:00:00.027059687 17846 0xa8f600 LOG GST_STATES gstelement.c:2984:gst_element_change_state_func:<video_filesink> default handler tries setting state from NULL to READY (000a)
0:00:00.027066075 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2795:gst_element_change_state:<video_filesink> element changed state SUCCESS
0:00:00.027071163 17846 0xa8f600 INFO GST_STATES gstelement.c:2460:gst_element_continue_state:<video_filesink> completed state change to READY
0:00:00.027076388 17846 0xa8f600 INFO GST_STATES gstelement.c:2365:_priv_gst_element_state_changed:<video_filesink> notifying about state-changed NULL to READY (VOID_PENDING pending)
0:00:00.027096319 17846 0xa8f600 LOG GST_STATES gstelement.c:2811:gst_element_change_state:<video_filesink> exit state change 1
0:00:00.027103989 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2722:gst_element_set_state_func:<video_filesink> returned SUCCESS
0:00:00.027109358 17846 0xa8f600 INFO GST_STATES gstbin.c:2526:gst_bin_change_state_func:<capture> child 'video_filesink' changed state to 2(READY) successfully
0:00:00.027117725 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2638:gst_element_set_state_func:<viewfinder_sink> set_state to READY
0:00:00.027123030 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2663:gst_element_set_state_func:<viewfinder_sink> setting target state to READY
0:00:00.027127963 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2676:gst_element_set_state_func:<viewfinder_sink> current NULL, old_pending VOID_PENDING, next VOID_PENDING, old return SUCCESS
0:00:00.027133416 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2710:gst_element_set_state_func:<viewfinder_sink> final: setting state from NULL to READY
0:00:00.027815279 17846 0xa8f600 DEBUG xvimagesink xvimagesink.c:1822:gst_xvimagesink_xcontext_get:<viewfinder_sink> X reports 1920x1200 pixels and 508 mm x 317 mm
0:00:00.027846985 17846 0xa8f600 DEBUG xvimagesink xvimagesink.c:1749:gst_xvimagesink_calculate_pixel_aspect_ratio: calculated pixel aspect ratio: 1.001577
0:00:00.027880609 17846 0xa8f600 DEBUG xvimagesink xvimagesink.c:1764:gst_xvimagesink_calculate_pixel_aspect_ratio: Decided on index 0 (1/1)
0:00:00.027893393 17846 0xa8f600 DEBUG xvimagesink xvimagesink.c:1772:gst_xvimagesink_calculate_pixel_aspect_ratio: set xcontext PAR to 1/1
0:00:00.028315227 17846 0xa8f600 DEBUG xvimagesink xvimagesink.c:1413:gst_xvimagesink_get_xv_support: Found 1 XV adaptor(s)
0:00:00.028348391 17846 0xa8f600 DEBUG xvimagesink xvimagesink.c:1368:gst_lookup_xv_port_from_adaptor: GrabPort 0 for XV Adaptor Radeon Textured Video failed: 2
0:00:00.028376710 17846 0xa8f600 DEBUG xvimagesink xvimagesink.c:1365:gst_lookup_xv_port_from_adaptor: XV Adaptor Radeon Textured Video with 16 ports
0:00:00.028407772 17846 0xa8f600 DEBUG xvimagesink xvimagesink.c:1456:gst_xvimagesink_get_xv_support:<viewfinder_sink> Checking 7 Xv port attributes
0:00:00.028435889 17846 0xa8f600 LOG xvimagesink xvimagesink.c:1541:gst_xvimagesink_get_xv_support:<viewfinder_sink> Encoding 0, name XV_IMAGE, max wxh 16384x16384 rate 1/1
0:00:00.028482736 17846 0xa8f600 DEBUG xvimagesink xvimagesink.c:1639:gst_xvimagesink_get_xv_support: Generated the following caps: video/x-raw-yuv, format=(fourcc)YUY2, width=(int)[ 1, 16384 ], height=(int)[ 1, 16384 ], framerate=(fraction)[ 0/1, 2147483647/1 ]; video/x-raw-yuv, format=(fourcc)YV12, width=(int)[ 1, 16384 ], height=(int)[ 1, 16384 ], framerate=(fraction)[ 0/1, 2147483647/1 ]; video/x-raw-yuv, format=(fourcc)I420, width=(int)[ 1, 16384 ], height=(int)[ 1, 16384 ], framerate=(fraction)[ 0/1, 2147483647/1 ]; video/x-raw-yuv, format=(fourcc)UYVY, width=(int)[ 1, 16384 ], height=(int)[ 1, 16384 ], framerate=(fraction)[ 0/1, 2147483647/1 ]
0:00:00.028574698 17846 0xa8f600 DEBUG xvimagesink xvimagesink.c:437:gst_xvimagesink_check_xshm_calls: XvShmCreateImage of 1x1
0:00:00.028706509 17846 0xa8f600 DEBUG xvimagesink xvimagesink.c:483:gst_xvimagesink_check_xshm_calls: XServer ShmAttached to 0x29db0003, id 0x2800001
0:00:00.028737995 17846 0xa8f600 DEBUG xvimagesink xvimagesink.c:502:gst_xvimagesink_check_xshm_calls: XServer ShmDetaching from 0x29db0003 id 0x2800001
0:00:00.028779940 17846 0xa8f600 DEBUG xvimagesink xvimagesink.c:1879:gst_xvimagesink_xcontext_get: xvimagesink is using XShm extension
0:00:00.028973530 17846 0xa8f600 DEBUG xvimagesink xvimagesink.c:2303:gst_xvimagesink_change_state:<viewfinder_sink> set calculated PAR on object's PAR
0:00:00.028982277 17846 0xa8f600 DEBUG xvimagesink xvimagesink.c:2307:gst_xvimagesink_change_state:<viewfinder_sink> XSynchronize called with FALSE
0:00:00.028988180 17846 0xa8f600 DEBUG xvimagesink xvimagesink.c:1689:gst_xvimagesink_manage_event_thread:<viewfinder_sink> run xevent thread, expose 1, events 1
0:00:00.029030554 17846 0xa8f600 LOG GST_STATES gstelement.c:2984:gst_element_change_state_func:<viewfinder_sink> default handler tries setting state from NULL to READY (000a)
0:00:00.029040344 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2795:gst_element_change_state:<viewfinder_sink> element changed state SUCCESS
0:00:00.029045908 17846 0xa8f600 INFO GST_STATES gstelement.c:2460:gst_element_continue_state:<viewfinder_sink> completed state change to READY
0:00:00.029051368 17846 0xa8f600 INFO GST_STATES gstelement.c:2365:_priv_gst_element_state_changed:<viewfinder_sink> notifying about state-changed NULL to READY (VOID_PENDING pending)
0:00:00.029064972 17846 0xa8f600 LOG GST_STATES gstelement.c:2811:gst_element_change_state:<viewfinder_sink> exit state change 1
0:00:00.029075813 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2722:gst_element_set_state_func:<viewfinder_sink> returned SUCCESS
0:00:00.029081560 17846 0xa8f600 INFO GST_STATES gstbin.c:2526:gst_bin_change_state_func:<capture> child 'viewfinder_sink' changed state to 2(READY) successfully
0:00:00.029090899 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2638:gst_element_set_state_func:<muxer> set_state to READY
0:00:00.029096541 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2663:gst_element_set_state_func:<muxer> setting target state to READY
0:00:00.029101771 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2676:gst_element_set_state_func:<muxer> current NULL, old_pending VOID_PENDING, next VOID_PENDING, old return SUCCESS
0:00:00.029107771 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2710:gst_element_set_state_func:<muxer> final: setting state from NULL to READY
0:00:00.029115379 17846 0xa8f600 LOG GST_STATES gstelement.c:2984:gst_element_change_state_func:<muxer> default handler tries setting state from NULL to READY (000a)
0:00:00.029121369 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2795:gst_element_change_state:<muxer> element changed state SUCCESS
0:00:00.029126431 17846 0xa8f600 INFO GST_STATES gstelement.c:2460:gst_element_continue_state:<muxer> completed state change to READY
0:00:00.029131649 17846 0xa8f600 INFO GST_STATES gstelement.c:2365:_priv_gst_element_state_changed:<muxer> notifying about state-changed NULL to READY (VOID_PENDING pending)
0:00:00.029142112 17846 0xa8f600 LOG GST_STATES gstelement.c:2811:gst_element_change_state:<muxer> exit state change 1
0:00:00.029148108 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2722:gst_element_set_state_func:<muxer> returned SUCCESS
0:00:00.029153390 17846 0xa8f600 INFO GST_STATES gstbin.c:2526:gst_bin_change_state_func:<capture> child 'muxer' changed state to 2(READY) successfully
0:00:00.029161472 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2638:gst_element_set_state_func:<viewfinder_colorspace> set_state to READY
0:00:00.029167130 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2663:gst_element_set_state_func:<viewfinder_colorspace> setting target state to READY
0:00:00.029172313 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2676:gst_element_set_state_func:<viewfinder_colorspace> current NULL, old_pending VOID_PENDING, next VOID_PENDING, old return SUCCESS
0:00:00.029178262 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2710:gst_element_set_state_func:<viewfinder_colorspace> final: setting state from NULL to READY
0:00:00.029183896 17846 0xa8f600 LOG GST_STATES gstelement.c:2984:gst_element_change_state_func:<viewfinder_colorspace> default handler tries setting state from NULL to READY (000a)
0:00:00.029189630 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2795:gst_element_change_state:<viewfinder_colorspace> element changed state SUCCESS
0:00:00.029194669 17846 0xa8f600 INFO GST_STATES gstelement.c:2460:gst_element_continue_state:<viewfinder_colorspace> completed state change to READY
0:00:00.029199866 17846 0xa8f600 INFO GST_STATES gstelement.c:2365:_priv_gst_element_state_changed:<viewfinder_colorspace> notifying about state-changed NULL to READY (VOID_PENDING pending)
0:00:00.029209500 17846 0xa8f600 LOG GST_STATES gstelement.c:2811:gst_element_change_state:<viewfinder_colorspace> exit state change 1
0:00:00.029215443 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2722:gst_element_set_state_func:<viewfinder_colorspace> returned SUCCESS
0:00:00.029220718 17846 0xa8f600 INFO GST_STATES gstbin.c:2526:gst_bin_change_state_func:<capture> child 'viewfinder_colorspace' changed state to 2(READY) successfully
0:00:00.029232179 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2638:gst_element_set_state_func:<video_encoder> set_state to READY
0:00:00.029237942 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2663:gst_element_set_state_func:<video_encoder> setting target state to READY
0:00:00.029243094 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2676:gst_element_set_state_func:<video_encoder> current NULL, old_pending VOID_PENDING, next VOID_PENDING, old return SUCCESS
0:00:00.029248930 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2710:gst_element_set_state_func:<video_encoder> final: setting state from NULL to READY
0:00:00.029254862 17846 0xa8f600 LOG GST_STATES gstelement.c:2984:gst_element_change_state_func:<video_encoder> default handler tries setting state from NULL to READY (000a)
0:00:00.029260664 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2795:gst_element_change_state:<video_encoder> element changed state SUCCESS
0:00:00.029265739 17846 0xa8f600 INFO GST_STATES gstelement.c:2460:gst_element_continue_state:<video_encoder> completed state change to READY
0:00:00.029271003 17846 0xa8f600 INFO GST_STATES gstelement.c:2365:_priv_gst_element_state_changed:<video_encoder> notifying about state-changed NULL to READY (VOID_PENDING pending)
0:00:00.029280970 17846 0xa8f600 LOG GST_STATES gstelement.c:2811:gst_element_change_state:<video_encoder> exit state change 1
0:00:00.029286870 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2722:gst_element_set_state_func:<video_encoder> returned SUCCESS
0:00:00.029292164 17846 0xa8f600 INFO GST_STATES gstbin.c:2526:gst_bin_change_state_func:<capture> child 'video_encoder' changed state to 2(READY) successfully
0:00:00.029300131 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2638:gst_element_set_state_func:<viewfinder_queue> set_state to READY
0:00:00.029305665 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2663:gst_element_set_state_func:<viewfinder_queue> setting target state to READY
0:00:00.029310795 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2676:gst_element_set_state_func:<viewfinder_queue> current NULL, old_pending VOID_PENDING, next VOID_PENDING, old return SUCCESS
0:00:00.029316610 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2710:gst_element_set_state_func:<viewfinder_queue> final: setting state from NULL to READY
0:00:00.029322164 17846 0xa8f600 LOG GST_STATES gstelement.c:2984:gst_element_change_state_func:<viewfinder_queue> default handler tries setting state from NULL to READY (000a)
0:00:00.029327828 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2795:gst_element_change_state:<viewfinder_queue> element changed state SUCCESS
0:00:00.029332856 17846 0xa8f600 INFO GST_STATES gstelement.c:2460:gst_element_continue_state:<viewfinder_queue> completed state change to READY
0:00:00.029338062 17846 0xa8f600 INFO GST_STATES gstelement.c:2365:_priv_gst_element_state_changed:<viewfinder_queue> notifying about state-changed NULL to READY (VOID_PENDING pending)
0:00:00.029347595 17846 0xa8f600 LOG GST_STATES gstelement.c:2811:gst_element_change_state:<viewfinder_queue> exit state change 1
0:00:00.029353484 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2722:gst_element_set_state_func:<viewfinder_queue> returned SUCCESS
0:00:00.029358779 17846 0xa8f600 INFO GST_STATES gstbin.c:2526:gst_bin_change_state_func:<capture> child 'viewfinder_queue' changed state to 2(READY) successfully
0:00:00.029366616 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2638:gst_element_set_state_func:<encoder_queue> set_state to READY
0:00:00.029372167 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2663:gst_element_set_state_func:<encoder_queue> setting target state to READY
0:00:00.029380181 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2676:gst_element_set_state_func:<encoder_queue> current NULL, old_pending VOID_PENDING, next VOID_PENDING, old return SUCCESS
0:00:00.029386191 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2710:gst_element_set_state_func:<encoder_queue> final: setting state from NULL to READY
0:00:00.029391860 17846 0xa8f600 LOG GST_STATES gstelement.c:2984:gst_element_change_state_func:<encoder_queue> default handler tries setting state from NULL to READY (000a)
0:00:00.029397612 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2795:gst_element_change_state:<encoder_queue> element changed state SUCCESS
0:00:00.029402742 17846 0xa8f600 INFO GST_STATES gstelement.c:2460:gst_element_continue_state:<encoder_queue> completed state change to READY
0:00:00.029407982 17846 0xa8f600 INFO GST_STATES gstelement.c:2365:_priv_gst_element_state_changed:<encoder_queue> notifying about state-changed NULL to READY (VOID_PENDING pending)
0:00:00.029417806 17846 0xa8f600 LOG GST_STATES gstelement.c:2811:gst_element_change_state:<encoder_queue> exit state change 1
0:00:00.029423731 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2722:gst_element_set_state_func:<encoder_queue> returned SUCCESS
0:00:00.029429000 17846 0xa8f600 INFO GST_STATES gstbin.c:2526:gst_bin_change_state_func:<capture> child 'encoder_queue' changed state to 2(READY) successfully
0:00:00.029436939 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2638:gst_element_set_state_func:<encoder_valve> set_state to READY
0:00:00.029442489 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2663:gst_element_set_state_func:<encoder_valve> setting target state to READY
0:00:00.029447665 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2676:gst_element_set_state_func:<encoder_valve> current NULL, old_pending VOID_PENDING, next VOID_PENDING, old return SUCCESS
0:00:00.029453522 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2710:gst_element_set_state_func:<encoder_valve> final: setting state from NULL to READY
0:00:00.029459136 17846 0xa8f600 LOG GST_STATES gstelement.c:2984:gst_element_change_state_func:<encoder_valve> default handler tries setting state from NULL to READY (000a)
0:00:00.029464878 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2795:gst_element_change_state:<encoder_valve> element changed state SUCCESS
0:00:00.029469880 17846 0xa8f600 INFO GST_STATES gstelement.c:2460:gst_element_continue_state:<encoder_valve> completed state change to READY
0:00:00.029475107 17846 0xa8f600 INFO GST_STATES gstelement.c:2365:_priv_gst_element_state_changed:<encoder_valve> notifying about state-changed NULL to READY (VOID_PENDING pending)
0:00:00.029484726 17846 0xa8f600 LOG GST_STATES gstelement.c:2811:gst_element_change_state:<encoder_valve> exit state change 1
0:00:00.029490544 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2722:gst_element_set_state_func:<encoder_valve> returned SUCCESS
0:00:00.029495777 17846 0xa8f600 INFO GST_STATES gstbin.c:2526:gst_bin_change_state_func:<capture> child 'encoder_valve' changed state to 2(READY) successfully
0:00:00.029503709 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2638:gst_element_set_state_func:<video_tee> set_state to READY
0:00:00.029509221 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2663:gst_element_set_state_func:<video_tee> setting target state to READY
0:00:00.029514377 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2676:gst_element_set_state_func:<video_tee> current NULL, old_pending VOID_PENDING, next VOID_PENDING, old return SUCCESS
0:00:00.029520244 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2710:gst_element_set_state_func:<video_tee> final: setting state from NULL to READY
0:00:00.029528849 17846 0xa8f600 LOG GST_STATES gstelement.c:2984:gst_element_change_state_func:<video_tee> default handler tries setting state from NULL to READY (000a)
0:00:00.029534820 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2795:gst_element_change_state:<video_tee> element changed state SUCCESS
0:00:00.029539947 17846 0xa8f600 INFO GST_STATES gstelement.c:2460:gst_element_continue_state:<video_tee> completed state change to READY
0:00:00.029553412 17846 0xa8f600 INFO GST_STATES gstelement.c:2365:_priv_gst_element_state_changed:<video_tee> notifying about state-changed NULL to READY (VOID_PENDING pending)
0:00:00.029570803 17846 0xa8f600 LOG GST_STATES gstelement.c:2811:gst_element_change_state:<video_tee> exit state change 1
0:00:00.029577421 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2722:gst_element_set_state_func:<video_tee> returned SUCCESS
0:00:00.029582770 17846 0xa8f600 INFO GST_STATES gstbin.c:2526:gst_bin_change_state_func:<capture> child 'video_tee' changed state to 2(READY) successfully
0:00:00.029591296 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2638:gst_element_set_state_func:<src_filter> set_state to READY
0:00:00.029596914 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2663:gst_element_set_state_func:<src_filter> setting target state to READY
0:00:00.029602185 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2676:gst_element_set_state_func:<src_filter> current NULL, old_pending VOID_PENDING, next VOID_PENDING, old return SUCCESS
0:00:00.029608144 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2710:gst_element_set_state_func:<src_filter> final: setting state from NULL to READY
0:00:00.029613866 17846 0xa8f600 LOG GST_STATES gstelement.c:2984:gst_element_change_state_func:<src_filter> default handler tries setting state from NULL to READY (000a)
0:00:00.029619752 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2795:gst_element_change_state:<src_filter> element changed state SUCCESS
0:00:00.029624866 17846 0xa8f600 INFO GST_STATES gstelement.c:2460:gst_element_continue_state:<src_filter> completed state change to READY
0:00:00.029630119 17846 0xa8f600 INFO GST_STATES gstelement.c:2365:_priv_gst_element_state_changed:<src_filter> notifying about state-changed NULL to READY (VOID_PENDING pending)
0:00:00.029639863 17846 0xa8f600 LOG GST_STATES gstelement.c:2811:gst_element_change_state:<src_filter> exit state change 1
0:00:00.029645653 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2722:gst_element_set_state_func:<src_filter> returned SUCCESS
0:00:00.029650888 17846 0xa8f600 INFO GST_STATES gstbin.c:2526:gst_bin_change_state_func:<capture> child 'src_filter' changed state to 2(READY) successfully
0:00:00.029657756 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2638:gst_element_set_state_func:<src> set_state to READY
0:00:00.029663177 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2663:gst_element_set_state_func:<src> setting target state to READY
0:00:00.029668334 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2676:gst_element_set_state_func:<src> current NULL, old_pending VOID_PENDING, next VOID_PENDING, old return SUCCESS
0:00:00.029674126 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2710:gst_element_set_state_func:<src> final: setting state from NULL to READY
0:00:00.068031297 17846 0xa8f600 LOG GST_STATES gstelement.c:2984:gst_element_change_state_func:<src> default handler tries setting state from NULL to READY (000a)
0:00:00.068055476 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2795:gst_element_change_state:<src> element changed state SUCCESS
0:00:00.068066795 17846 0xa8f600 INFO GST_STATES gstelement.c:2460:gst_element_continue_state:<src> completed state change to READY
0:00:00.068097019 17846 0xa8f600 INFO GST_STATES gstelement.c:2365:_priv_gst_element_state_changed:<src> notifying about state-changed NULL to READY (VOID_PENDING pending)
0:00:00.068120993 17846 0xa8f600 LOG GST_STATES gstelement.c:2811:gst_element_change_state:<src> exit state change 1
0:00:00.068132713 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2722:gst_element_set_state_func:<src> returned SUCCESS
0:00:00.068142900 17846 0xa8f600 INFO GST_STATES gstbin.c:2526:gst_bin_change_state_func:<capture> child 'src' changed state to 2(READY) successfully
0:00:00.068155994 17846 0xa8f600 DEBUG GST_STATES gstbin.c:2586:gst_bin_change_state_func:<capture> iterator done
0:00:00.068165849 17846 0xa8f600 LOG GST_STATES gstelement.c:2984:gst_element_change_state_func:<capture> default handler tries setting state from NULL to READY (000a)
0:00:00.068182028 17846 0xa8f600 DEBUG GST_STATES gstbin.c:2653:gst_bin_change_state_func:<capture> done changing bin's state from NULL to READY, now in NULL, ret SUCCESS
0:00:00.068194075 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2795:gst_element_change_state:<capture> element changed state SUCCESS
0:00:00.068214836 17846 0xa8f600 INFO GST_STATES gstelement.c:2435:gst_element_continue_state:<capture> committing state from NULL to READY, pending PLAYING, next PAUSED
0:00:00.068226923 17846 0xa8f600 INFO GST_STATES gstelement.c:2365:_priv_gst_element_state_changed:<capture> notifying about state-changed NULL to READY (PLAYING pending)
0:00:00.068253567 17846 0xa8f600 INFO GST_STATES gstelement.c:2442:gst_element_continue_state:<capture> continue state change READY to PAUSED, final PLAYING
0:00:00.068266762 17846 0xa8f600 DEBUG GST_STATES gstbin.c:2437:gst_bin_change_state_func:<capture> changing state of children from READY to PAUSED
0:00:00.068302328 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2638:gst_element_set_state_func:<video_filesink> set_state to PAUSED
0:00:00.068314312 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2663:gst_element_set_state_func:<video_filesink> setting target state to PAUSED
0:00:00.068324092 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2676:gst_element_set_state_func:<video_filesink> current READY, old_pending VOID_PENDING, next VOID_PENDING, old return SUCCESS
0:00:00.068347701 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2710:gst_element_set_state_func:<video_filesink> final: setting state from READY to PAUSED
0:00:00.068359318 17846 0xa8f600 DEBUG basesink gstbasesink.c:5004:gst_base_sink_change_state:<video_filesink> READY to PAUSED
0:00:00.068372122 17846 0xa8f600 DEBUG basesink gstbasesink.c:5026:gst_base_sink_change_state:<video_filesink> doing async state change
0:00:00.068388691 17846 0xa8f600 DEBUG GST_STATES gstbin.c:2885:bin_handle_async_start:<capture> state change busy
0:00:00.068400693 17846 0xa8f600 LOG GST_STATES gstelement.c:2984:gst_element_change_state_func:<video_filesink> default handler tries setting state from READY to PAUSED (0013)
0:00:00.068415605 17846 0xa8f600 DEBUG basesink gstbasesink.c:4239:gst_base_sink_pad_activate:<video_filesink> Trying pull mode first
0:00:00.068426025 17846 0xa8f600 DEBUG basesink gstbasesink.c:4245:gst_base_sink_pad_activate:<video_filesink> pull mode disabled
0:00:00.068435524 17846 0xa8f600 DEBUG basesink gstbasesink.c:4283:gst_base_sink_pad_activate:<video_filesink> Falling back to push mode
0:00:00.068446526 17846 0xa8f600 DEBUG basesink gstbasesink.c:4285:gst_base_sink_pad_activate:<video_filesink> Success activating push mode
0:00:00.068469213 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2777:gst_element_change_state:<video_filesink> element will change state ASYNC
0:00:00.068486015 17846 0xa8f600 LOG GST_STATES gstelement.c:2817:gst_element_change_state:<video_filesink> exit async state change 2
0:00:00.068496257 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2722:gst_element_set_state_func:<video_filesink> returned ASYNC
0:00:00.068506004 17846 0xa8f600 INFO GST_STATES gstbin.c:2532:gst_bin_change_state_func:<capture> child 'video_filesink' is changing state asynchronously to PAUSED
0:00:00.068521158 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2638:gst_element_set_state_func:<viewfinder_sink> set_state to PAUSED
0:00:00.068531568 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2663:gst_element_set_state_func:<viewfinder_sink> setting target state to PAUSED
0:00:00.068541097 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2676:gst_element_set_state_func:<viewfinder_sink> current READY, old_pending VOID_PENDING, next VOID_PENDING, old return SUCCESS
0:00:00.068564807 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2710:gst_element_set_state_func:<viewfinder_sink> final: setting state from READY to PAUSED
0:00:00.068587324 17846 0xa8f600 DEBUG basesink gstbasesink.c:5004:gst_base_sink_change_state:<viewfinder_sink> READY to PAUSED
0:00:00.068598733 17846 0xa8f600 DEBUG basesink gstbasesink.c:5026:gst_base_sink_change_state:<viewfinder_sink> doing async state change
0:00:00.068615160 17846 0xa8f600 DEBUG GST_STATES gstbin.c:2885:bin_handle_async_start:<capture> state change busy
0:00:00.068626789 17846 0xa8f600 LOG GST_STATES gstelement.c:2984:gst_element_change_state_func:<viewfinder_sink> default handler tries setting state from READY to PAUSED (0013)
0:00:00.068641276 17846 0xa8f600 DEBUG basesink gstbasesink.c:4239:gst_base_sink_pad_activate:<viewfinder_sink> Trying pull mode first
0:00:00.068651391 17846 0xa8f600 DEBUG basesink gstbasesink.c:4245:gst_base_sink_pad_activate:<viewfinder_sink> pull mode disabled
0:00:00.068660803 17846 0xa8f600 DEBUG basesink gstbasesink.c:4283:gst_base_sink_pad_activate:<viewfinder_sink> Falling back to push mode
0:00:00.068671495 17846 0xa8f600 DEBUG basesink gstbasesink.c:4285:gst_base_sink_pad_activate:<viewfinder_sink> Success activating push mode
0:00:00.068682229 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2777:gst_element_change_state:<viewfinder_sink> element will change state ASYNC
0:00:00.068691936 17846 0xa8f600 LOG GST_STATES gstelement.c:2817:gst_element_change_state:<viewfinder_sink> exit async state change 2
0:00:00.068711481 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2722:gst_element_set_state_func:<viewfinder_sink> returned ASYNC
0:00:00.068722695 17846 0xa8f600 INFO GST_STATES gstbin.c:2532:gst_bin_change_state_func:<capture> child 'viewfinder_sink' is changing state asynchronously to PAUSED
0:00:00.068738072 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2638:gst_element_set_state_func:<muxer> set_state to PAUSED
0:00:00.068748366 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2663:gst_element_set_state_func:<muxer> setting target state to PAUSED
0:00:00.068757804 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2676:gst_element_set_state_func:<muxer> current READY, old_pending VOID_PENDING, next VOID_PENDING, old return SUCCESS
0:00:00.068768286 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2710:gst_element_set_state_func:<muxer> final: setting state from READY to PAUSED
0:00:00.068779925 17846 0xa8f600 LOG GST_STATES gstelement.c:2984:gst_element_change_state_func:<muxer> default handler tries setting state from READY to PAUSED (0013)
0:00:00.068794592 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2795:gst_element_change_state:<muxer> element changed state SUCCESS
0:00:00.068810911 17846 0xa8f600 INFO GST_STATES gstelement.c:2460:gst_element_continue_state:<muxer> completed state change to PAUSED
0:00:00.068820883 17846 0xa8f600 INFO GST_STATES gstelement.c:2365:_priv_gst_element_state_changed:<muxer> notifying about state-changed READY to PAUSED (VOID_PENDING pending)
0:00:00.068852319 17846 0xa8f600 LOG GST_STATES gstelement.c:2811:gst_element_change_state:<muxer> exit state change 1
0:00:00.068863689 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2722:gst_element_set_state_func:<muxer> returned SUCCESS
0:00:00.068873458 17846 0xa8f600 INFO GST_STATES gstbin.c:2526:gst_bin_change_state_func:<capture> child 'muxer' changed state to 3(PAUSED) successfully
0:00:00.068888413 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2638:gst_element_set_state_func:<viewfinder_colorspace> set_state to PAUSED
0:00:00.068898885 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2663:gst_element_set_state_func:<viewfinder_colorspace> setting target state to PAUSED
0:00:00.068908722 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2676:gst_element_set_state_func:<viewfinder_colorspace> current READY, old_pending VOID_PENDING, next VOID_PENDING, old return SUCCESS
0:00:00.068919574 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2710:gst_element_set_state_func:<viewfinder_colorspace> final: setting state from READY to PAUSED
0:00:00.068929941 17846 0xa8f600 LOG GST_STATES gstelement.c:2984:gst_element_change_state_func:<viewfinder_colorspace> default handler tries setting state from READY to PAUSED (0013)
0:00:00.069006688 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2795:gst_element_change_state:<viewfinder_colorspace> element changed state SUCCESS
0:00:00.069019622 17846 0xa8f600 INFO GST_STATES gstelement.c:2460:gst_element_continue_state:<viewfinder_colorspace> completed state change to PAUSED
0:00:00.069029739 17846 0xa8f600 INFO GST_STATES gstelement.c:2365:_priv_gst_element_state_changed:<viewfinder_colorspace> notifying about state-changed READY to PAUSED (VOID_PENDING pending)
0:00:00.069049423 17846 0xa8f600 LOG GST_STATES gstelement.c:2811:gst_element_change_state:<viewfinder_colorspace> exit state change 1
0:00:00.069060543 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2722:gst_element_set_state_func:<viewfinder_colorspace> returned SUCCESS
0:00:00.069070177 17846 0xa8f600 INFO GST_STATES gstbin.c:2526:gst_bin_change_state_func:<capture> child 'viewfinder_colorspace' changed state to 3(PAUSED) successfully
0:00:00.069097331 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2638:gst_element_set_state_func:<video_encoder> set_state to PAUSED
0:00:00.069107916 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2663:gst_element_set_state_func:<video_encoder> setting target state to PAUSED
0:00:00.069117383 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2676:gst_element_set_state_func:<video_encoder> current READY, old_pending VOID_PENDING, next VOID_PENDING, old return SUCCESS
0:00:00.069128100 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2710:gst_element_set_state_func:<video_encoder> final: setting state from READY to PAUSED
0:00:00.069141612 17846 0xa8f600 LOG GST_STATES gstelement.c:2984:gst_element_change_state_func:<video_encoder> default handler tries setting state from READY to PAUSED (0013)
0:00:00.069157833 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2795:gst_element_change_state:<video_encoder> element changed state SUCCESS
0:00:00.069167998 17846 0xa8f600 INFO GST_STATES gstelement.c:2460:gst_element_continue_state:<video_encoder> completed state change to PAUSED
0:00:00.069177828 17846 0xa8f600 INFO GST_STATES gstelement.c:2365:_priv_gst_element_state_changed:<video_encoder> notifying about state-changed READY to PAUSED (VOID_PENDING pending)
0:00:00.069214193 17846 0xa8f600 LOG GST_STATES gstelement.c:2811:gst_element_change_state:<video_encoder> exit state change 1
0:00:00.069226783 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2722:gst_element_set_state_func:<video_encoder> returned SUCCESS
0:00:00.069236502 17846 0xa8f600 INFO GST_STATES gstbin.c:2526:gst_bin_change_state_func:<capture> child 'video_encoder' changed state to 3(PAUSED) successfully
0:00:00.069251239 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2638:gst_element_set_state_func:<viewfinder_queue> set_state to PAUSED
0:00:00.069261409 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2663:gst_element_set_state_func:<viewfinder_queue> setting target state to PAUSED
0:00:00.069270891 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2676:gst_element_set_state_func:<viewfinder_queue> current READY, old_pending VOID_PENDING, next VOID_PENDING, old return SUCCESS
0:00:00.069281451 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2710:gst_element_set_state_func:<viewfinder_queue> final: setting state from READY to PAUSED
0:00:00.069291825 17846 0xa8f600 LOG GST_STATES gstelement.c:2984:gst_element_change_state_func:<viewfinder_queue> default handler tries setting state from READY to PAUSED (0013)
0:00:00.069399863 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2795:gst_element_change_state:<viewfinder_queue> element changed state SUCCESS
0:00:00.069416050 17846 0xa8f600 INFO GST_STATES gstelement.c:2460:gst_element_continue_state:<viewfinder_queue> completed state change to PAUSED
0:00:00.069426372 17846 0xa8f600 INFO GST_STATES gstelement.c:2365:_priv_gst_element_state_changed:<viewfinder_queue> notifying about state-changed READY to PAUSED (VOID_PENDING pending)
0:00:00.069447548 17846 0xa8f600 LOG GST_STATES gstelement.c:2811:gst_element_change_state:<viewfinder_queue> exit state change 1
0:00:00.069472090 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2722:gst_element_set_state_func:<viewfinder_queue> returned SUCCESS
0:00:00.069482334 17846 0xa8f600 INFO GST_STATES gstbin.c:2526:gst_bin_change_state_func:<capture> child 'viewfinder_queue' changed state to 3(PAUSED) successfully
0:00:00.069498571 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2638:gst_element_set_state_func:<encoder_queue> set_state to PAUSED
0:00:00.069509110 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2663:gst_element_set_state_func:<encoder_queue> setting target state to PAUSED
0:00:00.069518770 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2676:gst_element_set_state_func:<encoder_queue> current READY, old_pending VOID_PENDING, next VOID_PENDING, old return SUCCESS
0:00:00.069529435 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2710:gst_element_set_state_func:<encoder_queue> final: setting state from READY to PAUSED
0:00:00.069539892 17846 0xa8f600 LOG GST_STATES gstelement.c:2984:gst_element_change_state_func:<encoder_queue> default handler tries setting state from READY to PAUSED (0013)
0:00:00.069716177 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2795:gst_element_change_state:<encoder_queue> element changed state SUCCESS
0:00:00.069734876 17846 0xa8f600 INFO GST_STATES gstelement.c:2460:gst_element_continue_state:<encoder_queue> completed state change to PAUSED
0:00:00.069745806 17846 0xa8f600 INFO GST_STATES gstelement.c:2365:_priv_gst_element_state_changed:<encoder_queue> notifying about state-changed READY to PAUSED (VOID_PENDING pending)
0:00:00.069767347 17846 0xa8f600 LOG GST_STATES gstelement.c:2811:gst_element_change_state:<encoder_queue> exit state change 1
0:00:00.069778922 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2722:gst_element_set_state_func:<encoder_queue> returned SUCCESS
0:00:00.069795238 17846 0xa8f600 INFO GST_STATES gstbin.c:2526:gst_bin_change_state_func:<capture> child 'encoder_queue' changed state to 3(PAUSED) successfully
0:00:00.069811190 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2638:gst_element_set_state_func:<encoder_valve> set_state to PAUSED
0:00:00.069821425 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2663:gst_element_set_state_func:<encoder_valve> setting target state to PAUSED
0:00:00.069843119 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2676:gst_element_set_state_func:<encoder_valve> current READY, old_pending VOID_PENDING, next VOID_PENDING, old return SUCCESS
0:00:00.069854188 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2710:gst_element_set_state_func:<encoder_valve> final: setting state from READY to PAUSED
0:00:00.069864608 17846 0xa8f600 LOG GST_STATES gstelement.c:2984:gst_element_change_state_func:<encoder_valve> default handler tries setting state from READY to PAUSED (0013)
0:00:00.069880227 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2795:gst_element_change_state:<encoder_valve> element changed state SUCCESS
0:00:00.069890272 17846 0xa8f600 INFO GST_STATES gstelement.c:2460:gst_element_continue_state:<encoder_valve> completed state change to PAUSED
0:00:00.069899894 17846 0xa8f600 INFO GST_STATES gstelement.c:2365:_priv_gst_element_state_changed:<encoder_valve> notifying about state-changed READY to PAUSED (VOID_PENDING pending)
0:00:00.069918880 17846 0xa8f600 LOG GST_STATES gstelement.c:2811:gst_element_change_state:<encoder_valve> exit state change 1
0:00:00.069929830 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2722:gst_element_set_state_func:<encoder_valve> returned SUCCESS
0:00:00.069939442 17846 0xa8f600 INFO GST_STATES gstbin.c:2526:gst_bin_change_state_func:<capture> child 'encoder_valve' changed state to 3(PAUSED) successfully
0:00:00.069964631 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2638:gst_element_set_state_func:<video_tee> set_state to PAUSED
0:00:00.069976115 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2663:gst_element_set_state_func:<video_tee> setting target state to PAUSED
0:00:00.069985572 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2676:gst_element_set_state_func:<video_tee> current READY, old_pending VOID_PENDING, next VOID_PENDING, old return SUCCESS
0:00:00.069996189 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2710:gst_element_set_state_func:<video_tee> final: setting state from READY to PAUSED
0:00:00.070006596 17846 0xa8f600 LOG GST_STATES gstelement.c:2984:gst_element_change_state_func:<video_tee> default handler tries setting state from READY to PAUSED (0013)
0:00:00.070022946 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2795:gst_element_change_state:<video_tee> element changed state SUCCESS
0:00:00.070033038 17846 0xa8f600 INFO GST_STATES gstelement.c:2460:gst_element_continue_state:<video_tee> completed state change to PAUSED
0:00:00.070042682 17846 0xa8f600 INFO GST_STATES gstelement.c:2365:_priv_gst_element_state_changed:<video_tee> notifying about state-changed READY to PAUSED (VOID_PENDING pending)
0:00:00.070061079 17846 0xa8f600 LOG GST_STATES gstelement.c:2811:gst_element_change_state:<video_tee> exit state change 1
0:00:00.070071956 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2722:gst_element_set_state_func:<video_tee> returned SUCCESS
0:00:00.070093108 17846 0xa8f600 INFO GST_STATES gstbin.c:2526:gst_bin_change_state_func:<capture> child 'video_tee' changed state to 3(PAUSED) successfully
0:00:00.070108432 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2638:gst_element_set_state_func:<src_filter> set_state to PAUSED
0:00:00.070124791 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2663:gst_element_set_state_func:<src_filter> setting target state to PAUSED
0:00:00.070134401 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2676:gst_element_set_state_func:<src_filter> current READY, old_pending VOID_PENDING, next VOID_PENDING, old return SUCCESS
0:00:00.070145083 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2710:gst_element_set_state_func:<src_filter> final: setting state from READY to PAUSED
0:00:00.070155452 17846 0xa8f600 LOG GST_STATES gstelement.c:2984:gst_element_change_state_func:<src_filter> default handler tries setting state from READY to PAUSED (0013)
0:00:00.070212872 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2795:gst_element_change_state:<src_filter> element changed state SUCCESS
0:00:00.070225394 17846 0xa8f600 INFO GST_STATES gstelement.c:2460:gst_element_continue_state:<src_filter> completed state change to PAUSED
0:00:00.070235294 17846 0xa8f600 INFO GST_STATES gstelement.c:2365:_priv_gst_element_state_changed:<src_filter> notifying about state-changed READY to PAUSED (VOID_PENDING pending)
0:00:00.070255868 17846 0xa8f600 LOG GST_STATES gstelement.c:2811:gst_element_change_state:<src_filter> exit state change 1
0:00:00.070267000 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2722:gst_element_set_state_func:<src_filter> returned SUCCESS
0:00:00.070276657 17846 0xa8f600 INFO GST_STATES gstbin.c:2526:gst_bin_change_state_func:<capture> child 'src_filter' changed state to 3(PAUSED) successfully
0:00:00.070289791 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2638:gst_element_set_state_func:<src> set_state to PAUSED
0:00:00.070299686 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2663:gst_element_set_state_func:<src> setting target state to PAUSED
0:00:00.070309058 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2676:gst_element_set_state_func:<src> current READY, old_pending VOID_PENDING, next VOID_PENDING, old return SUCCESS
0:00:00.070319915 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2710:gst_element_set_state_func:<src> final: setting state from READY to PAUSED
0:00:00.070342574 17846 0xa8f600 LOG GST_STATES gstelement.c:2984:gst_element_change_state_func:<src> default handler tries setting state from READY to PAUSED (0013)
0:00:01.884811664 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2802:gst_element_change_state:<src> element changed state NO_PREROLL
0:00:01.884840740 17846 0xa8f600 INFO GST_STATES gstelement.c:2460:gst_element_continue_state:<src> completed state change to PAUSED
0:00:01.884852417 17846 0xa8f600 INFO GST_STATES gstelement.c:2365:_priv_gst_element_state_changed:<src> notifying about state-changed READY to PAUSED (VOID_PENDING pending)
0:00:01.884874923 17846 0xa8f600 LOG GST_STATES gstelement.c:2811:gst_element_change_state:<src> exit state change 3
0:00:01.884889690 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2722:gst_element_set_state_func:<src> returned NO PREROLL
0:00:01.884900835 17846 0xa8f600 INFO GST_STATES gstbin.c:2570:gst_bin_change_state_func:<capture> child 'src' changed state to 3(PAUSED) successfully without preroll
0:00:01.884915437 17846 0xa8f600 DEBUG GST_STATES gstbin.c:2586:gst_bin_change_state_func:<capture> iterator done
0:00:01.884925269 17846 0xa8f600 LOG GST_STATES gstelement.c:2984:gst_element_change_state_func:<capture> default handler tries setting state from READY to PAUSED (0013)
0:00:01.884939283 17846 0xa8f600 DEBUG GST_STATES gstbin.c:2599:gst_bin_change_state_func:<capture> we have NO_PREROLL elements SUCCESS -> NO_PREROLL
0:00:01.884953495 17846 0xa8f600 DEBUG GST_STATES gstbin.c:2653:gst_bin_change_state_func:<capture> done changing bin's state from READY to PAUSED, now in READY, ret NO PREROLL
0:00:01.884975729 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2802:gst_element_change_state:<capture> element changed state NO_PREROLL
0:00:01.884986338 17846 0xa8f600 INFO GST_STATES gstelement.c:2435:gst_element_continue_state:<capture> committing state from READY to PAUSED, pending PLAYING, next PLAYING
0:00:01.884997445 17846 0xa8f600 INFO GST_STATES gstelement.c:2365:_priv_gst_element_state_changed:<capture> notifying about state-changed READY to PAUSED (PLAYING pending)
0:00:01.885015872 17846 0xa8f600 INFO GST_STATES gstelement.c:2442:gst_element_continue_state:<capture> continue state change PAUSED to PLAYING, final PLAYING
0:00:01.885297749 17846 0xa8f600 DEBUG GST_STATES gstbin.c:2437:gst_bin_change_state_func:<capture> changing state of children from PAUSED to PLAYING
0:00:01.885328848 17846 0xa8f600 DEBUG GST_STATES gstbin.c:1664:bin_element_is_sink:<capture> child encoder_valve is not sink
0:00:01.885342322 17846 0xa8f600 DEBUG GST_STATES gstbin.c:1664:bin_element_is_sink:<capture> child encoder_queue is not sink
0:00:01.885352977 17846 0xa8f600 DEBUG GST_STATES gstbin.c:1664:bin_element_is_sink:<capture> child viewfinder_queue is not sink
0:00:01.885363489 17846 0xa8f600 DEBUG GST_STATES gstbin.c:1664:bin_element_is_sink:<capture> child video_filesink is sink
0:00:01.885375416 17846 0xa8f600 DEBUG basesink gstbasesink.c:1180:gst_base_sink_query_latency:<video_filesink> we are not yet ready for LATENCY query
0:00:01.885388448 17846 0xa8f600 DEBUG basesink gstbasesink.c:1188:gst_base_sink_query_latency:<video_filesink> latency query failed but we are not live
0:00:01.885398015 17846 0xa8f600 DEBUG basesink gstbasesink.c:1197:gst_base_sink_query_latency:<video_filesink> latency query: live: 0, have_latency 0, upstream: 0, min 0:00:00.000000000, max 99:99:99.999999999
0:00:01.885413521 17846 0xa8f600 DEBUG basesink gstbasesink.c:4947:default_element_query:<video_filesink> query latency returns 1
0:00:01.885428121 17846 0xa8f600 DEBUG GST_STATES gstbin.c:1664:bin_element_is_sink:<capture> child muxer is not sink
0:00:01.885439355 17846 0xa8f600 DEBUG GST_STATES gstbin.c:1664:bin_element_is_sink:<capture> child video_encoder is not sink
0:00:01.885449667 17846 0xa8f600 DEBUG GST_STATES gstbin.c:1664:bin_element_is_sink:<capture> child viewfinder_sink is sink
0:00:01.885460464 17846 0xa8f600 DEBUG basesink gstbasesink.c:1180:gst_base_sink_query_latency:<viewfinder_sink> we are not yet ready for LATENCY query
0:00:01.885470034 17846 0xa8f600 DEBUG basesink gstbasesink.c:1190:gst_base_sink_query_latency:<viewfinder_sink> latency query failed and we are live
0:00:01.885479726 17846 0xa8f600 DEBUG basesink gstbasesink.c:4947:default_element_query:<viewfinder_sink> query latency returns 0
0:00:01.885490541 17846 0xa8f600 DEBUG GST_STATES gstbin.c:1664:bin_element_is_sink:<capture> child viewfinder_colorspace is not sink
0:00:01.885501020 17846 0xa8f600 DEBUG GST_STATES gstbin.c:1664:bin_element_is_sink:<capture> child video_tee is not sink
0:00:01.885511192 17846 0xa8f600 DEBUG GST_STATES gstbin.c:1664:bin_element_is_sink:<capture> child src_filter is not sink
0:00:01.885521424 17846 0xa8f600 DEBUG GST_STATES gstbin.c:1664:bin_element_is_sink:<capture> child src is not sink
0:00:01.885648167 17846 0xa8f600 INFO GST_STATES gstbin.c:2532:gst_bin_change_state_func:<capture> child 'video_filesink' is changing state asynchronously to PLAYING
0:00:01.885667961 17846 0xa8f600 INFO GST_STATES gstbin.c:2532:gst_bin_change_state_func:<capture> child 'viewfinder_sink' is changing state asynchronously to PLAYING
0:00:01.885690395 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2638:gst_element_set_state_func:<muxer> set_state to PLAYING
0:00:01.885701144 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2663:gst_element_set_state_func:<muxer> setting target state to PLAYING
0:00:01.885710811 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2676:gst_element_set_state_func:<muxer> current PAUSED, old_pending VOID_PENDING, next VOID_PENDING, old return SUCCESS
0:00:01.885721573 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2710:gst_element_set_state_func:<muxer> final: setting state from PAUSED to PLAYING
0:00:01.885732803 17846 0xa8f600 LOG GST_STATES gstelement.c:2984:gst_element_change_state_func:<muxer> default handler tries setting state from PAUSED to PLAYING (001c)
0:00:01.885743887 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2795:gst_element_change_state:<muxer> element changed state SUCCESS
0:00:01.885753459 17846 0xa8f600 INFO GST_STATES gstelement.c:2460:gst_element_continue_state:<muxer> completed state change to PLAYING
0:00:01.885763031 17846 0xa8f600 INFO GST_STATES gstelement.c:2365:_priv_gst_element_state_changed:<muxer> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)
0:00:01.885783668 17846 0xa8f600 LOG GST_STATES gstelement.c:2811:gst_element_change_state:<muxer> exit state change 1
0:00:01.885794762 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2722:gst_element_set_state_func:<muxer> returned SUCCESS
0:00:01.885804545 17846 0xa8f600 INFO GST_STATES gstbin.c:2526:gst_bin_change_state_func:<capture> child 'muxer' changed state to 4(PLAYING) successfully
0:00:01.885819081 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2638:gst_element_set_state_func:<viewfinder_colorspace> set_state to PLAYING
0:00:01.885829218 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2663:gst_element_set_state_func:<viewfinder_colorspace> setting target state to PLAYING
0:00:01.885838606 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2676:gst_element_set_state_func:<viewfinder_colorspace> current PAUSED, old_pending VOID_PENDING, next VOID_PENDING, old return SUCCESS
0:00:01.885849280 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2710:gst_element_set_state_func:<viewfinder_colorspace> final: setting state from PAUSED to PLAYING
0:00:01.885859540 17846 0xa8f600 LOG GST_STATES gstelement.c:2984:gst_element_change_state_func:<viewfinder_colorspace> default handler tries setting state from PAUSED to PLAYING (001c)
0:00:01.885870157 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2795:gst_element_change_state:<viewfinder_colorspace> element changed state SUCCESS
0:00:01.885879569 17846 0xa8f600 INFO GST_STATES gstelement.c:2460:gst_element_continue_state:<viewfinder_colorspace> completed state change to PLAYING
0:00:01.885889111 17846 0xa8f600 INFO GST_STATES gstelement.c:2365:_priv_gst_element_state_changed:<viewfinder_colorspace> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)
0:00:01.885907130 17846 0xa8f600 LOG GST_STATES gstelement.c:2811:gst_element_change_state:<viewfinder_colorspace> exit state change 1
0:00:01.885918127 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2722:gst_element_set_state_func:<viewfinder_colorspace> returned SUCCESS
0:00:01.885927771 17846 0xa8f600 INFO GST_STATES gstbin.c:2526:gst_bin_change_state_func:<capture> child 'viewfinder_colorspace' changed state to 4(PLAYING) successfully
0:00:01.885942306 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2638:gst_element_set_state_func:<video_encoder> set_state to PLAYING
0:00:01.885952753 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2663:gst_element_set_state_func:<video_encoder> setting target state to PLAYING
0:00:01.885968230 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2676:gst_element_set_state_func:<video_encoder> current PAUSED, old_pending VOID_PENDING, next VOID_PENDING, old return SUCCESS
0:00:01.885979137 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2710:gst_element_set_state_func:<video_encoder> final: setting state from PAUSED to PLAYING
0:00:01.885990274 17846 0xa8f600 LOG GST_STATES gstelement.c:2984:gst_element_change_state_func:<video_encoder> default handler tries setting state from PAUSED to PLAYING (001c)
0:00:01.886000848 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2795:gst_element_change_state:<video_encoder> element changed state SUCCESS
0:00:01.886010185 17846 0xa8f600 INFO GST_STATES gstelement.c:2460:gst_element_continue_state:<video_encoder> completed state change to PLAYING
0:00:01.886019570 17846 0xa8f600 INFO GST_STATES gstelement.c:2365:_priv_gst_element_state_changed:<video_encoder> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)
0:00:01.886037499 17846 0xa8f600 LOG GST_STATES gstelement.c:2811:gst_element_change_state:<video_encoder> exit state change 1
0:00:01.886048278 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2722:gst_element_set_state_func:<video_encoder> returned SUCCESS
0:00:01.886057883 17846 0xa8f600 INFO GST_STATES gstbin.c:2526:gst_bin_change_state_func:<capture> child 'video_encoder' changed state to 4(PLAYING) successfully
0:00:01.886072295 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2638:gst_element_set_state_func:<viewfinder_queue> set_state to PLAYING
0:00:01.886082469 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2663:gst_element_set_state_func:<viewfinder_queue> setting target state to PLAYING
0:00:01.886092154 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2676:gst_element_set_state_func:<viewfinder_queue> current PAUSED, old_pending VOID_PENDING, next VOID_PENDING, old return SUCCESS
0:00:01.886102566 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2710:gst_element_set_state_func:<viewfinder_queue> final: setting state from PAUSED to PLAYING
0:00:01.886112763 17846 0xa8f600 LOG GST_STATES gstelement.c:2984:gst_element_change_state_func:<viewfinder_queue> default handler tries setting state from PAUSED to PLAYING (001c)
0:00:01.886123065 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2795:gst_element_change_state:<viewfinder_queue> element changed state SUCCESS
0:00:01.886132322 17846 0xa8f600 INFO GST_STATES gstelement.c:2460:gst_element_continue_state:<viewfinder_queue> completed state change to PLAYING
0:00:01.886141727 17846 0xa8f600 INFO GST_STATES gstelement.c:2365:_priv_gst_element_state_changed:<viewfinder_queue> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)
0:00:01.886159366 17846 0xa8f600 LOG GST_STATES gstelement.c:2811:gst_element_change_state:<viewfinder_queue> exit state change 1
0:00:01.886170110 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2722:gst_element_set_state_func:<viewfinder_queue> returned SUCCESS
0:00:01.886179658 17846 0xa8f600 INFO GST_STATES gstbin.c:2526:gst_bin_change_state_func:<capture> child 'viewfinder_queue' changed state to 4(PLAYING) successfully
0:00:01.886194194 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2638:gst_element_set_state_func:<encoder_queue> set_state to PLAYING
0:00:01.886204381 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2663:gst_element_set_state_func:<encoder_queue> setting target state to PLAYING
0:00:01.886213753 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2676:gst_element_set_state_func:<encoder_queue> current PAUSED, old_pending VOID_PENDING, next VOID_PENDING, old return SUCCESS
0:00:01.886230115 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2710:gst_element_set_state_func:<encoder_queue> final: setting state from PAUSED to PLAYING
0:00:01.886241112 17846 0xa8f600 LOG GST_STATES gstelement.c:2984:gst_element_change_state_func:<encoder_queue> default handler tries setting state from PAUSED to PLAYING (001c)
0:00:01.886251897 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2795:gst_element_change_state:<encoder_queue> element changed state SUCCESS
0:00:01.886261159 17846 0xa8f600 INFO GST_STATES gstelement.c:2460:gst_element_continue_state:<encoder_queue> completed state change to PLAYING
0:00:01.886270646 17846 0xa8f600 INFO GST_STATES gstelement.c:2365:_priv_gst_element_state_changed:<encoder_queue> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)
0:00:01.886288670 17846 0xa8f600 LOG GST_STATES gstelement.c:2811:gst_element_change_state:<encoder_queue> exit state change 1
0:00:01.886299370 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2722:gst_element_set_state_func:<encoder_queue> returned SUCCESS
0:00:01.886308952 17846 0xa8f600 INFO GST_STATES gstbin.c:2526:gst_bin_change_state_func:<capture> child 'encoder_queue' changed state to 4(PLAYING) successfully
0:00:01.886323509 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2638:gst_element_set_state_func:<encoder_valve> set_state to PLAYING
0:00:01.886333791 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2663:gst_element_set_state_func:<encoder_valve> setting target state to PLAYING
0:00:01.886343425 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2676:gst_element_set_state_func:<encoder_valve> current PAUSED, old_pending VOID_PENDING, next VOID_PENDING, old return SUCCESS
0:00:01.886353900 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2710:gst_element_set_state_func:<encoder_valve> final: setting state from PAUSED to PLAYING
0:00:01.886364217 17846 0xa8f600 LOG GST_STATES gstelement.c:2984:gst_element_change_state_func:<encoder_valve> default handler tries setting state from PAUSED to PLAYING (001c)
0:00:01.886374646 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2795:gst_element_change_state:<encoder_valve> element changed state SUCCESS
0:00:01.886383916 17846 0xa8f600 INFO GST_STATES gstelement.c:2460:gst_element_continue_state:<encoder_valve> completed state change to PLAYING
0:00:01.886393375 17846 0xa8f600 INFO GST_STATES gstelement.c:2365:_priv_gst_element_state_changed:<encoder_valve> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)
0:00:01.886410697 17846 0xa8f600 LOG GST_STATES gstelement.c:2811:gst_element_change_state:<encoder_valve> exit state change 1
0:00:01.886421524 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2722:gst_element_set_state_func:<encoder_valve> returned SUCCESS
0:00:01.886431159 17846 0xa8f600 INFO GST_STATES gstbin.c:2526:gst_bin_change_state_func:<capture> child 'encoder_valve' changed state to 4(PLAYING) successfully
0:00:01.886445453 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2638:gst_element_set_state_func:<video_tee> set_state to PLAYING
0:00:01.886455460 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2663:gst_element_set_state_func:<video_tee> setting target state to PLAYING
0:00:01.886464812 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2676:gst_element_set_state_func:<video_tee> current PAUSED, old_pending VOID_PENDING, next VOID_PENDING, old return SUCCESS
0:00:01.886475119 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2710:gst_element_set_state_func:<video_tee> final: setting state from PAUSED to PLAYING
0:00:01.886485376 17846 0xa8f600 LOG GST_STATES gstelement.c:2984:gst_element_change_state_func:<video_tee> default handler tries setting state from PAUSED to PLAYING (001c)
0:00:01.886500910 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2795:gst_element_change_state:<video_tee> element changed state SUCCESS
0:00:01.886510508 17846 0xa8f600 INFO GST_STATES gstelement.c:2460:gst_element_continue_state:<video_tee> completed state change to PLAYING
0:00:01.886520012 17846 0xa8f600 INFO GST_STATES gstelement.c:2365:_priv_gst_element_state_changed:<video_tee> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)
0:00:01.886537824 17846 0xa8f600 LOG GST_STATES gstelement.c:2811:gst_element_change_state:<video_tee> exit state change 1
0:00:01.886557181 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2722:gst_element_set_state_func:<video_tee> returned SUCCESS
0:00:01.886568228 17846 0xa8f600 INFO GST_STATES gstbin.c:2526:gst_bin_change_state_func:<capture> child 'video_tee' changed state to 4(PLAYING) successfully
0:00:01.886583352 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2638:gst_element_set_state_func:<src_filter> set_state to PLAYING
0:00:01.886593514 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2663:gst_element_set_state_func:<src_filter> setting target state to PLAYING
0:00:01.886602973 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2676:gst_element_set_state_func:<src_filter> current PAUSED, old_pending VOID_PENDING, next VOID_PENDING, old return SUCCESS
0:00:01.886613403 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2710:gst_element_set_state_func:<src_filter> final: setting state from PAUSED to PLAYING
0:00:01.886623780 17846 0xa8f600 LOG GST_STATES gstelement.c:2984:gst_element_change_state_func:<src_filter> default handler tries setting state from PAUSED to PLAYING (001c)
0:00:01.886634157 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2795:gst_element_change_state:<src_filter> element changed state SUCCESS
0:00:01.886643422 17846 0xa8f600 INFO GST_STATES gstelement.c:2460:gst_element_continue_state:<src_filter> completed state change to PLAYING
0:00:01.886652851 17846 0xa8f600 INFO GST_STATES gstelement.c:2365:_priv_gst_element_state_changed:<src_filter> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)
0:00:01.886680590 17846 0xa8f600 LOG GST_STATES gstelement.c:2811:gst_element_change_state:<src_filter> exit state change 1
0:00:01.886692457 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2722:gst_element_set_state_func:<src_filter> returned SUCCESS
0:00:01.886702244 17846 0xa8f600 INFO GST_STATES gstbin.c:2526:gst_bin_change_state_func:<capture> child 'src_filter' changed state to 4(PLAYING) successfully
0:00:01.886714481 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2638:gst_element_set_state_func:<src> set_state to PLAYING
0:00:01.886724186 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2663:gst_element_set_state_func:<src> setting target state to PLAYING
0:00:01.886733665 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2676:gst_element_set_state_func:<src> current PAUSED, old_pending VOID_PENDING, next VOID_PENDING, old return NO PREROLL
0:00:01.886744207 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2710:gst_element_set_state_func:<src> final: setting state from PAUSED to PLAYING
0:00:01.886763124 17846 0xa8f600 LOG GST_STATES gstelement.c:2984:gst_element_change_state_func:<src> default handler tries setting state from PAUSED to PLAYING (001c)
0:00:01.886774996 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2795:gst_element_change_state:<src> element changed state SUCCESS
0:00:01.886784475 17846 0xa8f600 INFO GST_STATES gstelement.c:2460:gst_element_continue_state:<src> completed state change to PLAYING
0:00:01.886794255 17846 0xa8f600 INFO GST_STATES gstelement.c:2365:_priv_gst_element_state_changed:<src> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)
0:00:01.886818306 17846 0xa8f600 LOG GST_STATES gstelement.c:2811:gst_element_change_state:<src> exit state change 1
0:00:01.886829088 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2722:gst_element_set_state_func:<src> returned SUCCESS
0:00:01.886838915 17846 0xa8f600 INFO GST_STATES gstbin.c:2526:gst_bin_change_state_func:<capture> child 'src' changed state to 4(PLAYING) successfully
0:00:01.886851317 17846 0xa8f600 DEBUG GST_STATES gstbin.c:2586:gst_bin_change_state_func:<capture> iterator done
0:00:01.886861134 17846 0xa8f600 LOG GST_STATES gstelement.c:2984:gst_element_change_state_func:<capture> default handler tries setting state from PAUSED to PLAYING (001c)
0:00:01.886871654 17846 0xa8f600 DEBUG GST_STATES gstbin.c:2604:gst_bin_change_state_func:<capture> we have ASYNC elements SUCCESS -> ASYNC
0:00:01.886884928 17846 0xa8f600 DEBUG GST_STATES gstbin.c:2653:gst_bin_change_state_func:<capture> done changing bin's state from PAUSED to PLAYING, now in PAUSED, ret ASYNC
0:00:01.886896058 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2777:gst_element_change_state:<capture> element will change state ASYNC
0:00:01.886905292 17846 0xa8f600 LOG GST_STATES gstelement.c:2817:gst_element_change_state:<capture> exit async state change 2
0:00:01.886914659 17846 0xa8f600 LOG GST_STATES gstelement.c:2811:gst_element_change_state:<capture> exit state change 2
0:00:01.886923912 17846 0xa8f600 LOG GST_STATES gstelement.c:2811:gst_element_change_state:<capture> exit state change 2
0:00:01.886933366 17846 0xa8f600 DEBUG GST_STATES gstelement.c:2722:gst_element_set_state_func:<capture> returned ASYNC
0:00:02.060457805 17846 0xa7b140 DEBUG basesink gstbasesink.c:3439:gst_base_sink_event:<viewfinder_sink> received event 0xa7b1e0 newsegment event from 'src' at time 99:99:99.999999999: GstEventNewsegment, update=(boolean)false, rate=(double)1, applied-rate=(double)1, format=(GstFormat)GST_FORMAT_TIME, start=(gint64)0, stop=(gint64)-1, position=(gint64)0;
0:00:02.060541892 17846 0xa7b140 DEBUG basesink gstbasesink.c:3474:gst_base_sink_event:<viewfinder_sink> newsegment 0xa7b1e0
0:00:02.060579408 17846 0xa7b140 DEBUG basesink gstbasesink.c:1544:gst_base_sink_configure_segment:<viewfinder_sink> configured NEWSEGMENT update 0, rate 1.000000, applied rate 1.000000, format GST_FORMAT_TIME, 0:00:00.000000000 -- 99:99:99.999999999, time 0:00:00.000000000, accum 0:00:00.000000000
0:00:02.060599662 17846 0xa7b140 DEBUG basesink gstbasesink.c:3259:gst_base_sink_queue_object_unlocked:<viewfinder_sink> now 0 prerolled items
0:00:02.060610036 17846 0xa7b140 DEBUG basesink gstbasesink.c:3312:gst_base_sink_queue_object_unlocked:<viewfinder_sink> need more preroll data 0 <= 0
0:00:02.060626676 17846 0xa7b140 DEBUG xvimagesink xvimagesink.c:2552:gst_xvimagesink_buffer_alloc:<viewfinder_sink> buffer alloc requested size 115200 with caps video/x-raw-yuv, format=(fourcc)I420, width=(int)320, height=(int)240, interlaced=(boolean)false, pixel-aspect-ratio=(fraction)1/1, framerate=(fraction)15/1, intersecting with our caps video/x-raw-yuv, format=(fourcc)YUY2, width=(int)[ 1, 16384 ], height=(int)[ 1, 16384 ], framerate=(fraction)[ 0/1, 2147483647/1 ]; video/x-raw-yuv, format=(fourcc)YV12, width=(int)[ 1, 16384 ], height=(int)[ 1, 16384 ], framerate=(fraction)[ 0/1, 2147483647/1 ]; video/x-raw-yuv, format=(fourcc)I420, width=(int)[ 1, 16384 ], height=(int)[ 1, 16384 ], framerate=(fraction)[ 0/1, 2147483647/1 ]; video/x-raw-yuv, format=(fourcc)UYVY, width=(int)[ 1, 16384 ], height=(int)[ 1, 16384 ], framerate=(fraction)[ 0/1, 2147483647/1 ]
0:00:02.060704570 17846 0xa7b140 DEBUG xvimagesink xvimagesink.c:2558:gst_xvimagesink_buffer_alloc:<viewfinder_sink> intersection in buffer alloc returned video/x-raw-yuv, format=(fourcc)I420, width=(int)320, height=(int)240, framerate=(fraction)15/1, interlaced=(boolean)false, pixel-aspect-ratio=(fraction)1/1
0:00:02.060738758 17846 0xa7b140 DEBUG xvimagesink xvimagesink.c:2628:gst_xvimagesink_buffer_alloc:<viewfinder_sink> allocating a buffer with caps video/x-raw-yuv, format=(fourcc)I420, width=(int)320, height=(int)240, framerate=(fraction)15/1, interlaced=(boolean)false, pixel-aspect-ratio=(fraction)1/1
0:00:02.060777914 17846 0xa7b140 DEBUG xvimagesink xvimagesink.c:2681:gst_xvimagesink_buffer_alloc:<viewfinder_sink> no usable image in pool, creating xvimage
0:00:02.060803170 17846 0xa7b140 DEBUG xvimagesink xvimagesink.c:529:gst_xvimagesink_xvimage_new:0x9b7c70, data (nil), malloc (nil), ts 99:99:99.999999999, dur 99:99:99.999999999, size 0, offset 18446744073709551615, offset_end 18446744073709551615, caps: NULL Creating new XvImageBuffer
0:00:02.060815677 17846 0xa7b140 LOG xvimagesink xvimagesink.c:539:gst_xvimagesink_xvimage_new:<viewfinder_sink> creating 320x240
0:00:02.060973805 17846 0xa7b140 LOG xvimagesink xvimagesink.c:590:gst_xvimagesink_xvimage_new:<viewfinder_sink> XShm image size is 115200
0:00:02.060996567 17846 0xa7b140 DEBUG xvimagesink xvimagesink.c:616:gst_xvimagesink_xvimage_new:<viewfinder_sink> Plane 0 has a expected pitch of 320 bytes, offset of 0
0:00:02.061011869 17846 0xa7b140 DEBUG xvimagesink xvimagesink.c:616:gst_xvimagesink_xvimage_new:<viewfinder_sink> Plane 1 has a expected pitch of 160 bytes, offset of 76800
0:00:02.061022986 17846 0xa7b140 DEBUG xvimagesink xvimagesink.c:616:gst_xvimagesink_xvimage_new:<viewfinder_sink> Plane 2 has a expected pitch of 160 bytes, offset of 96000
0:00:02.061033778 17846 0xa7b140 DEBUG xvimagesink xvimagesink.c:641:gst_xvimagesink_xvimage_new:<viewfinder_sink> Plane 0 has a pitch of 320 bytes, offset of 0
0:00:02.061044112 17846 0xa7b140 DEBUG xvimagesink xvimagesink.c:641:gst_xvimagesink_xvimage_new:<viewfinder_sink> Plane 1 has a pitch of 160 bytes, offset of 76800
0:00:02.061054397 17846 0xa7b140 DEBUG xvimagesink xvimagesink.c:641:gst_xvimagesink_xvimage_new:<viewfinder_sink> Plane 2 has a pitch of 160 bytes, offset of 96000
0:00:02.061345421 17846 0xa7b140 DEBUG xvimagesink xvimagesink.c:691:gst_xvimagesink_xvimage_new:<viewfinder_sink> XServer ShmAttached to 0x29db8003, id 0x2800002
0:00:02.061398539 17846 0xa7b140 LOG xvimagesink xvimagesink.c:321:gst_xvimage_buffer_finalize:0x9b7c70, data 0x7f3401df9000, malloc (nil), ts 99:99:99.999999999, dur 99:99:99.999999999, size 115200, offset 18446744073709551615, offset_end 18446744073709551615, caps: video/x-raw-yuv, format=(fourcc)I420, width=(int)320, height=(int)240, interlaced=(boolean)false, pixel-aspect-ratio=(fraction)1/1, framerate=(fraction)15/1 destroy image as its size changed 320x240 vs current 0x0
0:00:02.061433302 17846 0xa7b140 DEBUG xvimagesink xvimagesink.c:223:gst_xvimage_buffer_destroy:0x9b7c70, data 0x7f3401df9000, malloc (nil), ts 99:99:99.999999999, dur 99:99:99.999999999, size 115200, offset 18446744073709551615, offset_end 18446744073709551615, caps: video/x-raw-yuv, format=(fourcc)I420, width=(int)320, height=(int)240, interlaced=(boolean)false, pixel-aspect-ratio=(fraction)1/1, framerate=(fraction)15/1 Destroying buffer
0:00:02.061445322 17846 0xa7b140 DEBUG xvimagesink xvimagesink.c:256:gst_xvimage_buffer_destroy:<viewfinder_sink> XServer ShmDetaching from 0x29db8003 id 0x2800002
0:00:02.061677102 17846 0xa7b140 DEBUG xvimagesink xvimagesink.c:2103:gst_xvimagesink_setcaps:<viewfinder_sink> In setcaps. Possible caps video/x-raw-yuv, format=(fourcc)YUY2, width=(int)[ 1, 16384 ], height=(int)[ 1, 16384 ], framerate=(fraction)[ 0/1, 2147483647/1 ]; video/x-raw-yuv, format=(fourcc)YV12, width=(int)[ 1, 16384 ], height=(int)[ 1, 16384 ], framerate=(fraction)[ 0/1, 2147483647/1 ]; video/x-raw-yuv, format=(fourcc)I420, width=(int)[ 1, 16384 ], height=(int)[ 1, 16384 ], framerate=(fraction)[ 0/1, 2147483647/1 ]; video/x-raw-yuv, format=(fourcc)UYVY, width=(int)[ 1, 16384 ], height=(int)[ 1, 16384 ], framerate=(fraction)[ 0/1, 2147483647/1 ], setting caps video/x-raw-yuv, format=(fourcc)I420, width=(int)320, height=(int)240, interlaced=(boolean)false, pixel-aspect-ratio=(fraction)1/1, framerate=(fraction)15/1
0:00:02.061779433 17846 0xa7b140 DEBUG xvimagesink xvimagesink.c:2174:gst_xvimagesink_setcaps:<viewfinder_sink> video width/height: 320x240, calculated display ratio: 4/3
0:00:02.061792465 17846 0xa7b140 DEBUG xvimagesink xvimagesink.c:2183:gst_xvimagesink_setcaps:<viewfinder_sink> keeping video height
0:00:02.061802244 17846 0xa7b140 DEBUG xvimagesink xvimagesink.c:2199:gst_xvimagesink_setcaps:<viewfinder_sink> scaling to 320x240
0:00:02.062631848 17846 0xa7b140 DEBUG basesink gstbasesink.c:3665:gst_base_sink_chain_unlocked:<viewfinder_sink> got times start: 0:00:00.106770388, end: 0:00:00.173437054
0:00:02.062656620 17846 0xa7b140 DEBUG basesink gstbasesink.c:3259:gst_base_sink_queue_object_unlocked:<viewfinder_sink> now 1 prerolled items
0:00:02.062671802 17846 0xa7b140 DEBUG basesink gstbasesink.c:3178:gst_base_sink_preroll_object:<viewfinder_sink> prerolling object 0xa50680
0:00:02.062682381 17846 0xa7b140 DEBUG basesink gstbasesink.c:3196:gst_base_sink_preroll_object:<viewfinder_sink> preroll buffer 0:00:00.106770388
0:00:02.062693503 17846 0xa7b140 DEBUG basesink gstbasesink.c:1016:gst_base_sink_set_last_buffer_unlocked:<viewfinder_sink> setting last buffer to 0xa50680
0:00:02.062704550 17846 0xa7b140 LOG videosink gstvideosink.c:200:gst_video_sink_show_preroll_frame:<viewfinder_sink> rendering frame, ts=0:00:00.106770388
0:00:02.062716225 17846 0xa7b140 DEBUG xvimagesink xvimagesink.c:2391:gst_xvimagesink_show_frame:<viewfinder_sink> creating our xvimage
0:00:02.062734876 17846 0xa7b140 DEBUG xvimagesink xvimagesink.c:529:gst_xvimagesink_xvimage_new:0x9b7d50, data (nil), malloc (nil), ts 99:99:99.999999999, dur 99:99:99.999999999, size 0, offset 18446744073709551615, offset_end 18446744073709551615, caps: NULL Creating new XvImageBuffer
0:00:02.062746881 17846 0xa7b140 LOG xvimagesink xvimagesink.c:539:gst_xvimagesink_xvimage_new:<viewfinder_sink> creating 320x240
0:00:02.062955674 17846 0xa7b140 LOG xvimagesink xvimagesink.c:590:gst_xvimagesink_xvimage_new:<viewfinder_sink> XShm image size is 115200
0:00:02.062975141 17846 0xa7b140 DEBUG xvimagesink xvimagesink.c:616:gst_xvimagesink_xvimage_new:<viewfinder_sink> Plane 0 has a expected pitch of 320 bytes, offset of 0
0:00:02.062990890 17846 0xa7b140 DEBUG xvimagesink xvimagesink.c:616:gst_xvimagesink_xvimage_new:<viewfinder_sink> Plane 1 has a expected pitch of 160 bytes, offset of 76800
0:00:02.063003554 17846 0xa7b140 DEBUG xvimagesink xvimagesink.c:616:gst_xvimagesink_xvimage_new:<viewfinder_sink> Plane 2 has a expected pitch of 160 bytes, offset of 96000
0:00:02.063013929 17846 0xa7b140 DEBUG xvimagesink xvimagesink.c:641:gst_xvimagesink_xvimage_new:<viewfinder_sink> Plane 0 has a pitch of 320 bytes, offset of 0
0:00:02.063024009 17846 0xa7b140 DEBUG xvimagesink xvimagesink.c:641:gst_xvimagesink_xvimage_new:<viewfinder_sink> Plane 1 has a pitch of 160 bytes, offset of 76800
0:00:02.063034078 17846 0xa7b140 DEBUG xvimagesink xvimagesink.c:641:gst_xvimagesink_xvimage_new:<viewfinder_sink> Plane 2 has a pitch of 160 bytes, offset of 96000
0:00:02.063252231 17846 0xa7b140 DEBUG xvimagesink xvimagesink.c:691:gst_xvimagesink_xvimage_new:<viewfinder_sink> XServer ShmAttached to 0x29dc0003, id 0x2800005
0:00:02.063373460 17846 0xa7b140 LOG xvimagesink xvimagesink.c:814:gst_xvimagesink_xvimage_put:<viewfinder_sink> reffing 0x9b7d50 as our current image
0:00:02.063388982 17846 0xa7b140 LOG xvimagesink xvimagesink.c:862:gst_xvimagesink_xvimage_put:<viewfinder_sink> XvShmPutImage with image 320x240 and window 320x240, from xvimage 0x9b7d50, data 0x7f3401df9000, malloc (nil), ts 99:99:99.999999999, dur 99:99:99.999999999, size 115200, offset 18446744073709551615, offset_end 18446744073709551615, caps: NULL
0:00:02.066643324 17846 0xa7b140 DEBUG basesink gstbasesink.c:1605:gst_base_sink_commit_state:<viewfinder_sink> commiting state to PAUSED
0:00:02.066664201 17846 0xa7b140 DEBUG basesink gstbasesink.c:1630:gst_base_sink_commit_state:<viewfinder_sink> posting PAUSED state change message
0:00:02.066692754 17846 0xa7b140 DEBUG basesink gstbasesink.c:1636:gst_base_sink_commit_state:<viewfinder_sink> posting async-done message
0:00:02.066713441 17846 0xa7b140 DEBUG basesink gstbasesink.c:3284:gst_base_sink_queue_object_unlocked:<viewfinder_sink> rendering queued object 0xa7b1e0
0:00:02.066729765 17846 0xa7b140 DEBUG basesink gstbasesink.c:2612:gst_base_sink_do_sync:<viewfinder_sink> non syncable object 0xa7b1e0
0:00:02.066740417 17846 0xa7b140 DEBUG basesink gstbasesink.c:3044:gst_base_sink_render_object:<viewfinder_sink> rendering event 0xa7b1e0, type newsegment
0:00:02.066751127 17846 0xa7b140 DEBUG basesink gstbasesink.c:3058:gst_base_sink_render_object:<viewfinder_sink> Got seqnum #46
0:00:02.066765421 17846 0xa7b140 DEBUG basesink gstbasesink.c:1544:gst_base_sink_configure_segment:<viewfinder_sink> configured NEWSEGMENT update 0, rate 1.000000, applied rate 1.000000, format GST_FORMAT_TIME, 0:00:00.000000000 -- 99:99:99.999999999, time 0:00:00.000000000, accum 0:00:00.000000000
0:00:02.066785703 17846 0xa7b140 DEBUG basesink gstbasesink.c:3113:gst_base_sink_render_object:<viewfinder_sink> object unref after render 0xa7b1e0
0:00:02.066798835 17846 0xa7b140 DEBUG basesink gstbasesink.c:2017:gst_base_sink_get_sync_times:<viewfinder_sink> got times start: 0:00:00.106770388, stop: 0:00:00.173437054, do_sync 1
0:00:02.066812467 17846 0xa7b140 DEBUG basesink gstbasesink.c:2344:gst_base_sink_do_preroll:<viewfinder_sink> prerolling object 0xa50680
0:00:02.066822626 17846 0xa7b140 DEBUG basesink gstbasesink.c:3178:gst_base_sink_preroll_object:<viewfinder_sink> prerolling object 0xa50680
0:00:02.066832418 17846 0xa7b140 DEBUG basesink gstbasesink.c:2277:gst_base_sink_wait_preroll:<viewfinder_sink> waiting in preroll for flush or PLAYING
0:00:02.083837351 17846 0xa7b0a0 LOG xvimagesink xvimagesink.c:862:gst_xvimagesink_xvimage_put:<viewfinder_sink> XvShmPutImage with image 320x240 and window 320x240, from xvimage 0x9b7d50, data 0x7f3401df9000, malloc (nil), ts 99:99:99.999999999, dur 99:99:99.999999999, size 115200, offset 18446744073709551615, offset_end 18446744073709551615, caps: NULL
More information about the gstreamer-devel
mailing list