`dynamic-tee-vsink.c` example shows black screen with gstreamer-vaapi
When using https://github.com/sdroege/gst-snippets/blob/master/dynamic-tee-vsink.c with vaapi installed, I just see a black screen with dubious log output indicating that the pipeline is getting paused where it should actually be playing. Removing gstreamer-vaapi to force a different encoder seems to help.
Log that leads to black screen with gstreamer-vaapi installed (gstreamer 1.16.1, archlinux package):
0:00:03.079231484 1534397 0x56550c158400 INFO GST_ELEMENT_PADS
gstelement.c:668:gst_element_add_pad:<tee0> adding pad 'src_1'
0:00:03.079316601 1534397 0x56550c158400 INFO GST_ELEMENT_FACTORY
gstelementfactory.c:361:gst_element_factory_create: creating element "queue"
0:00:03.079479602 1534397 0x56550c158400 INFO GST_ELEMENT_PADS
gstelement.c:668:gst_element_add_pad:<GstQueue@0x7fd6a0059900> adding pad
'sink'
0:00:03.079535811 1534397 0x56550c158400 INFO GST_ELEMENT_PADS
gstelement.c:668:gst_element_add_pad:<GstQueue@0x7fd6a0059900> adding pad
'src'
0:00:03.079583988 1534397 0x56550c158400 INFO GST_ELEMENT_FACTORY
gstelementfactory.c:361:gst_element_factory_create: creating element
"videoconvert"
0:00:03.079642633 1534397 0x56550c158400 INFO GST_ELEMENT_PADS
gstelement.c:668:gst_element_add_pad:<GstBaseTransform@0x56550c2d68d0> adding
pad 'sink'
0:00:03.079697209 1534397 0x56550c158400 INFO GST_ELEMENT_PADS
gstelement.c:668:gst_element_add_pad:<GstBaseTransform@0x56550c2d68d0> adding
pad 'src'
0:00:03.080384513 1534397 0x56550c158400 INFO GST_PLUGIN_LOADING
gstplugin.c:902:_priv_gst_plugin_load_file_for_registry: plugin "/usr/lib/
gstreamer-1.0/libgstautodetect.so" loaded
0:00:03.080418382 1534397 0x56550c158400 INFO GST_ELEMENT_FACTORY
gstelementfactory.c:361:gst_element_factory_create: creating element
"autovideosink"
0:00:03.080566363 1534397 0x56550c158400 INFO GST_ELEMENT_PADS
gstelement.c:668:gst_element_add_pad:<autovideosink0> adding pad 'sink'
0:00:03.080596157 1534397 0x56550c158400 INFO GST_ELEMENT_FACTORY
gstelementfactory.c:358:gst_element_factory_create: creating element
"fakesink" named "fake-video-sink"
0:00:03.080633376 1534397 0x56550c158400 INFO GST_ELEMENT_PADS
gstelement.c:668:gst_element_add_pad:<GstBaseSink@0x56550c3f1550> adding pad
'sink'
0:00:03.080688605 1534397 0x56550c158400 INFO GST_ELEMENT_PADS
gstelement.c:915:gst_element_get_static_pad: found pad fake-video-sink:sink
0:00:03.080715730 1534397 0x56550c158400 INFO GST_PADS
gstpad.c:2377:gst_pad_link_prepare: trying to link sink:proxypad5 and fake-
video-sink:sink
0:00:03.080740623 1534397 0x56550c158400 INFO GST_PADS
gstpad.c:2585:gst_pad_link_full: linked sink:proxypad5 and fake-video-
sink:sink, successful
0:00:03.080758683 1534397 0x56550c158400 INFO GST_EVENT
gstevent.c:1579:gst_event_new_reconfigure: creating reconfigure event
0:00:03.080837028 1534397 0x56550c158400 INFO GST_ELEMENT_PADS
gstutils.c:1771:gst_element_link_pads_full: trying to link element queue1:
(any) to element videoconvert1:(any)
0:00:03.080863671 1534397 0x56550c158400 INFO GST_PADS
gstutils.c:1034:gst_pad_check_link: trying to link queue1:src and
videoconvert1:sink
0:00:03.080891803 1534397 0x56550c158400 INFO GST_PADS
gstpad.c:4237:gst_pad_peer_query:<queue1:sink> pad has no peer
0:00:03.080921761 1534397 0x56550c158400 INFO GST_PADS
gstpad.c:4237:gst_pad_peer_query:<videoconvert1:src> pad has no peer
0:00:03.082849923 1534397 0x56550c158400 INFO GST_PADS
gstutils.c:1587:prepare_link_maybe_ghosting: queue1 and videoconvert1 in same
bin, no need for ghost pads
0:00:03.082867188 1534397 0x56550c158400 INFO GST_PADS
gstpad.c:2377:gst_pad_link_prepare: trying to link queue1:src and
videoconvert1:sink
0:00:03.082875755 1534397 0x56550c158400 INFO GST_PADS
gstpad.c:4237:gst_pad_peer_query:<queue1:sink> pad has no peer
0:00:03.082884546 1534397 0x56550c158400 INFO GST_PADS
gstpad.c:4237:gst_pad_peer_query:<videoconvert1:src> pad has no peer
0:00:03.083682518 1534397 0x56550c158400 INFO GST_PADS
gstpad.c:2585:gst_pad_link_full: linked queue1:src and videoconvert1:sink,
successful
0:00:03.083690544 1534397 0x56550c158400 INFO GST_EVENT
gstevent.c:1579:gst_event_new_reconfigure: creating reconfigure event
0:00:03.083697092 1534397 0x56550c158400 INFO GST_EVENT
gstpad.c:5812:gst_pad_send_event_unchecked:<queue1:src> Received event on
flushing pad. Discarding
0:00:03.083709121 1534397 0x56550c158400 INFO GST_ELEMENT_PADS
gstutils.c:1771:gst_element_link_pads_full: trying to link element
videoconvert1:(any) to element autovideosink0:(any)
0:00:03.083721242 1534397 0x56550c158400 INFO GST_PADS
gstutils.c:1034:gst_pad_check_link: trying to link videoconvert1:src and
autovideosink0:sink
0:00:03.083731411 1534397 0x56550c158400 INFO GST_PADS
gstpad.c:4237:gst_pad_peer_query:<queue1:sink> pad has no peer
0:00:03.084522246 1534397 0x56550c158400 INFO GST_PADS
gstutils.c:1587:prepare_link_maybe_ghosting: videoconvert1 and autovideosink0
in same bin, no need for ghost pads
0:00:03.084534493 1534397 0x56550c158400 INFO GST_PADS
gstpad.c:2377:gst_pad_link_prepare: trying to link videoconvert1:src and
autovideosink0:sink
0:00:03.084542572 1534397 0x56550c158400 INFO GST_PADS
gstpad.c:4237:gst_pad_peer_query:<queue1:sink> pad has no peer
0:00:03.085335895 1534397 0x56550c158400 INFO GST_PADS
gstpad.c:2585:gst_pad_link_full: linked videoconvert1:src and
autovideosink0:sink, successful
0:00:03.085343724 1534397 0x56550c158400 INFO GST_EVENT
gstevent.c:1579:gst_event_new_reconfigure: creating reconfigure event
0:00:03.085350140 1534397 0x56550c158400 INFO GST_EVENT
gstpad.c:5812:gst_pad_send_event_unchecked:<videoconvert1:src> Received event
on flushing pad. Discarding
0:00:03.085364687 1534397 0x56550c158400 INFO GST_STATES
gstelement.c:2647:gst_element_continue_state:<queue1> committing state from
NULL to READY, pending PLAYING, next PAUSED
0:00:03.085376262 1534397 0x56550c158400 INFO GST_STATES
gstelement.c:2575:_priv_gst_element_state_changed:<queue1> notifying about
state-changed NULL to READY (PLAYING pending)
0:00:03.085395201 1534397 0x56550c158400 INFO GST_STATES
gstelement.c:2655:gst_element_continue_state:<queue1> continue state change
READY to PAUSED, final PLAYING
0:00:03.085411380 1534397 0x56550c158400 INFO task
gsttask.c:453:gst_task_set_lock: setting stream lock 0x56550c3cb190 on task
0x56550c3d4290
0:00:03.085420021 1534397 0x56550c158400 INFO GST_PADS
gstpad.c:6159:gst_pad_start_task:<queue1:src> created task 0x56550c3d4290
0:00:03.085439479 1534397 0x56550c158400 INFO GST_STATES
gstelement.c:2647:gst_element_continue_state:<queue1> committing state from
READY to PAUSED, pending PLAYING, next PLAYING
0:00:03.085447826 1534397 0x56550c158400 INFO GST_STATES
gstelement.c:2575:_priv_gst_element_state_changed:<queue1> notifying about
state-changed READY to PAUSED (PLAYING pending)
0:00:03.085456012 1534397 0x56550c158400 INFO GST_STATES
gstelement.c:2655:gst_element_continue_state:<queue1> continue state change
PAUSED to PLAYING, final PLAYING
0:00:03.085462277 1534397 0x56550c158400 INFO GST_STATES
gstelement.c:2675:gst_element_continue_state:<queue1> completed state change
to PLAYING
0:00:03.085471943 1534397 0x56550c158400 INFO GST_STATES
gstelement.c:2575:_priv_gst_element_state_changed:<queue1> notifying about
state-changed PAUSED to PLAYING (VOID_PENDING pending)
0:00:03.085485041 1534397 0x56550c158400 INFO GST_STATES
gstelement.c:2647:gst_element_continue_state:<videoconvert1> committing state
from NULL to READY, pending PLAYING, next PAUSED
0:00:03.085493188 1534397 0x56550c158400 INFO GST_STATES
gstelement.c:2575:_priv_gst_element_state_changed:<videoconvert1> notifying
about state-changed NULL to READY (PLAYING pending)
0:00:03.085502576 1534397 0x56550c158400 INFO GST_STATES
gstelement.c:2655:gst_element_continue_state:<videoconvert1> continue state
change READY to PAUSED, final PLAYING
0:00:03.085514953 1534397 0x56550c158400 INFO GST_STATES
gstelement.c:2647:gst_element_continue_state:<videoconvert1> committing state
from READY to PAUSED, pending PLAYING, next PLAYING
0:00:03.085523116 1534397 0x56550c158400 INFO GST_STATES
gstelement.c:2575:_priv_gst_element_state_changed:<videoconvert1> notifying
about state-changed READY to PAUSED (PLAYING pending)
0:00:03.085532405 1534397 0x56550c158400 INFO GST_STATES
gstelement.c:2655:gst_element_continue_state:<videoconvert1> continue state
change PAUSED to PLAYING, final PLAYING
0:00:03.085539554 1534397 0x56550c158400 INFO GST_STATES
gstelement.c:2675:gst_element_continue_state:<videoconvert1> completed state
change to PLAYING
0:00:03.085547662 1534397 0x56550c158400 INFO GST_STATES
gstelement.c:2575:_priv_gst_element_state_changed:<videoconvert1> notifying
about state-changed PAUSED to PLAYING (VOID_PENDING pending)
0:00:03.085559817 1534397 0x56550c158400 INFO GST_STATES
gstelement.c:2675:gst_element_continue_state:<fake-video-sink> completed state
change to NULL
0:00:03.085571987 1534397 0x56550c158400 INFO GST_ELEMENT_PADS
gstpad.c:2132:gst_pad_unlink: unlinking sink:proxypad5(0x56550c3dc570) and
fake-video-sink:sink(0x7fd6a005bcd0)
0:00:03.085581906 1534397 0x56550c158400 INFO GST_ELEMENT_PADS
gstpad.c:2187:gst_pad_unlink: unlinked sink:proxypad5 and fake-video-sink:sink
0:00:03.085590247 1534397 0x56550c158400 INFO GST_PARENTAGE
gstbin.c:1801:gst_bin_remove_func:<autovideosink0> removed child "fake-video-
sink"
0:00:03.085603414 1534397 0x56550c158400 INFO GST_REFCOUNTING
gstelement.c:3251:gst_element_dispose:<fake-video-sink> 0x56550c3f1550 dispose
0:00:03.085611152 1534397 0x56550c158400 INFO GST_ELEMENT_PADS
gstelement.c:784:gst_element_remove_pad:<fake-video-sink> removing pad 'sink'
0:00:03.085622744 1534397 0x56550c158400 INFO GST_REFCOUNTING
gstelement.c:3296:gst_element_dispose:<fake-video-sink> 0x56550c3f1550 parent
class dispose
0:00:03.085631056 1534397 0x56550c158400 INFO GST_REFCOUNTING
gstelement.c:3328:gst_element_finalize:<fake-video-sink> 0x56550c3f1550
finalize
0:00:03.085638498 1534397 0x56550c158400 INFO GST_REFCOUNTING
gstelement.c:3333:gst_element_finalize:<fake-video-sink> 0x56550c3f1550
finalize parent
0:00:03.086019432 1534397 0x56550c158400 INFO GST_ELEMENT_FACTORY
gstelementfactory.c:358:gst_element_factory_create: creating element
"vaapisink" named "autovideosink0-actual-sink-vaapi"
0:00:03.086184883 1534397 0x56550c158400 INFO GST_ELEMENT_PADS
gstelement.c:668:gst_element_add_pad:<GstBaseSink@0x56550c3fd600> adding pad
'sink'
0:00:03.086200457 1534397 0x56550c158400 INFO GST_ELEMENT_PADS
gstelement.c:915:gst_element_get_static_pad: found pad (null):sink
0:00:03.086220514 1534397 0x56550c158400 INFO GST_ELEMENT_PADS
gstelement.c:915:gst_element_get_static_pad: found pad autovideosink0-actual-
sink-vaapi:sink
0:00:03.086236575 1534397 0x56550c158400 INFO GST_PADS
gstpad.c:4237:gst_pad_peer_query:<autovideosink0-actual-sink-vaapi:sink> pad
has no peer
0:00:03.086244674 1534397 0x56550c158400 INFO GST_CONTEXT
gstvaapivideocontext.c:150:context_pad_query:<autovideosink0-actual-sink-
vaapi:sink> context pad peer query failed
0:00:03.087108827 1534397 0x56550c158400 INFO vaapi
gstvaapiutils.c:94:gst_vaapi_log: VA-API version 1.5.0
0:00:03.087256530 1534397 0x56550c158400 INFO vaapi
gstvaapiutils.c:94:gst_vaapi_log: va_getDriverName() returns 0
0:00:03.087270818 1534397 0x56550c158400 INFO vaapi
gstvaapiutils.c:94:gst_vaapi_log: Trying to open /usr/lib/dri/
i965_drv_video.so
0:00:03.087290622 1534397 0x56550c158400 INFO vaapi
gstvaapiutils.c:94:gst_vaapi_log: Found init function __vaDriverInit_1_3
0:00:03.087630048 1534397 0x56550c158400 INFO vaapi
gstvaapiutils.c:94:gst_vaapi_log: va_openDriver() returns 0
0:00:03.087648585 1534397 0x56550c158400 INFO vaapi
gstvaapiutils.c:121:vaapi_initialize: VA-API version 1.5
0:00:03.087660289 1534397 0x56550c158400 INFO vaapidisplay
gstvaapidisplay.c:906:gst_vaapi_display_create:<vaapidisplayglx1> new display
addr=0x56550c3d4410
0:00:03.087681051 1534397 0x56550c158400 INFO vaapisink
gstvaapipluginbase.c:55:plugin_set_display:<autovideosink0-actual-sink-vaapi>
set display <vaapidisplayglx1>
0:00:03.087702747 1534397 0x56550c158400 INFO GST_CONTEXT
gstvaapivideocontext.c:311:gst_vaapi_video_context_propagate:<autovideosink0-
actual-sink-vaapi> posting `have-context' (0x56550c3e3520) message with
display <vaapidisplayglx1>
0:00:03.087722298 1534397 0x56550c158400 INFO vaapisink
gstvaapisink.c:1232:gst_vaapisink_display_changed: created VA/GLX display
0x56550c3d4410
0:00:03.089485440 1534397 0x56550c158400 INFO GST_STATES
gstelement.c:2675:gst_element_continue_state:<autovideosink0-actual-sink-
vaapi> completed state change to READY
0:00:03.089503227 1534397 0x56550c158400 INFO GST_STATES
gstelement.c:2575:_priv_gst_element_state_changed:<autovideosink0-actual-sink-
vaapi> notifying about state-changed NULL to READY (VOID_PENDING pending)
0:00:03.089527384 1534397 0x56550c158400 INFO GST_STATES
gstelement.c:2675:gst_element_continue_state:<autovideosink0-actual-sink-
vaapi> completed state change to NULL
0:00:03.089537722 1534397 0x56550c158400 INFO GST_STATES
gstelement.c:2575:_priv_gst_element_state_changed:<autovideosink0-actual-sink-
vaapi> notifying about state-changed READY to NULL (VOID_PENDING pending)
0:00:03.089878840 1534397 0x56550c158400 INFO vaapisink
gstvaapipluginbase.c:55:plugin_set_display:<autovideosink0-actual-sink-vaapi>
set display <vaapidisplayglx0>
0:00:03.089902575 1534397 0x56550c158400 INFO GST_ELEMENT_PADS
gstelement.c:915:gst_element_get_static_pad: found pad autovideosink0-actual-
sink-vaapi:sink
0:00:03.089915842 1534397 0x56550c158400 INFO GST_PADS
gstpad.c:2377:gst_pad_link_prepare: trying to link sink:proxypad5 and
autovideosink0-actual-sink-vaapi:sink
0:00:03.089926275 1534397 0x56550c158400 INFO GST_PADS
gstpad.c:2585:gst_pad_link_full: linked sink:proxypad5 and autovideosink0-
actual-sink-vaapi:sink, successful
0:00:03.089933751 1534397 0x56550c158400 INFO GST_EVENT
gstevent.c:1579:gst_event_new_reconfigure: creating reconfigure event
0:00:03.089952031 1534397 0x56550c158400 INFO GST_STATES
gstbin.c:2503:gst_bin_element_set_state:<autovideosink0-actual-sink-vaapi>
current NULL pending VOID_PENDING, desired next READY
0:00:03.090802207 1534397 0x56550c158400 INFO GST_STATES
gstelement.c:2675:gst_element_continue_state:<autovideosink0-actual-sink-
vaapi> completed state change to READY
0:00:03.090816364 1534397 0x56550c158400 INFO GST_STATES
gstelement.c:2575:_priv_gst_element_state_changed:<autovideosink0-actual-sink-
vaapi> notifying about state-changed NULL to READY (VOID_PENDING pending)
0:00:03.090831961 1534397 0x56550c158400 INFO GST_STATES
gstbin.c:2952:gst_bin_change_state_func:<autovideosink0> child
'autovideosink0-actual-sink-vaapi' changed state to 2(READY) successfully
0:00:03.090843969 1534397 0x56550c158400 INFO GST_STATES
gstelement.c:2647:gst_element_continue_state:<autovideosink0> committing state
from NULL to READY, pending PLAYING, next PAUSED
0:00:03.090851371 1534397 0x56550c158400 INFO GST_STATES
gstelement.c:2575:_priv_gst_element_state_changed:<autovideosink0> notifying
about state-changed NULL to READY (PLAYING pending)
0:00:03.090861524 1534397 0x56550c158400 INFO GST_STATES
gstelement.c:2655:gst_element_continue_state:<autovideosink0> continue state
change READY to PAUSED, final PLAYING
0:00:03.090874793 1534397 0x56550c158400 INFO GST_STATES
gstbin.c:2503:gst_bin_element_set_state:<autovideosink0-actual-sink-vaapi>
current READY pending VOID_PENDING, desired next PAUSED
0:00:03.090887096 1534397 0x56550c158400 INFO GST_STATES
gstelement.c:2575:_priv_gst_element_state_changed:<pipeline0> notifying about
state-changed PAUSED to PAUSED (PAUSED pending)
0:00:03.090901159 1534397 0x56550c158400 INFO GST_STATES
gstbin.c:2959:gst_bin_change_state_func:<autovideosink0> child
'autovideosink0-actual-sink-vaapi' is changing state asynchronously to PAUSED
0:00:03.090915481 1534397 0x56550c158400 INFO GST_ELEMENT_PADS
gstelement.c:915:gst_element_get_static_pad: found pad queue1:sink
0:00:03.090927587 1534397 0x56550c158400 INFO GST_PADS
gstpad.c:2377:gst_pad_link_prepare: trying to link tee0:src_1 and queue1:sink
0:00:03.091541584 1534397 0x56550c158400 INFO GST_PADS
gstpad.c:2585:gst_pad_link_full: linked tee0:src_1 and queue1:sink, successful
0:00:03.091552972 1534397 0x56550c158400 INFO GST_EVENT
gstevent.c:1579:gst_event_new_reconfigure: creating reconfigure event
added
0:00:03.107264973 1534397 0x7fd6a807c770 INFO vaapidecode
gstvaapidecode.c:360:gst_vaapidecode_update_src_caps:<vaapidecode0> new src
caps = video/x-raw(memory:VASurface), format=(string)NV12, width=(int)1280,
height=(int)800, interlace-mode=(string)progressive, multiview-
mode=(string)mono, multiview-flags=(GstVideoMultiviewFlagsSet)0:ffffffff:/
right-view-first/left-flipped/left-flopped/right-flipped/right-flopped/half-
aspect/mixed-mono, pixel-aspect-ratio=(fraction)1/1, framerate=(fraction)30/1
0:00:03.107447247 1534397 0x7fd6a005d630 INFO basetransform
gstbasetransform.c:1317:gst_base_transform_setcaps:<capsfilter1> reuse caps
0:00:03.115024568 1534397 0x7fd6a005d630 INFO basetransform
gstbasetransform.c:1317:gst_base_transform_setcaps:<vaapipostproc0> reuse caps
0:00:03.115209353 1534397 0x7fd6a005d630 INFO basetransform
gstbasetransform.c:1317:gst_base_transform_setcaps:<videoconvert0> reuse caps
0:00:03.115387051 1534397 0x7fd6981a0450 INFO basetransform
gstbasetransform.c:1317:gst_base_transform_setcaps:<videoconvert1> reuse caps
0:00:03.115489630 1534397 0x7fd6981a0450 INFO GST_EVENT
gstevent.c:820:gst_event_new_caps: creating caps event video/x-
raw(memory:VASurface), format=(string)NV12, width=(int)1280, height=(int)800,
interlace-mode=(string)progressive, multiview-mode=(string)mono, multiview-
flags=(GstVideoMultiviewFlagsSet)0:ffffffff:/right-view-first/left-flipped/
left-flopped/right-flipped/right-flopped/half-aspect/mixed-mono, pixel-aspect-
ratio=(fraction)1/1, framerate=(fraction)30/1
0:00:03.118500325 1534397 0x7fd6a807c770 INFO basetransform
gstbasetransform.c:1317:gst_base_transform_setcaps:<capsfilter0> reuse capsworking log without gstreamer-vaapi installed:
add
0:00:03.303215696 28532 0x55dae69ff400 INFO GST_ELEMENT_PADS gstelement.c:668:gst_element_add_pad:<tee0> adding pad 'src_1'
0:00:03.303236330 28532 0x55dae69ff400 INFO GST_ELEMENT_FACTORY gstelementfactory.c:361:gst_element_factory_create: creating element "queue"
0:00:03.303266023 28532 0x55dae69ff400 INFO GST_ELEMENT_PADS gstelement.c:668:gst_element_add_pad:<GstQueue@0x7fa148078c00> adding pad 'sink'
0:00:03.303286054 28532 0x55dae69ff400 INFO GST_ELEMENT_PADS gstelement.c:668:gst_element_add_pad:<GstQueue@0x7fa148078c00> adding pad 'src'
0:00:03.303303075 28532 0x55dae69ff400 INFO GST_ELEMENT_FACTORY gstelementfactory.c:361:gst_element_factory_create: creating element "videoconvert"
0:00:03.303319987 28532 0x55dae69ff400 INFO GST_ELEMENT_PADS gstelement.c:668:gst_element_add_pad:<GstBaseTransform@0x55dae6b66500> adding pad 'sink'
0:00:03.303333916 28532 0x55dae69ff400 INFO GST_ELEMENT_PADS gstelement.c:668:gst_element_add_pad:<GstBaseTransform@0x55dae6b66500> adding pad 'src'
0:00:03.303638338 28532 0x55dae69ff400 INFO GST_PLUGIN_LOADING gstplugin.c:902:_priv_gst_plugin_load_file_for_registry: plugin "/usr/lib/gstreamer-1.0/libgstautodetect.so" loaded
0:00:03.303653824 28532 0x55dae69ff400 INFO GST_ELEMENT_FACTORY gstelementfactory.c:361:gst_element_factory_create: creating element "autovideosink"
0:00:03.303736245 28532 0x55dae69ff400 INFO GST_ELEMENT_PADS gstelement.c:668:gst_element_add_pad:<autovideosink0> adding pad 'sink'
0:00:03.303751366 28532 0x55dae69ff400 INFO GST_ELEMENT_FACTORY gstelementfactory.c:358:gst_element_factory_create: creating element "fakesink" named "fake-video-sink"
0:00:03.303769284 28532 0x55dae69ff400 INFO GST_ELEMENT_PADS gstelement.c:668:gst_element_add_pad:<GstBaseSink@0x55dae6c91bc0> adding pad 'sink'
0:00:03.303796065 28532 0x55dae69ff400 INFO GST_ELEMENT_PADS gstelement.c:915:gst_element_get_static_pad: found pad fake-video-sink:sink
0:00:03.303808917 28532 0x55dae69ff400 INFO GST_PADS gstpad.c:2377:gst_pad_link_prepare: trying to link sink:proxypad4 and fake-video-sink:sink
0:00:03.303825402 28532 0x55dae69ff400 INFO GST_PADS gstpad.c:2585:gst_pad_link_full: linked sink:proxypad4 and fake-video-sink:sink, successful
0:00:03.303838629 28532 0x55dae69ff400 INFO GST_EVENT gstevent.c:1579:gst_event_new_reconfigure: creating reconfigure event
0:00:03.303891835 28532 0x55dae69ff400 INFO GST_ELEMENT_PADS gstutils.c:1771:gst_element_link_pads_full: trying to link element queue1:(any) to element videoconvert1:(any)
0:00:03.303912861 28532 0x55dae69ff400 INFO GST_PADS gstutils.c:1034:gst_pad_check_link: trying to link queue1:src and videoconvert1:sink
0:00:03.303935192 28532 0x55dae69ff400 INFO GST_PADS gstpad.c:4237:gst_pad_peer_query:<queue1:sink> pad has no peer
0:00:03.303958442 28532 0x55dae69ff400 INFO GST_PADS gstpad.c:4237:gst_pad_peer_query:<videoconvert1:src> pad has no peer
0:00:03.305642980 28532 0x55dae69ff400 INFO GST_PADS gstutils.c:1587:prepare_link_maybe_ghosting: queue1 and videoconvert1 in same bin, no need for ghost pads
0:00:03.305685612 28532 0x55dae69ff400 INFO GST_PADS gstpad.c:2377:gst_pad_link_prepare: trying to link queue1:src and videoconvert1:sink
0:00:03.305709217 28532 0x55dae69ff400 INFO GST_PADS gstpad.c:4237:gst_pad_peer_query:<queue1:sink> pad has no peer
0:00:03.305731267 28532 0x55dae69ff400 INFO GST_PADS gstpad.c:4237:gst_pad_peer_query:<videoconvert1:src> pad has no peer
0:00:03.307409486 28532 0x55dae69ff400 INFO GST_PADS gstpad.c:2585:gst_pad_link_full: linked queue1:src and videoconvert1:sink, successful
0:00:03.307430248 28532 0x55dae69ff400 INFO GST_EVENT gstevent.c:1579:gst_event_new_reconfigure: creating reconfigure event
0:00:03.307448134 28532 0x55dae69ff400 INFO GST_EVENT gstpad.c:5812:gst_pad_send_event_unchecked:<queue1:src> Received event on flushing pad. Discarding
0:00:03.307475300 28532 0x55dae69ff400 INFO GST_ELEMENT_PADS gstutils.c:1771:gst_element_link_pads_full: trying to link element videoconvert1:(any) to element autovideosink0:(any)
0:00:03.307496714 28532 0x55dae69ff400 INFO GST_PADS gstutils.c:1034:gst_pad_check_link: trying to link videoconvert1:src and autovideosink0:sink
0:00:03.307517089 28532 0x55dae69ff400 INFO GST_PADS gstpad.c:4237:gst_pad_peer_query:<queue1:sink> pad has no peer
0:00:03.309176912 28532 0x55dae69ff400 INFO GST_PADS gstutils.c:1587:prepare_link_maybe_ghosting: videoconvert1 and autovideosink0 in same bin, no need for ghost pads
0:00:03.309204165 28532 0x55dae69ff400 INFO GST_PADS gstpad.c:2377:gst_pad_link_prepare: trying to link videoconvert1:src and autovideosink0:sink
0:00:03.309225210 28532 0x55dae69ff400 INFO GST_PADS gstpad.c:4237:gst_pad_peer_query:<queue1:sink> pad has no peer
0:00:03.311082285 28532 0x55dae69ff400 INFO GST_PADS gstpad.c:2585:gst_pad_link_full: linked videoconvert1:src and autovideosink0:sink, successful
0:00:03.311104610 28532 0x55dae69ff400 INFO GST_EVENT gstevent.c:1579:gst_event_new_reconfigure: creating reconfigure event
0:00:03.311123146 28532 0x55dae69ff400 INFO GST_EVENT gstpad.c:5812:gst_pad_send_event_unchecked:<videoconvert1:src> Received event on flushing pad. Discarding
0:00:03.311163480 28532 0x55dae69ff400 INFO GST_STATES gstelement.c:2647:gst_element_continue_state:<queue1> committing state from NULL to READY, pending PLAYING, next PAUSED
0:00:03.311187561 28532 0x55dae69ff400 INFO GST_STATES gstelement.c:2575:_priv_gst_element_state_changed:<queue1> notifying about state-changed NULL to READY (PLAYING pending)
0:00:03.311224292 28532 0x55dae69ff400 INFO GST_STATES gstelement.c:2655:gst_element_continue_state:<queue1> continue state change READY to PAUSED, final PLAYING
0:00:03.311264080 28532 0x55dae69ff400 INFO task gsttask.c:453:gst_task_set_lock: setting stream lock 0x55dae6c71180 on task 0x55dae6c7b290
0:00:03.311283460 28532 0x55dae69ff400 INFO GST_PADS gstpad.c:6159:gst_pad_start_task:<queue1:src> created task 0x55dae6c7b290
0:00:03.311327195 28532 0x55dae69ff400 INFO GST_STATES gstelement.c:2647:gst_element_continue_state:<queue1> committing state from READY to PAUSED, pending PLAYING, next PLAYING
0:00:03.311349850 28532 0x55dae69ff400 INFO GST_STATES gstelement.c:2575:_priv_gst_element_state_changed:<queue1> notifying about state-changed READY to PAUSED (PLAYING pending)
0:00:03.311373758 28532 0x55dae69ff400 INFO GST_STATES gstelement.c:2655:gst_element_continue_state:<queue1> continue state change PAUSED to PLAYING, final PLAYING
0:00:03.311390828 28532 0x55dae69ff400 INFO GST_STATES gstelement.c:2675:gst_element_continue_state:<queue1> completed state change to PLAYING
0:00:03.311409700 28532 0x55dae69ff400 INFO GST_STATES gstelement.c:2575:_priv_gst_element_state_changed:<queue1> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)
0:00:03.311437741 28532 0x55dae69ff400 INFO GST_STATES gstelement.c:2647:gst_element_continue_state:<videoconvert1> committing state from NULL to READY, pending PLAYING, next PAUSED
0:00:03.311457870 28532 0x55dae69ff400 INFO GST_STATES gstelement.c:2575:_priv_gst_element_state_changed:<videoconvert1> notifying about state-changed NULL to READY (PLAYING pending)
0:00:03.311479358 28532 0x55dae69ff400 INFO GST_STATES gstelement.c:2655:gst_element_continue_state:<videoconvert1> continue state change READY to PAUSED, final PLAYING
0:00:03.311506854 28532 0x55dae69ff400 INFO GST_STATES gstelement.c:2647:gst_element_continue_state:<videoconvert1> committing state from READY to PAUSED, pending PLAYING, next PLAYING
0:00:03.311526488 28532 0x55dae69ff400 INFO GST_STATES gstelement.c:2575:_priv_gst_element_state_changed:<videoconvert1> notifying about state-changed READY to PAUSED (PLAYING pending)
0:00:03.311548028 28532 0x55dae69ff400 INFO GST_STATES gstelement.c:2655:gst_element_continue_state:<videoconvert1> continue state change PAUSED to PLAYING, final PLAYING
0:00:03.311565115 28532 0x55dae69ff400 INFO GST_STATES gstelement.c:2675:gst_element_continue_state:<videoconvert1> completed state change to PLAYING
0:00:03.311583431 28532 0x55dae69ff400 INFO GST_STATES gstelement.c:2575:_priv_gst_element_state_changed:<videoconvert1> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)
0:00:03.311610945 28532 0x55dae69ff400 INFO GST_STATES gstelement.c:2675:gst_element_continue_state:<fake-video-sink> completed state change to NULL
0:00:03.311639226 28532 0x55dae69ff400 INFO GST_ELEMENT_PADS gstpad.c:2132:gst_pad_unlink: unlinking sink:proxypad4(0x55dae6c80560) and fake-video-sink:sink(0x7fa1441eb370)
0:00:03.311662142 28532 0x55dae69ff400 INFO GST_ELEMENT_PADS gstpad.c:2187:gst_pad_unlink: unlinked sink:proxypad4 and fake-video-sink:sink
0:00:03.311681334 28532 0x55dae69ff400 INFO GST_PARENTAGE gstbin.c:1801:gst_bin_remove_func:<autovideosink0> removed child "fake-video-sink"
0:00:03.311713630 28532 0x55dae69ff400 INFO GST_REFCOUNTING gstelement.c:3251:gst_element_dispose:<fake-video-sink> 0x55dae6c91bc0 dispose
0:00:03.311731276 28532 0x55dae69ff400 INFO GST_ELEMENT_PADS gstelement.c:784:gst_element_remove_pad:<fake-video-sink> removing pad 'sink'
0:00:03.311756227 28532 0x55dae69ff400 INFO GST_REFCOUNTING gstelement.c:3296:gst_element_dispose:<fake-video-sink> 0x55dae6c91bc0 parent class dispose
0:00:03.311774634 28532 0x55dae69ff400 INFO GST_REFCOUNTING gstelement.c:3328:gst_element_finalize:<fake-video-sink> 0x55dae6c91bc0 finalize
0:00:03.311792434 28532 0x55dae69ff400 INFO GST_REFCOUNTING gstelement.c:3333:gst_element_finalize:<fake-video-sink> 0x55dae6c91bc0 finalize parent
0:00:03.313357998 28532 0x55dae69ff400 INFO GST_PLUGIN_LOADING gstplugin.c:902:_priv_gst_plugin_load_file_for_registry: plugin "/usr/lib/gstreamer-1.0/libgstxvimagesink.so" loaded
0:00:03.313394142 28532 0x55dae69ff400 INFO GST_ELEMENT_FACTORY gstelementfactory.c:358:gst_element_factory_create: creating element "xvimagesink" named "autovideosink0-actual-sink-xvimage"
0:00:03.313619804 28532 0x55dae69ff400 INFO GST_ELEMENT_PADS gstelement.c:668:gst_element_add_pad:<GstBaseSink@0x55dae6c9cd30> adding pad 'sink'
0:00:03.313658538 28532 0x55dae69ff400 INFO GST_ELEMENT_PADS gstelement.c:915:gst_element_get_static_pad: found pad autovideosink0-actual-sink-xvimage:sink
0:00:03.314805624 28532 0x55dae69ff400 INFO GST_STATES gstelement.c:2675:gst_element_continue_state:<autovideosink0-actual-sink-xvimage> completed state change to READY
0:00:03.314825008 28532 0x55dae69ff400 INFO GST_STATES gstelement.c:2575:_priv_gst_element_state_changed:<autovideosink0-actual-sink-xvimage> notifying about state-changed NULL to READY (VOID_PENDING pending)
0:00:03.365206165 28532 0x55dae69ff400 INFO GST_STATES gstelement.c:2675:gst_element_continue_state:<autovideosink0-actual-sink-xvimage> completed state change to NULL
0:00:03.365236534 28532 0x55dae69ff400 INFO GST_STATES gstelement.c:2575:_priv_gst_element_state_changed:<autovideosink0-actual-sink-xvimage> notifying about state-changed READY to NULL (VOID_PENDING pending)
0:00:03.365356975 28532 0x55dae69ff400 INFO GST_ELEMENT_PADS gstelement.c:915:gst_element_get_static_pad: found pad autovideosink0-actual-sink-xvimage:sink
0:00:03.365385256 28532 0x55dae69ff400 INFO GST_PADS gstpad.c:2377:gst_pad_link_prepare: trying to link sink:proxypad4 and autovideosink0-actual-sink-xvimage:sink
0:00:03.365405493 28532 0x55dae69ff400 INFO GST_PADS gstpad.c:2585:gst_pad_link_full: linked sink:proxypad4 and autovideosink0-actual-sink-xvimage:sink, successful
0:00:03.365420706 28532 0x55dae69ff400 INFO GST_EVENT gstevent.c:1579:gst_event_new_reconfigure: creating reconfigure event
0:00:03.365457837 28532 0x55dae69ff400 INFO GST_STATES gstbin.c:2503:gst_bin_element_set_state:<autovideosink0-actual-sink-xvimage> current NULL pending VOID_PENDING, desired next READY
0:00:03.366707476 28532 0x55dae69ff400 INFO GST_STATES gstelement.c:2675:gst_element_continue_state:<autovideosink0-actual-sink-xvimage> completed state change to READY
0:00:03.366737048 28532 0x55dae69ff400 INFO GST_STATES gstelement.c:2575:_priv_gst_element_state_changed:<autovideosink0-actual-sink-xvimage> notifying about state-changed NULL to READY (VOID_PENDING pending)
0:00:03.366770517 28532 0x55dae69ff400 INFO GST_STATES gstbin.c:2952:gst_bin_change_state_func:<autovideosink0> child 'autovideosink0-actual-sink-xvimage' changed state to 2(READY) successfully
0:00:03.366797717 28532 0x55dae69ff400 INFO GST_STATES gstelement.c:2647:gst_element_continue_state:<autovideosink0> committing state from NULL to READY, pending PLAYING, next PAUSED
0:00:03.366816167 28532 0x55dae69ff400 INFO GST_STATES gstelement.c:2575:_priv_gst_element_state_changed:<autovideosink0> notifying about state-changed NULL to READY (PLAYING pending)
0:00:03.366837773 28532 0x55dae69ff400 INFO GST_STATES gstelement.c:2655:gst_element_continue_state:<autovideosink0> continue state change READY to PAUSED, final PLAYING
0:00:03.366866801 28532 0x55dae69ff400 INFO GST_STATES gstbin.c:2503:gst_bin_element_set_state:<autovideosink0-actual-sink-xvimage> current READY pending VOID_PENDING, desired next PAUSED
0:00:03.366893295 28532 0x55dae69ff400 INFO GST_STATES gstelement.c:2575:_priv_gst_element_state_changed:<pipeline0> notifying about state-changed PAUSED to PAUSED (PAUSED pending)
0:00:03.366925009 28532 0x55dae69ff400 INFO GST_STATES gstbin.c:2959:gst_bin_change_state_func:<autovideosink0> child 'autovideosink0-actual-sink-xvimage' is changing state asynchronously to PAUSED
0:00:03.366954167 28532 0x55dae69ff400 INFO GST_ELEMENT_PADS gstelement.c:915:gst_element_get_static_pad: found pad queue1:sink
0:00:03.366980874 28532 0x55dae69ff400 INFO GST_PADS gstpad.c:2377:gst_pad_link_prepare: trying to link tee0:src_1 and queue1:sink
0:00:03.368227895 28532 0x55dae69ff400 INFO GST_PADS gstpad.c:2585:gst_pad_link_full: linked tee0:src_1 and queue1:sink, successful
0:00:03.368244819 28532 0x55dae69ff400 INFO GST_EVENT gstevent.c:1579:gst_event_new_reconfigure: creating reconfigure event
0:00:03.368298262 28532 0x55dae69ff400 INFO GST_STATES gstelement.c:2675:gst_element_continue_state:<queue1> completed state change to PLAYING
added
0:00:03.370898416 28532 0x7fa1440084f0 INFO basetransform gstbasetransform.c:1317:gst_base_transform_setcaps:<capsfilter0> reuse caps
0:00:03.371166683 28532 0x7fa1480045e0 INFO basetransform gstbasetransform.c:1317:gst_base_transform_setcaps:<videoconvert1> reuse caps
0:00:03.371326584 28532 0x7fa1480045e0 INFO GST_EVENT gstevent.c:820:gst_event_new_caps: creating caps event video/x-raw, format=(string)I420, width=(int)1920, height=(int)1080, interlace-mode=(string)progressive, multiview-mode=(string)mono, multiview-flags=(GstVideoMultiviewFlagsSet)0:ffffffff:/right-view-first/left-flipped/left-flopped/right-flipped/right-flopped/half-aspect/mixed-mono, pixel-aspect-ratio=(fraction)1/1, chroma-site=(string)mpeg2, colorimetry=(string)bt709, framerate=(fraction)30000/1001
0:00:03.380145761 28532 0x7fa1440084f0 INFO basetransform gstbasetransform.c:1317:gst_base_transform_setcaps:<videoconvert0> reuse caps
0:00:03.383742250 28532 0x7fa1480045e0 INFO GST_STATES gstbin.c:3421:bin_handle_async_done:<autovideosink0> committing state from READY to PAUSED, old pending PLAYING
0:00:03.383786698 28532 0x7fa1480045e0 INFO GST_STATES gstbin.c:3444:bin_handle_async_done:<autovideosink0> completed state change, pending VOID
0:00:03.383807177 28532 0x7fa1480045e0 INFO GST_STATES gstelement.c:2575:_priv_gst_element_state_changed:<autovideosink0> notifying about state-changed READY to PAUSED (VOID_PENDING pending)
0:00:03.383841141 28532 0x7fa1480045e0 INFO GST_STATES gstbin.c:3421:bin_handle_async_done:<pipeline0> committing state from PAUSED to PAUSED, old pending PLAYING
0:00:03.383859232 28532 0x7fa1480045e0 INFO GST_STATES gstbin.c:3452:bin_handle_async_done:<pipeline0> continue state change, pending PLAYING
0:00:03.383875189 28532 0x7fa1480045e0 INFO GST_STATES gstelement.c:2575:_priv_gst_element_state_changed:<pipeline0> notifying about state-changed PAUSED to PAUSED (PLAYING pending)
0:00:03.385405431 28532 0x7fa11c0029e0 INFO GST_STATES gstbin.c:3248:gst_bin_continue_func:<pipeline0> continue state change PAUSED to PLAYING, final PLAYING
0:00:03.385542570 28532 0x7fa11c0029e0 INFO GST_EVENT gstevent.c:1449:gst_event_new_latency: creating latency event 0:00:00.000000000
0:00:03.385594134 28532 0x7fa11c0029e0 INFO bin gstbin.c:2783:gst_bin_do_latency_func:<pipeline0> configured latency of 0:00:00.000000000
0:00:03.385629162 28532 0x7fa11c0029e0 INFO GST_STATES gstbin.c:2503:gst_bin_element_set_state:<autovideosink0> current PAUSED pending VOID_PENDING, desired next PLAYING
0:00:03.385647049 28532 0x7fa11c0029e0 INFO GST_STATES gstbin.c:2503:gst_bin_element_set_state:<autovideosink0-actual-sink-xvimage> current PAUSED pending VOID_PENDING, desired next PLAYING
0:00:03.385665137 28532 0x7fa11c0029e0 INFO GST_STATES gstelement.c:2675:gst_element_continue_state:<autovideosink0-actual-sink-xvimage> completed state change to PLAYING
0:00:03.385676475 28532 0x7fa11c0029e0 INFO GST_STATES gstelement.c:2575:_priv_gst_element_state_changed:<autovideosink0-actual-sink-xvimage> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)
0:00:03.385702125 28532 0x7fa11c0029e0 INFO GST_STATES gstbin.c:2952:gst_bin_change_state_func:<autovideosink0> child 'autovideosink0-actual-sink-xvimage' changed state to 4(PLAYING) successfully
0:00:03.385713858 28532 0x7fa11c0029e0 INFO GST_STATES gstelement.c:2675:gst_element_continue_state:<autovideosink0> completed state change to PLAYING
0:00:03.385723595 28532 0x7fa11c0029e0 INFO GST_STATES gstelement.c:2575:_priv_gst_element_state_changed:<autovideosink0> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)
0:00:03.385739901 28532 0x7fa11c0029e0 INFO GST_STATES gstbin.c:2952:gst_bin_change_state_func:<pipeline0> child 'autovideosink0' changed state to 4(PLAYING) successfully
0:00:03.385753300 28532 0x7fa11c0029e0 INFO GST_STATES gstbin.c:2503:gst_bin_element_set_state:<fakesink0> current PLAYING pending VOID_PENDING, desired next PLAYING
0:00:03.385763398 28532 0x7fa11c0029e0 INFO GST_STATES gstbin.c:2621:gst_bin_element_set_state:<fakesink0> skipping transition from PLAYING to PLAYING
0:00:03.385773067 28532 0x7fa11c0029e0 INFO GST_STATES gstbin.c:2952:gst_bin_change_state_func:<pipeline0> child 'fakesink0' changed state to 4(PLAYING) successfully
0:00:03.385788825 28532 0x7fa11c0029e0 INFO GST_STATES gstbin.c:2503:gst_bin_element_set_state:<videoconvert1> current PLAYING pending VOID_PENDING, desired next PLAYING
0:00:03.385798126 28532 0x7fa11c0029e0 INFO GST_STATES gstbin.c:2621:gst_bin_element_set_state:<videoconvert1> skipping transition from PLAYING to PLAYING
0:00:03.385806795 28532 0x7fa11c0029e0 INFO GST_STATES gstbin.c:2952:gst_bin_change_state_func:<pipeline0> child 'videoconvert1' changed state to 4(PLAYING) successfully
0:00:03.385817523 28532 0x7fa11c0029e0 INFO GST_STATES gstbin.c:2503:gst_bin_element_set_state:<queue0> current PLAYING pending VOID_PENDING, desired next PLAYING
0:00:03.385826356 28532 0x7fa11c0029e0 INFO GST_STATES gstbin.c:2621:gst_bin_element_set_state:<queue0> skipping transition from PLAYING to PLAYING
0:00:03.385835532 28532 0x7fa11c0029e0 INFO GST_STATES gstbin.c:2952:gst_bin_change_state_func:<pipeline0> child 'queue0' changed state to 4(PLAYING) successfully
0:00:03.385846203 28532 0x7fa11c0029e0 INFO GST_STATES gstbin.c:2503:gst_bin_element_set_state:<queue1> current PLAYING pending VOID_PENDING, desired next PLAYING
0:00:03.385855029 28532 0x7fa11c0029e0 INFO GST_STATES gstbin.c:2621:gst_bin_element_set_state:<queue1> skipping transition from PLAYING to PLAYING
0:00:03.385864249 28532 0x7fa11c0029e0 INFO GST_STATES gstbin.c:2952:gst_bin_change_state_func:<pipeline0> child 'queue1' changed state to 4(PLAYING) successfully
0:00:03.385874516 28532 0x7fa11c0029e0 INFO GST_STATES gstbin.c:2503:gst_bin_element_set_state:<tee0> current PLAYING pending VOID_PENDING, desired next PLAYING
0:00:03.385883039 28532 0x7fa11c0029e0 INFO GST_STATES gstbin.c:2621:gst_bin_element_set_state:<tee0> skipping transition from PLAYING to PLAYING
0:00:03.385892754 28532 0x7fa11c0029e0 INFO GST_STATES gstbin.c:2952:gst_bin_change_state_func:<pipeline0> child 'tee0' changed state to 4(PLAYING) successfully
0:00:03.385904895 28532 0x7fa11c0029e0 INFO GST_STATES gstbin.c:2503:gst_bin_element_set_state:<videoconvert0> current PLAYING pending VOID_PENDING, desired next PLAYING
0:00:03.385913269 28532 0x7fa11c0029e0 INFO GST_STATES gstbin.c:2621:gst_bin_element_set_state:<videoconvert0> skipping transition from PLAYING to PLAYING
0:00:03.385922557 28532 0x7fa11c0029e0 INFO GST_STATES gstbin.c:2952:gst_bin_change_state_func:<pipeline0> child 'videoconvert0' changed state to 4(PLAYING) successfully
0:00:03.385933091 28532 0x7fa11c0029e0 INFO GST_STATES gstbin.c:2503:gst_bin_element_set_state:<decodebin0> current PLAYING pending VOID_PENDING, desired next PLAYING
0:00:03.385954181 28532 0x7fa11c0029e0 INFO GST_STATES gstbin.c:2503:gst_bin_element_set_state:<avdec_aac0> current PLAYING pending VOID_PENDING, desired next PLAYING
0:00:03.385963935 28532 0x7fa11c0029e0 INFO GST_STATES gstbin.c:2621:gst_bin_element_set_state:<avdec_aac0> skipping transition from PLAYING to PLAYING
0:00:03.385973296 28532 0x7fa11c0029e0 INFO GST_STATES gstbin.c:2952:gst_bin_change_state_func:<decodebin0> child 'avdec_aac0' changed state to 4(PLAYING) successfully
0:00:03.385983770 28532 0x7fa11c0029e0 INFO GST_STATES gstbin.c:2503:gst_bin_element_set_state:<aacparse0> current PLAYING pending VOID_PENDING, desired next PLAYING
0:00:03.385992669 28532 0x7fa11c0029e0 INFO GST_STATES gstbin.c:2621:gst_bin_element_set_state:<aacparse0> skipping transition from PLAYING to PLAYING
0:00:03.386001943 28532 0x7fa11c0029e0 INFO GST_STATES gstbin.c:2952:gst_bin_change_state_func:<decodebin0> child 'aacparse0' changed state to 4(PLAYING) successfully
0:00:03.386012925 28532 0x7fa11c0029e0 INFO GST_STATES gstbin.c:2503:gst_bin_element_set_state:<avdec_h264-0> current PLAYING pending VOID_PENDING, desired next PLAYING
0:00:03.386021722 28532 0x7fa11c0029e0 INFO GST_STATES gstbin.c:2621:gst_bin_element_set_state:<avdec_h264-0> skipping transition from PLAYING to PLAYING
0:00:03.386031012 28532 0x7fa11c0029e0 INFO GST_STATES gstbin.c:2952:gst_bin_change_state_func:<decodebin0> child 'avdec_h264-0' changed state to 4(PLAYING) successfully
0:00:03.386041458 28532 0x7fa11c0029e0 INFO GST_STATES gstbin.c:2503:gst_bin_element_set_state:<capsfilter0> current PLAYING pending VOID_PENDING, desired next PLAYING
0:00:03.386050457 28532 0x7fa11c0029e0 INFO GST_STATES gstbin.c:2621:gst_bin_element_set_state:<capsfilter0> skipping transition from PLAYING to PLAYING
0:00:03.386059930 28532 0x7fa11c0029e0 INFO GST_STATES gstbin.c:2952:gst_bin_change_state_func:<decodebin0> child 'capsfilter0' changed state to 4(PLAYING) successfully
0:00:03.386070561 28532 0x7fa11c0029e0 INFO GST_STATES gstbin.c:2503:gst_bin_element_set_state:<h264parse0> current PLAYING pending VOID_PENDING, desired next PLAYING
0:00:03.386079233 28532 0x7fa11c0029e0 INFO GST_STATES gstbin.c:2621:gst_bin_element_set_state:<h264parse0> skipping transition from PLAYING to PLAYING
0:00:03.386088346 28532 0x7fa11c0029e0 INFO GST_STATES gstbin.c:2952:gst_bin_change_state_func:<decodebin0> child 'h264parse0' changed state to 4(PLAYING) successfully
0:00:03.386100034 28532 0x7fa11c0029e0 INFO GST_STATES gstbin.c:2503:gst_bin_element_set_state:<multiqueue0> current PLAYING pending VOID_PENDING, desired next PLAYING
0:00:03.386108819 28532 0x7fa11c0029e0 INFO GST_STATES gstbin.c:2621:gst_bin_element_set_state:<multiqueue0> skipping transition from PLAYING to PLAYING
0:00:03.386117831 28532 0x7fa11c0029e0 INFO GST_STATES gstbin.c:2952:gst_bin_change_state_func:<decodebin0> child 'multiqueue0' changed state to 4(PLAYING) successfully
0:00:03.386128766 28532 0x7fa11c0029e0 INFO GST_STATES gstbin.c:2503:gst_bin_element_set_state:<qtdemux0> current PLAYING pending VOID_PENDING, desired next PLAYING
0:00:03.386137663 28532 0x7fa11c0029e0 INFO GST_STATES gstbin.c:2621:gst_bin_element_set_state:<qtdemux0> skipping transition from PLAYING to PLAYING
0:00:03.386146782 28532 0x7fa11c0029e0 INFO GST_STATES gstbin.c:2952:gst_bin_change_state_func:<decodebin0> child 'qtdemux0' changed state to 4(PLAYING) successfully
0:00:03.386157000 28532 0x7fa11c0029e0 INFO GST_STATES gstbin.c:2503:gst_bin_element_set_state:<typefind> current PLAYING pending VOID_PENDING, desired next PLAYING
0:00:03.386165506 28532 0x7fa11c0029e0 INFO GST_STATES gstbin.c:2621:gst_bin_element_set_state:<typefind> skipping transition from PLAYING to PLAYING
0:00:03.386174667 28532 0x7fa11c0029e0 INFO GST_STATES gstbin.c:2952:gst_bin_change_state_func:<decodebin0> child 'typefind' changed state to 4(PLAYING) successfully
0:00:03.386185065 28532 0x7fa11c0029e0 INFO GST_STATES gstelement.c:2675:gst_element_continue_state:<decodebin0> completed state change to PLAYING
0:00:03.386196604 28532 0x7fa11c0029e0 INFO GST_STATES gstbin.c:2952:gst_bin_change_state_func:<pipeline0> child 'decodebin0' changed state to 4(PLAYING) successfully
0:00:03.386210315 28532 0x7fa11c0029e0 INFO GST_STATES gstbin.c:2503:gst_bin_element_set_state:<filesrc0> current PLAYING pending VOID_PENDING, desired next PLAYING
0:00:03.386219693 28532 0x7fa11c0029e0 INFO GST_STATES gstbin.c:2621:gst_bin_element_set_state:<filesrc0> skipping transition from PLAYING to PLAYING
0:00:03.386229896 28532 0x7fa11c0029e0 INFO GST_STATES gstbin.c:2952:gst_bin_change_state_func:<pipeline0> child 'filesrc0' changed state to 4(PLAYING) successfully
0:00:03.386240621 28532 0x7fa11c0029e0 INFO GST_STATES gstelement.c:2675:gst_element_continue_state:<pipeline0> completed state change to PLAYING
0:00:03.386250895 28532 0x7fa11c0029e0 INFO GST_STATES gstelement.c:2575:_priv_gst_element_state_changed:<pipeline0> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)
0:00:04.274561020 28532 0x7fa144145540 INFO audiodecoder gstaudiodecoder.c:2454:gst_audio_decoder_sink_eventfunc:<avdec_aac0> upstream stream tags: taglist, audio-codec=(string)"MPEG-4\ AAC", maximum-bitrate=(uint)384000, bitrate=(uint)384000, language-code=(string)en, minimum-bitrate=(uint)272249;