Skip to content

Instantly share code, notes, and snippets.

@virtuald

virtuald/debug.log

Last active August 29, 2015 14:22
Show Gist options
  • Save virtuald/7592a16d6dee07404438 to your computer and use it in GitHub Desktop.
Save virtuald/7592a16d6dee07404438 to your computer and use it in GitHub Desktop.
Download ZIP
GStreamer deadlock
Raw
debug.log
0:00:00.000044940 24400 0xd5e720 INFO GST_INIT gst.c:499:init_pre: Initializing GStreamer Core Library version 1.4.5
0:00:00.000090481 24400 0xd5e720 INFO GST_INIT gst.c:500:init_pre: Using library installed in /usr/lib64
0:00:00.000100859 24400 0xd5e720 INFO GST_INIT gst.c:511:init_pre: Linux localhost.localdomain 3.19.3-200.fc21.x86_64 #1 SMP Thu Mar 26 21:39:42 UTC 2015 x86_64
0:00:00.000254496 24400 0xd5e720 INFO GST_INIT gstmessage.c:119:_priv_gst_message_initialize: init messages
0:00:00.000601084 24400 0xd5e720 INFO GST_INIT gstcontext.c:77:_priv_gst_context_initialize: init contexts
0:00:00.000787706 24400 0xd5e720 INFO GST_PLUGIN_LOADING gstplugin.c:317:_priv_gst_plugin_initialize: registering 0 static plugins
0:00:00.000865813 24400 0xd5e720 INFO GST_PLUGIN_LOADING gstplugin.c:225:gst_plugin_register_static: registered static plugin "staticelements"
0:00:00.000876420 24400 0xd5e720 INFO GST_PLUGIN_LOADING gstplugin.c:227:gst_plugin_register_static: added static plugin "staticelements", result: 1
0:00:00.000897381 24400 0xd5e720 INFO GST_REGISTRY gstregistry.c:1722:ensure_current_registry: reading registry cache: /home/virtuald/.cache/gstreamer-1.0/registry.x86_64.bin
0:00:00.014997031 24400 0xd5e720 INFO GST_REGISTRY gstregistrybinary.c:619:priv_gst_registry_binary_read_cache: loaded /home/virtuald/.cache/gstreamer-1.0/registry.x86_64.bin in 0.014084 seconds
0:00:00.015045124 24400 0xd5e720 INFO GST_REGISTRY gstregistry.c:1578:scan_and_update_registry: Validating plugins from registry cache: /home/virtuald/.cache/gstreamer-1.0/registry.x86_64.bin
0:00:00.016082467 24400 0xd5e720 INFO GST_REGISTRY gstregistry.c:1680:scan_and_update_registry: Registry cache has not changed
0:00:00.016093110 24400 0xd5e720 INFO GST_REGISTRY gstregistry.c:1757:ensure_current_registry: registry reading and updating done, result = 1
0:00:00.016099754 24400 0xd5e720 INFO GST_INIT gst.c:709:init_post: GLib runtime version: 2.42.2
0:00:00.016106452 24400 0xd5e720 INFO GST_INIT gst.c:711:init_post: GLib headers version: 2.42.1
0:00:00.016115186 24400 0xd5e720 INFO GST_INIT gst.c:348:gst_init_check: initialized GStreamer successfully
0:00:00.016196019 24400 0xd5e720 INFO GST_ELEMENT_FACTORY gstelementfactory.c:362:gst_element_factory_create: creating element "pipeline" named "pipe"
0:00:00.017562956 24400 0xd5e720 INFO GST_PLUGIN_LOADING gstplugin.c:833:gst_plugin_load_file: plugin "/usr/lib64/gstreamer-1.0/libgstplayback.so" loaded
0:00:00.017577492 24400 0xd5e720 INFO GST_ELEMENT_FACTORY gstelementfactory.c:364:gst_element_factory_create: creating element "playbin"
0:00:00.018338311 24400 0xd5e720 WARN playbin gstplaybin2.c:1569:gst_playbin_uri_is_valid:<playbin0> uri 'file:///home/virtuald/Music/DJ/emusic/Artie Shaw - You're A Lucky Guy.mp3' not valid, character #43
0:00:00.018353815 24400 0xd5e720 WARN playbin gstplaybin2.c:1589:gst_play_bin_set_uri:<playbin0> not entirely correct file URI 'file:///home/virtuald/Music/DJ/emusic/Artie Shaw - You're A Lucky Guy.mp3' - make sure to escape spaces and non-ASCII characters properly and specify an absolute path. Use gst_filename_to_uri() to convert filenames to URIs
0:00:00.018507652 24400 0xd5e720 INFO GST_PLUGIN_LOADING gstplugin.c:833:gst_plugin_load_file: plugin "/usr/lib64/gstreamer-1.0/libgstautodetect.so" loaded
0:00:00.018518517 24400 0xd5e720 INFO GST_ELEMENT_FACTORY gstelementfactory.c:364:gst_element_factory_create: creating element "autoaudiosink"
0:00:00.018590802 24400 0xd5e720 INFO GST_ELEMENT_PADS gstelement.c:643:gst_element_add_pad:<autoaudiosink0> adding pad 'sink'
0:00:00.018902710 24400 0xd5e720 INFO GST_PLUGIN_LOADING gstplugin.c:833:gst_plugin_load_file: plugin "/usr/lib64/gstreamer-1.0/libgstcoreelements.so" loaded
0:00:00.018921036 24400 0xd5e720 INFO GST_ELEMENT_FACTORY gstelementfactory.c:362:gst_element_factory_create: creating element "fakesink" named "fake-audio-sink"
0:00:00.019016818 24400 0xd5e720 INFO GST_ELEMENT_PADS gstelement.c:643:gst_element_add_pad:<GstBaseSink@0xfece00> adding pad 'sink'
0:00:00.019039828 24400 0xd5e720 INFO GST_ELEMENT_PADS gstelement.c:895:gst_element_get_static_pad: found pad fake-audio-sink:sink
0:00:00.019049500 24400 0xd5e720 INFO GST_PADS gstpad.c:2186:gst_pad_link_prepare: trying to link sink:proxypad0 and fake-audio-sink:sink
0:00:00.019057873 24400 0xd5e720 INFO GST_PADS gstpad.c:2388:gst_pad_link_full: linked sink:proxypad0 and fake-audio-sink:sink, successful
0:00:00.019064695 24400 0xd5e720 INFO GST_EVENT gstevent.c:1373:gst_event_new_reconfigure: creating reconfigure event
0:00:00.019499351 24400 0xd5e720 INFO GST_PLUGIN_LOADING gstplugin.c:833:gst_plugin_load_file: plugin "/usr/lib64/gstreamer-1.0/libgstadder.so" loaded
0:00:00.019510864 24400 0xd5e720 INFO GST_ELEMENT_FACTORY gstelementfactory.c:364:gst_element_factory_create: creating element "adder"
0:00:00.019563479 24400 0xd5e720 INFO adder gstadder.c:1653:gst_adder_child_proxy_init: intializing child proxy interface
0:00:00.019598301 24400 0xd5e720 INFO GST_ELEMENT_PADS gstelement.c:643:gst_element_add_pad:<GstAdder@0xff40c0> adding pad 'src'
0:00:00.019848112 24400 0xd5e720 INFO GST_ELEMENT_PADS gstutils.c:1545:gst_element_link_pads_full: trying to link element adder0:(any) to element autoaudiosink0:(any)
0:00:00.019864087 24400 0xd5e720 INFO GST_PADS gstutils.c:937:gst_pad_check_link: trying to link adder0:src and autoaudiosink0:sink
0:00:00.019889868 24400 0xd5e720 INFO GST_PADS gstutils.c:1445:prepare_link_maybe_ghosting: adder0 and autoaudiosink0 in same bin, no need for ghost pads
0:00:00.019903590 24400 0xd5e720 INFO GST_PADS gstpad.c:2186:gst_pad_link_prepare: trying to link adder0:src and autoaudiosink0:sink
0:00:00.019918299 24400 0xd5e720 INFO GST_PADS gstpad.c:2388:gst_pad_link_full: linked adder0:src and autoaudiosink0:sink, successful
0:00:00.019925871 24400 0xd5e720 INFO GST_EVENT gstevent.c:1373:gst_event_new_reconfigure: creating reconfigure event
0:00:00.019938154 24400 0xd5e720 INFO GST_EVENT gstpad.c:5182:gst_pad_send_event_unchecked:<adder0:src> Received event on flushing pad. Discarding
0:00:00.019986971 24400 0xd5e720 INFO GST_ELEMENT_FACTORY gstelementfactory.c:362:gst_element_factory_create: creating element "bin" named "out1"
0:00:00.020037419 24400 0xd5e720 INFO playbin gstplaybin2.c:2227:gst_play_bin_set_sink:<playbin0> Setting audio sink to <out1>
0:00:00.020120370 24400 0xd5e720 INFO GST_STATES gstbin.c:2230:gst_bin_element_set_state:<playsink> current NULL pending VOID_PENDING, desired next NULL
0:00:00.020137145 24400 0xd5e720 INFO GST_STATES gstbin.c:2230:gst_bin_element_set_state:<streamsynchronizer0> current NULL pending VOID_PENDING, desired next NULL
0:00:00.020144360 24400 0xd5e720 INFO GST_STATES gstbin.c:2347:gst_bin_element_set_state:<streamsynchronizer0> skipping transition from NULL to NULL
0:00:00.020151471 24400 0xd5e720 INFO GST_STATES gstbin.c:2673:gst_bin_change_state_func:<playsink> child 'streamsynchronizer0' changed state to 1(NULL) successfully
0:00:00.020161806 24400 0xd5e720 INFO GST_STATES gstelement.c:2328:gst_element_continue_state:<playsink> completed state change to NULL
0:00:00.020168792 24400 0xd5e720 INFO GST_STATES gstbin.c:2673:gst_bin_change_state_func:<playbin0> child 'playsink' changed state to 1(NULL) successfully
0:00:00.020176636 24400 0xd5e720 INFO GST_STATES gstelement.c:2328:gst_element_continue_state:<playbin0> completed state change to NULL
0:00:00.020256908 24400 0xd5e720 INFO GST_ELEMENT_PADS gstelement.c:643:gst_element_add_pad:<adder0> adding pad 'sink_0'
0:00:00.020438629 24400 0xd5e720 INFO GST_PADS gstpad.c:2186:gst_pad_link_prepare: trying to link sink:proxypad1 and adder0:sink_0
0:00:00.020451273 24400 0xd5e720 INFO GST_PADS gstpad.c:2388:gst_pad_link_full: linked sink:proxypad1 and adder0:sink_0, successful
0:00:00.020458320 24400 0xd5e720 INFO GST_EVENT gstevent.c:1373:gst_event_new_reconfigure: creating reconfigure event
0:00:00.020507108 24400 0xd5e720 INFO GST_ELEMENT_PADS gstelement.c:643:gst_element_add_pad:<out1> adding pad 'sink'
0:00:00.020730127 24400 0xd5e720 INFO GST_STATES gstbin.c:2230:gst_bin_element_set_state:<playbin0> current NULL pending VOID_PENDING, desired next READY
0:00:00.020748412 24400 0xd5e720 INFO GST_STATES gstbin.c:2230:gst_bin_element_set_state:<playsink> current NULL pending VOID_PENDING, desired next READY
0:00:00.020760101 24400 0xd5e720 INFO GST_STATES gstbin.c:2230:gst_bin_element_set_state:<streamsynchronizer0> current NULL pending VOID_PENDING, desired next READY
0:00:00.020769153 24400 0xd5e720 INFO GST_STATES gstelement.c:2328:gst_element_continue_state:<streamsynchronizer0> completed state change to READY
0:00:00.020775452 24400 0xd5e720 INFO GST_STATES gstelement.c:2233:_priv_gst_element_state_changed:<streamsynchronizer0> notifying about state-changed NULL to READY (VOID_PENDING pending)
0:00:00.020798303 24400 0xd5e720 INFO GST_STATES gstbin.c:2673:gst_bin_change_state_func:<playsink> child 'streamsynchronizer0' changed state to 2(READY) successfully
0:00:00.020808650 24400 0xd5e720 INFO GST_STATES gstelement.c:2328:gst_element_continue_state:<playsink> completed state change to READY
0:00:00.020814822 24400 0xd5e720 INFO GST_STATES gstelement.c:2233:_priv_gst_element_state_changed:<playsink> notifying about state-changed NULL to READY (VOID_PENDING pending)
0:00:00.020824798 24400 0xd5e720 INFO GST_STATES gstbin.c:2673:gst_bin_change_state_func:<playbin0> child 'playsink' changed state to 2(READY) successfully
0:00:00.020833046 24400 0xd5e720 INFO GST_STATES gstelement.c:2328:gst_element_continue_state:<playbin0> completed state change to READY
0:00:00.020838786 24400 0xd5e720 INFO GST_STATES gstelement.c:2233:_priv_gst_element_state_changed:<playbin0> notifying about state-changed NULL to READY (VOID_PENDING pending)
0:00:00.020847881 24400 0xd5e720 INFO GST_STATES gstbin.c:2673:gst_bin_change_state_func:<pipe> child 'playbin0' changed state to 2(READY) successfully
0:00:00.020856698 24400 0xd5e720 INFO GST_STATES gstbin.c:2230:gst_bin_element_set_state:<autoaudiosink0> current NULL pending VOID_PENDING, desired next READY
0:00:00.020865809 24400 0xd5e720 INFO GST_STATES gstelement.c:2328:gst_element_continue_state:<fake-audio-sink> completed state change to NULL
0:00:00.020874560 24400 0xd5e720 INFO GST_ELEMENT_PADS gstpad.c:1943:gst_pad_unlink: unlinking sink:proxypad0(0xfe6040) and fake-audio-sink:sink(0xfee0a0)
0:00:00.020883798 24400 0xd5e720 INFO GST_ELEMENT_PADS gstpad.c:1997:gst_pad_unlink: unlinked sink:proxypad0 and fake-audio-sink:sink
0:00:00.020891522 24400 0xd5e720 INFO GST_PARENTAGE gstbin.c:1554:gst_bin_remove_func:<autoaudiosink0> removed child "fake-audio-sink"
0:00:00.020900278 24400 0xd5e720 INFO GST_REFCOUNTING gstelement.c:2873:gst_element_dispose:<fake-audio-sink> dispose
0:00:00.020905948 24400 0xd5e720 INFO GST_ELEMENT_PADS gstelement.c:763:gst_element_remove_pad:<fake-audio-sink> removing pad 'sink'
0:00:00.020918079 24400 0xd5e720 INFO GST_REFCOUNTING gstelement.c:2917:gst_element_dispose:<fake-audio-sink> parent class dispose
0:00:00.020929987 24400 0xd5e720 INFO GST_REFCOUNTING gstelement.c:2948:gst_element_finalize:<fake-audio-sink> finalize
0:00:00.020942577 24400 0xd5e720 INFO GST_REFCOUNTING gstelement.c:2953:gst_element_finalize:<fake-audio-sink> finalize parent
0:00:00.025248678 24400 0xd5e720 INFO GST_PLUGIN_LOADING gstplugin.c:833:gst_plugin_load_file: plugin "/usr/lib64/gstreamer-1.0/libgstpulse.so" loaded
0:00:00.025266794 24400 0xd5e720 INFO GST_ELEMENT_FACTORY gstelementfactory.c:362:gst_element_factory_create: creating element "pulsesink" named "autoaudiosink0-actual-sink-pulse"
0:00:00.025399487 24400 0xd5e720 INFO GST_ELEMENT_PADS gstelement.c:643:gst_element_add_pad:<GstBaseSink@0x100d6f0> adding pad 'sink'
0:00:00.025486650 24400 0xd5e720 INFO GST_ELEMENT_PADS gstelement.c:895:gst_element_get_static_pad: found pad autoaudiosink0-actual-sink-pulse:sink
0:00:00.025509592 24400 0xd5e720 INFO pulse pulsesink.c:3239:gst_pulsesink_change_state:<autoaudiosink0-actual-sink-pulse> new pa main loop thread
0:00:00.025600634 24400 0xd5e720 INFO pulse pulsesink.c:533:gst_pulseringbuffer_open_device:<autoaudiosink0-actual-sink-pulse> new context with name python, pbuf=0x1010070, pctx=0xff9010
0:00:00.028192179 24400 0xd5e720 INFO GST_STATES gstelement.c:2328:gst_element_continue_state:<autoaudiosink0-actual-sink-pulse> completed state change to READY
0:00:00.028209894 24400 0xd5e720 INFO GST_STATES gstelement.c:2233:_priv_gst_element_state_changed:<autoaudiosink0-actual-sink-pulse> notifying about state-changed NULL to READY (VOID_PENDING pending)
0:00:00.028266859 24400 0xd5e720 INFO GST_ELEMENT_PADS gstelement.c:895:gst_element_get_static_pad: found pad autoaudiosink0-actual-sink-pulse:sink
0:00:00.028278813 24400 0xd5e720 INFO GST_PADS gstpad.c:2186:gst_pad_link_prepare: trying to link sink:proxypad0 and autoaudiosink0-actual-sink-pulse:sink
0:00:00.028287720 24400 0xd5e720 INFO GST_PADS gstpad.c:2388:gst_pad_link_full: linked sink:proxypad0 and autoaudiosink0-actual-sink-pulse:sink, successful
0:00:00.028294837 24400 0xd5e720 INFO GST_EVENT gstevent.c:1373:gst_event_new_reconfigure: creating reconfigure event
0:00:00.028312538 24400 0xd5e720 INFO GST_STATES gstbin.c:2230:gst_bin_element_set_state:<autoaudiosink0-actual-sink-pulse> current READY pending VOID_PENDING, desired next READY
0:00:00.028320674 24400 0xd5e720 INFO GST_STATES gstbin.c:2347:gst_bin_element_set_state:<autoaudiosink0-actual-sink-pulse> skipping transition from READY to READY
0:00:00.028327221 24400 0xd5e720 INFO GST_STATES gstbin.c:2673:gst_bin_change_state_func:<autoaudiosink0> child 'autoaudiosink0-actual-sink-pulse' changed state to 2(READY) successfully
0:00:00.028336643 24400 0xd5e720 INFO GST_STATES gstelement.c:2328:gst_element_continue_state:<autoaudiosink0> completed state change to READY
0:00:00.028342790 24400 0xd5e720 INFO GST_STATES gstelement.c:2233:_priv_gst_element_state_changed:<autoaudiosink0> notifying about state-changed NULL to READY (VOID_PENDING pending)
0:00:00.028354139 24400 0xd5e720 INFO GST_STATES gstbin.c:2673:gst_bin_change_state_func:<pipe> child 'autoaudiosink0' changed state to 2(READY) successfully
0:00:00.028363846 24400 0xd5e720 INFO GST_STATES gstbin.c:2230:gst_bin_element_set_state:<adder0> current NULL pending VOID_PENDING, desired next READY
0:00:00.028372628 24400 0xd5e720 INFO GST_STATES gstelement.c:2328:gst_element_continue_state:<adder0> completed state change to READY
0:00:00.028378345 24400 0xd5e720 INFO GST_STATES gstelement.c:2233:_priv_gst_element_state_changed:<adder0> notifying about state-changed NULL to READY (VOID_PENDING pending)
0:00:00.028387366 24400 0xd5e720 INFO GST_STATES gstbin.c:2673:gst_bin_change_state_func:<pipe> child 'adder0' changed state to 2(READY) successfully
0:00:00.028404050 24400 0xd5e720 INFO GST_STATES gstelement.c:2303:gst_element_continue_state:<pipe> committing state from NULL to READY, pending PLAYING, next PAUSED
0:00:00.028411944 24400 0xd5e720 INFO GST_STATES gstelement.c:2233:_priv_gst_element_state_changed:<pipe> notifying about state-changed NULL to READY (PLAYING pending)
0:00:00.028420176 24400 0xd5e720 INFO GST_STATES gstelement.c:2310:gst_element_continue_state:<pipe> continue state change READY to PAUSED, final PLAYING
0:00:00.028431908 24400 0xd5e720 INFO GST_STATES gstbin.c:2230:gst_bin_element_set_state:<playbin0> current READY pending VOID_PENDING, desired next PAUSED
0:00:00.028477151 24400 0xd5e720 INFO GST_STATES gstelement.c:2328:gst_element_continue_state:<out1> completed state change to READY
0:00:00.028485860 24400 0xd5e720 INFO GST_STATES gstelement.c:2233:_priv_gst_element_state_changed:<out1> notifying about state-changed NULL to READY (VOID_PENDING pending)
0:00:00.028506347 24400 0xd5e720 INFO GST_ELEMENT_FACTORY gstelementfactory.c:364:gst_element_factory_create: creating element "uridecodebin"
0:00:00.028643686 24400 0xd5e720 INFO GST_STATES gstelement.c:2328:gst_element_continue_state:<uridecodebin0> completed state change to READY
0:00:00.028653776 24400 0xd5e720 INFO GST_STATES gstelement.c:2233:_priv_gst_element_state_changed:<uridecodebin0> notifying about state-changed NULL to READY (VOID_PENDING pending)
0:00:00.028670365 24400 0xd5e720 INFO GST_STATES gstbin.c:2230:gst_bin_element_set_state:<playsink> current READY pending VOID_PENDING, desired next PAUSED
0:00:00.028679586 24400 0xd5e720 INFO playsink gstplaysink.c:1400:do_async_start:<playsink> Sending async_start message
0:00:00.028692234 24400 0xd5e720 INFO GST_STATES gstbin.c:2230:gst_bin_element_set_state:<streamsynchronizer0> current READY pending VOID_PENDING, desired next PAUSED
0:00:00.028702811 24400 0xd5e720 INFO GST_STATES gstelement.c:2328:gst_element_continue_state:<streamsynchronizer0> completed state change to PAUSED
0:00:00.028708972 24400 0xd5e720 INFO GST_STATES gstelement.c:2233:_priv_gst_element_state_changed:<streamsynchronizer0> notifying about state-changed READY to PAUSED (VOID_PENDING pending)
0:00:00.028724174 24400 0xd5e720 INFO GST_STATES gstbin.c:2673:gst_bin_change_state_func:<playsink> child 'streamsynchronizer0' changed state to 3(PAUSED) successfully
0:00:00.028735207 24400 0xd5e720 INFO GST_STATES gstbin.c:2679:gst_bin_change_state_func:<playbin0> child 'playsink' is changing state asynchronously to PAUSED
0:00:00.028743425 24400 0xd5e720 INFO GST_STATES gstbin.c:2230:gst_bin_element_set_state:<uridecodebin0> current READY pending VOID_PENDING, desired next PAUSED
0:00:00.028810643 24400 0xd5e720 INFO GST_ELEMENT_FACTORY gstelementfactory.c:362:gst_element_factory_create: creating element "filesrc" named "source"
0:00:00.028870735 24400 0xd5e720 INFO GST_ELEMENT_PADS gstelement.c:643:gst_element_add_pad:<GstBaseSrc@0xfde480> adding pad 'src'
0:00:00.028892565 24400 0xd5e720 INFO filesrc gstfilesrc.c:253:gst_file_src_set_location: filename : /home/virtuald/Music/DJ/emusic/Artie Shaw - You're A Lucky Guy.mp3
0:00:00.028900049 24400 0xd5e720 INFO filesrc gstfilesrc.c:254:gst_file_src_set_location: uri : file:///home/virtuald/Music/DJ/emusic/Artie%20Shaw%20-%20You're%20A%20Lucky%20Guy.mp3
0:00:00.028913892 24400 0xd5e720 INFO filesrc gstfilesrc.c:450:gst_file_src_start:<source> opening file /home/virtuald/Music/DJ/emusic/Artie Shaw - You're A Lucky Guy.mp3
0:00:00.028953229 24400 0xd5e720 WARN basesrc gstbasesrc.c:3470:gst_base_src_start_complete:<source> pad not activated yet
0:00:00.029003559 24400 0xd5e720 INFO GST_ELEMENT_FACTORY gstelementfactory.c:364:gst_element_factory_create: creating element "decodebin"
0:00:00.029088811 24400 0xd5e720 INFO GST_ELEMENT_FACTORY gstelementfactory.c:362:gst_element_factory_create: creating element "typefind" named "typefind"
0:00:00.029144851 24400 0xd5e720 INFO GST_ELEMENT_PADS gstelement.c:643:gst_element_add_pad:<GstTypeFindElement@0x101e130> adding pad 'sink'
0:00:00.029165388 24400 0xd5e720 INFO GST_ELEMENT_PADS gstelement.c:643:gst_element_add_pad:<GstTypeFindElement@0x101e130> adding pad 'src'
0:00:00.029190159 24400 0xd5e720 INFO GST_ELEMENT_PADS gstelement.c:895:gst_element_get_static_pad: found pad typefind:sink
0:00:00.029218625 24400 0xd5e720 INFO GST_PADS gstpad.c:2186:gst_pad_link_prepare: trying to link sink:proxypad2 and typefind:sink
0:00:00.029227615 24400 0xd5e720 INFO GST_PADS gstpad.c:2388:gst_pad_link_full: linked sink:proxypad2 and typefind:sink, successful
0:00:00.029234388 24400 0xd5e720 INFO GST_EVENT gstevent.c:1373:gst_event_new_reconfigure: creating reconfigure event
0:00:00.029245547 24400 0xd5e720 INFO GST_ELEMENT_PADS gstelement.c:643:gst_element_add_pad:<GstDecodeBin@0xfe47e0> adding pad 'sink'
0:00:00.029291455 24400 0xd5e720 INFO GST_ELEMENT_PADS gstutils.c:1545:gst_element_link_pads_full: trying to link element source:(any) to element decodebin0:sink
0:00:00.029301605 24400 0xd5e720 INFO GST_ELEMENT_PADS gstelement.c:895:gst_element_get_static_pad: found pad decodebin0:sink
0:00:00.029308432 24400 0xd5e720 INFO GST_PADS gstutils.c:1445:prepare_link_maybe_ghosting: source and decodebin0 in same bin, no need for ghost pads
0:00:00.029318442 24400 0xd5e720 INFO GST_PADS gstpad.c:2186:gst_pad_link_prepare: trying to link source:src and decodebin0:sink
0:00:00.029334713 24400 0xd5e720 INFO GST_PADS gstpad.c:2388:gst_pad_link_full: linked source:src and decodebin0:sink, successful
0:00:00.029342053 24400 0xd5e720 INFO GST_EVENT gstevent.c:1373:gst_event_new_reconfigure: creating reconfigure event
0:00:00.029347672 24400 0xd5e720 INFO GST_EVENT gstpad.c:5182:gst_pad_send_event_unchecked:<source:src> Received event on flushing pad. Discarding
0:00:00.029362280 24400 0xd5e720 INFO GST_STATES gstbin.c:2230:gst_bin_element_set_state:<decodebin0> current NULL pending VOID_PENDING, desired next PAUSED
0:00:00.029375284 24400 0xd5e720 INFO GST_STATES gstbin.c:2230:gst_bin_element_set_state:<typefind> current NULL pending VOID_PENDING, desired next READY
0:00:00.029383838 24400 0xd5e720 INFO GST_STATES gstelement.c:2328:gst_element_continue_state:<typefind> completed state change to READY
0:00:00.029389682 24400 0xd5e720 INFO GST_STATES gstelement.c:2233:_priv_gst_element_state_changed:<typefind> notifying about state-changed NULL to READY (VOID_PENDING pending)
0:00:00.029400271 24400 0xd5e720 INFO GST_STATES gstbin.c:2673:gst_bin_change_state_func:<decodebin0> child 'typefind' changed state to 2(READY) successfully
0:00:00.029409050 24400 0xd5e720 INFO GST_STATES gstelement.c:2303:gst_element_continue_state:<decodebin0> committing state from NULL to READY, pending PAUSED, next PAUSED
0:00:00.029424274 24400 0xd5e720 INFO GST_STATES gstelement.c:2233:_priv_gst_element_state_changed:<decodebin0> notifying about state-changed NULL to READY (PAUSED pending)
0:00:00.029434121 24400 0xd5e720 INFO GST_STATES gstelement.c:2310:gst_element_continue_state:<decodebin0> continue state change READY to PAUSED, final PAUSED
0:00:00.029450904 24400 0xd5e720 INFO GST_STATES gstbin.c:2230:gst_bin_element_set_state:<typefind> current READY pending VOID_PENDING, desired next PAUSED
0:00:00.029471724 24400 0xd5e720 INFO filesrc gstfilesrc.c:450:gst_file_src_start:<source> opening file /home/virtuald/Music/DJ/emusic/Artie Shaw - You're A Lucky Guy.mp3
0:00:00.029494036 24400 0xd5e720 WARN basesrc gstbasesrc.c:3470:gst_base_src_start_complete:<source> pad not activated yet
0:00:00.029509824 24400 0xd5e720 INFO filesrc gstfilesrc.c:450:gst_file_src_start:<source> opening file /home/virtuald/Music/DJ/emusic/Artie Shaw - You're A Lucky Guy.mp3
0:00:00.029538236 24400 0xd5e720 INFO task gsttask.c:431:gst_task_set_lock: setting stream lock 0xfee110 on task 0x1024050
0:00:00.029548179 24400 0xd5e720 INFO GST_PADS gstpad.c:5515:gst_pad_start_task:<typefind:sink> created task 0x1024050
0:00:00.029591666 24400 0xd5e720 INFO GST_STATES gstelement.c:2328:gst_element_continue_state:<typefind> completed state change to PAUSED
0:00:00.029600374 24400 0xd5e720 INFO GST_STATES gstelement.c:2233:_priv_gst_element_state_changed:<typefind> notifying about state-changed READY to PAUSED (VOID_PENDING pending)
0:00:00.029612486 24400 0xd5e720 INFO GST_STATES gstbin.c:2673:gst_bin_change_state_func:<decodebin0> child 'typefind' changed state to 3(PAUSED) successfully
0:00:00.029623832 24400 0xd5e720 INFO GST_STATES gstbin.c:2679:gst_bin_change_state_func:<uridecodebin0> child 'decodebin0' is changing state asynchronously to PAUSED
0:00:00.029632282 24400 0xd5e720 INFO GST_STATES gstbin.c:2230:gst_bin_element_set_state:<source> current NULL pending VOID_PENDING, desired next PAUSED
0:00:00.029640891 24400 0xd5e720 INFO GST_STATES gstelement.c:2303:gst_element_continue_state:<source> committing state from NULL to READY, pending PAUSED, next PAUSED
0:00:00.029647969 24400 0xd5e720 INFO GST_STATES gstelement.c:2233:_priv_gst_element_state_changed:<source> notifying about state-changed NULL to READY (PAUSED pending)
0:00:00.029656567 24400 0xd5e720 INFO GST_STATES gstelement.c:2310:gst_element_continue_state:<source> continue state change READY to PAUSED, final PAUSED
0:00:00.029665087 24400 0xd5e720 INFO GST_STATES gstelement.c:2328:gst_element_continue_state:<source> completed state change to PAUSED
0:00:00.029670962 24400 0xd5e720 INFO GST_STATES gstelement.c:2233:_priv_gst_element_state_changed:<source> notifying about state-changed READY to PAUSED (VOID_PENDING pending)
0:00:00.029668242 24400 0x101d000 INFO GST_ELEMENT_PADS gstelement.c:895:gst_element_get_static_pad: found pad typefind:sink
0:00:00.029684903 24400 0xd5e720 INFO GST_STATES gstbin.c:2673:gst_bin_change_state_func:<uridecodebin0> child 'source' changed state to 3(PAUSED) successfully
0:00:00.029722167 24400 0xd5e720 INFO GST_STATES gstbin.c:2679:gst_bin_change_state_func:<playbin0> child 'uridecodebin0' is changing state asynchronously to PAUSED
0:00:00.029735581 24400 0xd5e720 INFO GST_STATES gstbin.c:2679:gst_bin_change_state_func:<pipe> child 'playbin0' is changing state asynchronously to PAUSED
0:00:00.029748335 24400 0xd5e720 INFO GST_STATES gstbin.c:2230:gst_bin_element_set_state:<autoaudiosink0> current READY pending VOID_PENDING, desired next PAUSED
0:00:00.029765032 24400 0xd5e720 INFO GST_STATES gstbin.c:2230:gst_bin_element_set_state:<autoaudiosink0-actual-sink-pulse> current READY pending VOID_PENDING, desired next PAUSED
0:00:00.029788701 24400 0xd5e720 INFO GST_STATES gstbin.c:2679:gst_bin_change_state_func:<autoaudiosink0> child 'autoaudiosink0-actual-sink-pulse' is changing state asynchronously to PAUSED
0:00:00.029801303 24400 0xd5e720 INFO GST_STATES gstbin.c:2679:gst_bin_change_state_func:<pipe> child 'autoaudiosink0' is changing state asynchronously to PAUSED
0:00:00.029815104 24400 0xd5e720 INFO GST_STATES gstbin.c:2230:gst_bin_element_set_state:<adder0> current READY pending VOID_PENDING, desired next PAUSED
0:00:00.029828914 24400 0xd5e720 INFO GST_STATES gstelement.c:2328:gst_element_continue_state:<adder0> completed state change to PAUSED
0:00:00.029835369 24400 0xd5e720 INFO GST_STATES gstelement.c:2233:_priv_gst_element_state_changed:<adder0> notifying about state-changed READY to PAUSED (VOID_PENDING pending)
0:00:00.029844483 24400 0xd5e720 INFO GST_STATES gstbin.c:2673:gst_bin_change_state_func:<pipe> child 'adder0' changed state to 3(PAUSED) successfully
0:00:00.030018609 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for video/x-ms-asf
0:00:00.030061669 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for audio/x-musepack
0:00:00.030079515 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for audio/x-au
0:00:00.030094138 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for video/x-msvideo
0:00:00.030108005 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for audio/qcelp
0:00:00.030122716 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for video/x-cdxa
0:00:00.030136106 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for video/x-vcd
0:00:00.030148907 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for audio/x-imelody
0:00:00.030176115 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for audio/midi
0:00:00.030190878 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for audio/riff-midi
0:00:00.030204414 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for audio/mobile-xmf
0:00:00.030217783 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for video/x-fli
0:00:00.030231255 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for application/x-id3v2
0:00:00.030244603 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for application/x-id3v1
0:00:00.030261702 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for application/x-apetag
0:00:00.030279522 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for audio/x-ttafile
0:00:00.030297526 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for audio/x-mod
0:00:00.030317067 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for audio/mpeg
0:00:00.030331806 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for audio/x-ac3
0:00:00.030347668 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for audio/x-dts
0:00:00.030362750 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for audio/x-gsm
0:00:00.030380252 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for video/mpeg-sys
0:00:00.030406470 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for video/mpegts
0:00:00.030423176 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for application/ogg
0:00:00.030438646 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for video/mpeg-elementary
0:00:00.030452254 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for video/mpeg4
0:00:00.030467474 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for video/x-h263
0:00:00.030489725 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for video/x-h264
0:00:00.030507431 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for video/x-h265
0:00:00.030525279 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for video/x-nuv
0:00:00.030538639 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for audio/x-m4a
0:00:00.030551853 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for application/x-3gp
0:00:00.030564512 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for video/quicktime
0:00:00.030579588 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for image/x-quicktime
0:00:00.030593428 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for image/jp2
0:00:00.030606243 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for video/mj2
0:00:00.030622412 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for text/html
0:00:00.030636032 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for application/vnd.rn-realmedia
0:00:00.030651568 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for application/x-pn-realaudio
0:00:00.030665709 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for application/x-shockwave-flash
0:00:00.030679439 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for application/vnd.ms-sstr+xml
0:00:00.030691689 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for video/x-flv
0:00:00.030708281 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for text/plain
0:00:00.030722289 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for text/utf-16
0:00:00.030735160 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for text/utf-32
0:00:00.030747793 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for text/uri-list
0:00:00.030760768 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for application/x-hls
0:00:00.030773605 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for application/sdp
0:00:00.030791986 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for application/smil
0:00:00.030805957 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for application/xml
0:00:00.030824667 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for audio/x-wav
0:00:00.030838418 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for audio/x-aiff
0:00:00.030852050 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for audio/x-svx
0:00:00.030865132 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for audio/x-paris
0:00:00.030878073 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for audio/x-nist
0:00:00.030890662 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for audio/x-voc
0:00:00.030903647 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for audio/x-sds
0:00:00.030919742 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for audio/x-ircam
0:00:00.030940046 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for audio/x-w64
0:00:00.030955501 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for audio/x-rf64
0:00:00.030968754 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for audio/x-shorten
0:00:00.030981842 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for application/x-ape
0:00:00.030998195 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for image/jpeg
0:00:00.031012249 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for image/gif
0:00:00.031028219 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for image/png
0:00:00.031041514 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for image/bmp
0:00:00.031059010 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for image/tiff
0:00:00.031073001 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for image/webp
0:00:00.031085834 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for image/x-exr
0:00:00.031101471 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for image/x-portable-pixmap
0:00:00.031115422 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for video/x-matroska
0:00:00.031132921 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for application/mxf
0:00:00.031145999 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for video/x-mve
0:00:00.031159928 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for video/x-dv
0:00:00.031178285 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for audio/x-amr-nb-sh
0:00:00.031191634 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for audio/x-amr-wb-sh
0:00:00.031204303 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for audio/iLBC-sh
0:00:00.031217449 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for audio/x-sbc
0:00:00.031233279 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for audio/x-sid
0:00:00.031246525 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for image/x-xcf
0:00:00.031259297 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for video/x-mng
0:00:00.031271824 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for image/x-jng
0:00:00.031286320 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for image/x-xpixmap
0:00:00.031299459 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for image/x-sun-raster
0:00:00.031312436 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for application/x-bzip
0:00:00.031328461 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for application/x-gzip
0:00:00.031347228 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for application/zip
0:00:00.031360786 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for application/x-compress
0:00:00.031373244 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for subtitle/x-kate
0:00:00.031385916 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for audio/x-flac
0:00:00.031398930 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for audio/x-vorbis
0:00:00.031411537 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for video/x-theora
0:00:00.031425172 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for application/x-ogm-video
0:00:00.031437979 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for application/x-ogm-audio
0:00:00.031450706 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for application/x-ogm-text
0:00:00.031463350 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for audio/x-speex
0:00:00.031475939 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for audio/x-celt
0:00:00.031490108 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for application/x-ogg-skeleton
0:00:00.031502816 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for text/x-cmml
0:00:00.031515609 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for application/x-executable
0:00:00.031539003 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for audio/aac
0:00:00.031554035 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for audio/x-spc
0:00:00.031568551 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for audio/x-wavpack
0:00:00.031586362 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for audio/x-wavpack-correction
0:00:00.031600350 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for audio/x-caf
0:00:00.031613750 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for application/postscript
0:00:00.031627968 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for image/svg+xml
0:00:00.031641287 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for application/x-rar
0:00:00.031654751 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for application/x-tar
0:00:00.031667843 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for application/x-ar
0:00:00.031680867 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for application/x-ms-dos-executable
0:00:00.031694772 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for video/x-dirac
0:00:00.031707427 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for multipart/x-mixed-replace
0:00:00.031723141 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for application/x-mmsh
0:00:00.031735970 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for video/vivo
0:00:00.031748784 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for audio/x-nsf
0:00:00.031762964 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for audio/x-gym
0:00:00.031775940 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for audio/x-ay
0:00:00.031788308 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for audio/x-gbs
0:00:00.031800646 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for audio/x-vgm
0:00:00.031816598 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for audio/x-sap
0:00:00.031829682 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for video/x-ivf
0:00:00.031842531 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for audio/x-kss
0:00:00.031859066 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for application/pdf
0:00:00.031873021 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for application/msword
0:00:00.031891040 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for application/octet-stream
0:00:00.031904354 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for image/vnd.adobe.photoshop
0:00:00.031919603 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for image/vnd.wap.wbmp
0:00:00.031936406 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for application/x-yuv4mpeg
0:00:00.031950145 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for image/x-icon
0:00:00.031961540 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for image/x-degas
0:00:00.031972748 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for application/octet-stream
0:00:00.031987139 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for application/x-ssa
0:00:00.032001175 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for video/x-pva
0:00:00.032014329 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for audio/x-xi
0:00:00.032028567 24400 0x101d000 INFO GST_TYPEFIND gsttypefind.c:71:gst_type_find_register: registering typefind function for audio/audible
0:00:00.032041812 24400 0x101d000 INFO GST_PLUGIN_LOADING gstplugin.c:833:gst_plugin_load_file: plugin "/usr/lib64/gstreamer-1.0/libgsttypefindfunctions.so" loaded
0:00:00.032081317 24400 0x101d000 INFO typefind gsttypefindelement.c:182:gst_type_find_element_have_type:<typefind> found caps application/x-id3, probability=100
0:00:00.032096193 24400 0x101d000 INFO GST_EVENT gstevent.c:678:gst_event_new_caps: creating caps event application/x-id3
0:00:00.032112364 24400 0x101d000 INFO GST_ELEMENT_PADS gstelement.c:895:gst_element_get_static_pad: found pad typefind:src
0:00:00.032120059 24400 0x101d000 INFO GST_ELEMENT_PADS gstelement.c:895:gst_element_get_static_pad: found pad typefind:sink
0:00:00.032171342 24400 0x101d000 INFO GST_PADS gstpad.c:2186:gst_pad_link_prepare: trying to link typefind:src and decodepad0:proxypad3
0:00:00.032182606 24400 0x101d000 INFO GST_PADS gstpad.c:2388:gst_pad_link_full: linked typefind:src and decodepad0:proxypad3, successful
0:00:00.032189778 24400 0x101d000 INFO GST_EVENT gstevent.c:1373:gst_event_new_reconfigure: creating reconfigure event
0:00:00.032488293 24400 0x101d000 INFO GST_ELEMENT_PADS gstelement.c:895:gst_element_get_static_pad: found pad out1:sink
0:00:00.042514305 24400 0x101d000 INFO GST_ELEMENT_PADS gstpad.c:1943:gst_pad_unlink: unlinking typefind:src(0xfee960) and decodepad0:proxypad3(0xfe6940)
0:00:00.042548090 24400 0x101d000 INFO GST_ELEMENT_PADS gstpad.c:1997:gst_pad_unlink: unlinked typefind:src and decodepad0:proxypad3
0:00:00.042562586 24400 0x101d000 INFO GST_PADS gstpad.c:2186:gst_pad_link_prepare: trying to link typefind:src and decodepad0:proxypad3
0:00:00.042570783 24400 0x101d000 INFO GST_PADS gstpad.c:2388:gst_pad_link_full: linked typefind:src and decodepad0:proxypad3, successful
0:00:00.042577576 24400 0x101d000 INFO GST_EVENT gstevent.c:1373:gst_event_new_reconfigure: creating reconfigure event
0:00:00.042599377 24400 0x101d000 INFO GST_ELEMENT_PADS gstpad.c:1943:gst_pad_unlink: unlinking typefind:src(0xfee960) and decodepad0:proxypad3(0xfe6940)
0:00:00.042620419 24400 0x101d000 INFO GST_ELEMENT_PADS gstpad.c:1997:gst_pad_unlink: unlinked typefind:src and decodepad0:proxypad3
0:00:00.042863429 24400 0x101d000 INFO GST_PLUGIN_LOADING gstplugin.c:833:gst_plugin_load_file: plugin "/usr/lib64/gstreamer-1.0/libgstid3demux.so" loaded
0:00:00.042874855 24400 0x101d000 INFO GST_ELEMENT_FACTORY gstelementfactory.c:364:gst_element_factory_create: creating element "id3demux"
0:00:00.042946022 24400 0x101d000 INFO GST_ELEMENT_PADS gstelement.c:643:gst_element_add_pad:<GstTagDemux@0xfe6c50> adding pad 'sink'
0:00:00.042964718 24400 0x101d000 INFO GST_ELEMENT_PADS gstelement.c:643:gst_element_add_pad:<GstTagDemux@0xfe6c50> adding pad 'src'
0:00:00.043000880 24400 0x101d000 INFO GST_PADS gstpad.c:2186:gst_pad_link_prepare: trying to link typefind:src and id3demux0:sink
0:00:00.043016473 24400 0x101d000 INFO GST_PADS gstpad.c:2388:gst_pad_link_full: linked typefind:src and id3demux0:sink, successful
0:00:00.043024030 24400 0x101d000 INFO GST_EVENT gstevent.c:1373:gst_event_new_reconfigure: creating reconfigure event
0:00:00.043036087 24400 0x101d000 INFO GST_STATES gstelement.c:2328:gst_element_continue_state:<id3demux0> completed state change to READY
0:00:00.043043101 24400 0x101d000 INFO GST_STATES gstelement.c:2233:_priv_gst_element_state_changed:<id3demux0> notifying about state-changed NULL to READY (VOID_PENDING pending)
0:00:00.043062993 24400 0x101d000 INFO GST_ELEMENT_PADS gstelement.c:895:gst_element_get_static_pad: found pad id3demux0:src
0:00:00.043107965 24400 0x101d000 INFO task gsttask.c:431:gst_task_set_lock: setting stream lock 0xfef290 on task 0x10245f0
0:00:00.043118046 24400 0x101d000 INFO GST_PADS gstpad.c:5515:gst_pad_start_task:<id3demux0:sink> created task 0x10245f0
0:00:00.043160370 24400 0x101d000 INFO GST_STATES gstelement.c:2328:gst_element_continue_state:<id3demux0> completed state change to PAUSED
0:00:00.043168796 24400 0x101d000 INFO GST_STATES gstelement.c:2233:_priv_gst_element_state_changed:<id3demux0> notifying about state-changed READY to PAUSED (VOID_PENDING pending)
0:00:00.043184741 24400 0x101d000 INFO task gsttask.c:300:gst_task_func:<typefind:sink> Task going to paused
0:00:00.043277825 24400 0x7f661c0f0770 INFO id3demux gstid3demux.c:154:gst_id3demux_identify_tag:<id3demux0> Found ID3v2 marker, tag_size = 62930
0:00:00.043617427 24400 0x7f661c0f0770 FIXME id3v2 gstid3tag.c:142:gst_tag_from_id3_tag: Cannot map ID3v2 tag 'USER' to GStreamer tag
0:00:00.043639341 24400 0x7f661c0f0770 FIXME id3v2 gstid3tag.c:142:gst_tag_from_id3_tag: Cannot map ID3v2 tag 'TFLT' to GStreamer tag
0:00:00.043661987 24400 0x7f661c0f0770 FIXME id3v2 gstid3tag.c:142:gst_tag_from_id3_tag: Cannot map ID3v2 tag 'TIT1' to GStreamer tag
0:00:00.043687769 24400 0x7f661c0f0770 INFO id3demux gstid3demux.c:154:gst_id3demux_identify_tag:<id3demux0> Found ID3v1 marker, tag_size = 128
0:00:00.043881818 24400 0x7f661c0f0770 INFO typefindfunctions gsttypefindfunctions.c:1435:mp3_type_find_at_offset: audio/mpeg calculated 100 = 100 * 5 / 5 * (10000 - 0) / 10000
0:00:00.043913061 24400 0x7f661c0f0770 INFO tagdemux gsttagdemux.c:1371:gst_tag_demux_element_find:<id3demux0> Found type audio/mpeg, mpegversion=(int)1, layer=(int)3, parsed=(boolean)false with a probability of 100
0:00:00.043937668 24400 0x7f661c0f0770 INFO GST_ELEMENT_PADS gstelement.c:895:gst_element_get_static_pad: found pad id3demux0:sink
0:00:00.043968123 24400 0x7f661c0f0770 INFO GST_EVENT gstevent.c:678:gst_event_new_caps: creating caps event audio/mpeg, mpegversion=(int)1, layer=(int)3, parsed=(boolean)false
0:00:00.043992977 24400 0x7f661c0f0770 INFO GST_PADS gstpad.c:2186:gst_pad_link_prepare: trying to link id3demux0:src and decodepad0:proxypad3
0:00:00.044008131 24400 0x7f661c0f0770 INFO GST_PADS gstpad.c:2388:gst_pad_link_full: linked id3demux0:src and decodepad0:proxypad3, successful
0:00:00.044015189 24400 0x7f661c0f0770 INFO GST_EVENT gstevent.c:1373:gst_event_new_reconfigure: creating reconfigure event
0:00:00.044036336 24400 0x7f661c0f0770 INFO GST_ELEMENT_PADS gstelement.c:895:gst_element_get_static_pad: found pad out1:sink
0:00:00.045223702 24400 0x7f661c0f0770 INFO GST_ELEMENT_PADS gstpad.c:1943:gst_pad_unlink: unlinking id3demux0:src(0xfef450) and decodepad0:proxypad3(0xfe6940)
0:00:00.045247684 24400 0x7f661c0f0770 INFO GST_ELEMENT_PADS gstpad.c:1997:gst_pad_unlink: unlinked id3demux0:src and decodepad0:proxypad3
0:00:00.045260440 24400 0x7f661c0f0770 INFO GST_PADS gstpad.c:2186:gst_pad_link_prepare: trying to link id3demux0:src and decodepad0:proxypad3
0:00:00.045267704 24400 0x7f661c0f0770 INFO GST_PADS gstpad.c:2388:gst_pad_link_full: linked id3demux0:src and decodepad0:proxypad3, successful
0:00:00.045273820 24400 0x7f661c0f0770 INFO GST_EVENT gstevent.c:1373:gst_event_new_reconfigure: creating reconfigure event
0:00:00.045295223 24400 0x7f661c0f0770 INFO GST_ELEMENT_PADS gstpad.c:1943:gst_pad_unlink: unlinking id3demux0:src(0xfef450) and decodepad0:proxypad3(0xfe6940)
0:00:00.045306734 24400 0x7f661c0f0770 INFO GST_ELEMENT_PADS gstpad.c:1997:gst_pad_unlink: unlinked id3demux0:src and decodepad0:proxypad3
0:00:00.045538350 24400 0x7f661c0f0770 INFO GST_PLUGIN_LOADING gstplugin.c:833:gst_plugin_load_file: plugin "/usr/lib64/gstreamer-1.0/libgstaudioparsers.so" loaded
0:00:00.045548364 24400 0x7f661c0f0770 INFO GST_ELEMENT_FACTORY gstelementfactory.c:364:gst_element_factory_create: creating element "mpegaudioparse"
0:00:00.045612227 24400 0x7f661c0f0770 INFO GST_ELEMENT_PADS gstelement.c:643:gst_element_add_pad:<GstBaseParse@0x7f6614026a30> adding pad 'sink'
0:00:00.045627664 24400 0x7f661c0f0770 INFO GST_ELEMENT_PADS gstelement.c:643:gst_element_add_pad:<GstBaseParse@0x7f6614026a30> adding pad 'src'
0:00:00.045650861 24400 0x7f661c0f0770 INFO GST_PADS gstpad.c:2186:gst_pad_link_prepare: trying to link id3demux0:src and mpegaudioparse0:sink
0:00:00.045664863 24400 0x7f661c0f0770 INFO GST_PADS gstpad.c:3745:gst_pad_peer_query:<mpegaudioparse0:src> pad has no peer
0:00:00.045673263 24400 0x7f661c0f0770 INFO GST_PADS gstpad.c:2388:gst_pad_link_full: linked id3demux0:src and mpegaudioparse0:sink, successful
0:00:00.045679918 24400 0x7f661c0f0770 INFO GST_EVENT gstevent.c:1373:gst_event_new_reconfigure: creating reconfigure event
0:00:00.045694536 24400 0x7f661c0f0770 INFO GST_STATES gstelement.c:2328:gst_element_continue_state:<mpegaudioparse0> completed state change to READY
0:00:00.045701152 24400 0x7f661c0f0770 INFO GST_STATES gstelement.c:2233:_priv_gst_element_state_changed:<mpegaudioparse0> notifying about state-changed NULL to READY (VOID_PENDING pending)
0:00:00.045716811 24400 0x7f661c0f0770 INFO GST_PADS gstpad.c:3745:gst_pad_peer_query:<mpegaudioparse0:src> pad has no peer
0:00:00.045730173 24400 0x7f661c0f0770 INFO GST_ELEMENT_PADS gstelement.c:895:gst_element_get_static_pad: found pad mpegaudioparse0:src
0:00:00.045742125 24400 0x7f661c0f0770 INFO GST_PADS gstpad.c:2186:gst_pad_link_prepare: trying to link mpegaudioparse0:src and decodepad0:proxypad3
0:00:00.045749704 24400 0x7f661c0f0770 INFO GST_PADS gstpad.c:2388:gst_pad_link_full: linked mpegaudioparse0:src and decodepad0:proxypad3, successful
0:00:00.045755949 24400 0x7f661c0f0770 INFO GST_EVENT gstevent.c:1373:gst_event_new_reconfigure: creating reconfigure event
0:00:00.045760951 24400 0x7f661c0f0770 INFO GST_EVENT gstpad.c:5182:gst_pad_send_event_unchecked:<mpegaudioparse0:src> Received event on flushing pad. Discarding
0:00:00.045829057 24400 0x7f661c0f0770 INFO GST_EVENT gstevent.c:759:gst_event_new_segment: creating segment event time segment start=0:00:00.000000000, offset=0:00:00.000000000, stop=99:99:99.999999999, rate=1.000000, applied_rate=1.000000, flags=0x00, time=0:00:00.000000000, base=0:00:00.000000000, position 0:00:00.000000000, duration 99:99:99.999999999
0:00:00.045860050 24400 0x7f661c0f0770 INFO task gsttask.c:431:gst_task_set_lock: setting stream lock 0xfefb50 on task 0x1024ef0
0:00:00.045868448 24400 0x7f661c0f0770 INFO GST_PADS gstpad.c:5515:gst_pad_start_task:<mpegaudioparse0:sink> created task 0x1024ef0
0:00:00.045902796 24400 0x7f661c0f0770 INFO GST_STATES gstelement.c:2328:gst_element_continue_state:<mpegaudioparse0> completed state change to PAUSED
0:00:00.045910902 24400 0x7f661c0f0770 INFO GST_STATES gstelement.c:2233:_priv_gst_element_state_changed:<mpegaudioparse0> notifying about state-changed READY to PAUSED (VOID_PENDING pending)
0:00:00.045928371 24400 0x7f661c0f0770 INFO task gsttask.c:300:gst_task_func:<id3demux0:sink> Task going to paused
0:00:00.045946740 24400 0xe1a8f0 INFO GST_ELEMENT_PADS gstelement.c:895:gst_element_get_static_pad: found pad mpegaudioparse0:sink
0:00:00.046058359 24400 0xe1a8f0 INFO GST_EVENT gstevent.c:678:gst_event_new_caps: creating caps event audio/mpeg, mpegversion=(int)1, mpegaudioversion=(int)1, layer=(int)3, rate=(int)44100, channels=(int)2, parsed=(boolean)true
0:00:00.046086373 24400 0xe1a8f0 INFO GST_ELEMENT_PADS gstpad.c:1943:gst_pad_unlink: unlinking mpegaudioparse0:src(0xfefd10) and decodepad0:proxypad3(0xfe6940)
0:00:00.046100903 24400 0xe1a8f0 INFO GST_ELEMENT_PADS gstpad.c:1997:gst_pad_unlink: unlinked mpegaudioparse0:src and decodepad0:proxypad3
0:00:00.046113551 24400 0xe1a8f0 INFO GST_PADS gstpad.c:2186:gst_pad_link_prepare: trying to link mpegaudioparse0:src and decodepad0:proxypad3
0:00:00.046121175 24400 0xe1a8f0 INFO GST_PADS gstpad.c:2388:gst_pad_link_full: linked mpegaudioparse0:src and decodepad0:proxypad3, successful
0:00:00.046127682 24400 0xe1a8f0 INFO GST_EVENT gstevent.c:1373:gst_event_new_reconfigure: creating reconfigure event
0:00:00.046148885 24400 0xe1a8f0 INFO GST_ELEMENT_PADS gstelement.c:895:gst_element_get_static_pad: found pad out1:sink
0:00:00.047252072 24400 0xe1a8f0 INFO GST_ELEMENT_PADS gstpad.c:1943:gst_pad_unlink: unlinking mpegaudioparse0:src(0xfefd10) and decodepad0:proxypad3(0xfe6940)
0:00:00.047270800 24400 0xe1a8f0 INFO GST_ELEMENT_PADS gstpad.c:1997:gst_pad_unlink: unlinked mpegaudioparse0:src and decodepad0:proxypad3
0:00:00.047283017 24400 0xe1a8f0 INFO GST_PADS gstpad.c:2186:gst_pad_link_prepare: trying to link mpegaudioparse0:src and decodepad0:proxypad3
0:00:00.047290399 24400 0xe1a8f0 INFO GST_PADS gstpad.c:2388:gst_pad_link_full: linked mpegaudioparse0:src and decodepad0:proxypad3, successful
0:00:00.047296789 24400 0xe1a8f0 INFO GST_EVENT gstevent.c:1373:gst_event_new_reconfigure: creating reconfigure event
0:00:00.047313176 24400 0xe1a8f0 INFO GST_ELEMENT_PADS gstpad.c:1943:gst_pad_unlink: unlinking mpegaudioparse0:src(0xfefd10) and decodepad0:proxypad3(0xfe6940)
0:00:00.047324425 24400 0xe1a8f0 INFO GST_ELEMENT_PADS gstpad.c:1997:gst_pad_unlink: unlinked mpegaudioparse0:src and decodepad0:proxypad3
0:00:00.047335450 24400 0xe1a8f0 INFO GST_PADS gstpad.c:2186:gst_pad_link_prepare: trying to link mpegaudioparse0:src and decodepad0:proxypad3
0:00:00.047342385 24400 0xe1a8f0 INFO GST_PADS gstpad.c:2388:gst_pad_link_full: linked mpegaudioparse0:src and decodepad0:proxypad3, successful
0:00:00.047348550 24400 0xe1a8f0 INFO GST_EVENT gstevent.c:1373:gst_event_new_reconfigure: creating reconfigure event
0:00:00.047370483 24400 0xe1a8f0 INFO GST_ELEMENT_PADS gstelement.c:895:gst_element_get_static_pad: found pad out1:sink
0:00:00.047751903 24400 0xe1a8f0 INFO GST_ELEMENT_PADS gstpad.c:1943:gst_pad_unlink: unlinking mpegaudioparse0:src(0xfefd10) and decodepad0:proxypad3(0xfe6940)
0:00:00.047769159 24400 0xe1a8f0 INFO GST_ELEMENT_PADS gstpad.c:1997:gst_pad_unlink: unlinked mpegaudioparse0:src and decodepad0:proxypad3
0:00:00.048054910 24400 0xe1a8f0 INFO GST_PLUGIN_LOADING gstplugin.c:833:gst_plugin_load_file: plugin "/usr/lib64/gstreamer-1.0/libgstmad.so" loaded
0:00:00.048067129 24400 0xe1a8f0 INFO GST_ELEMENT_FACTORY gstelementfactory.c:364:gst_element_factory_create: creating element "mad"
0:00:00.048161036 24400 0xe1a8f0 INFO GST_ELEMENT_PADS gstelement.c:643:gst_element_add_pad:<GstAudioDecoder@0x7f660c016aa0> adding pad 'sink'
0:00:00.048177490 24400 0xe1a8f0 INFO GST_ELEMENT_PADS gstelement.c:643:gst_element_add_pad:<GstAudioDecoder@0x7f660c016aa0> adding pad 'src'
0:00:00.048207540 24400 0xe1a8f0 INFO GST_PADS gstpad.c:2186:gst_pad_link_prepare: trying to link mpegaudioparse0:src and mad0:sink
0:00:00.048224637 24400 0xe1a8f0 INFO GST_PADS gstpad.c:2388:gst_pad_link_full: linked mpegaudioparse0:src and mad0:sink, successful
0:00:00.048231900 24400 0xe1a8f0 INFO GST_EVENT gstevent.c:1373:gst_event_new_reconfigure: creating reconfigure event
0:00:00.048248579 24400 0xe1a8f0 INFO GST_STATES gstelement.c:2328:gst_element_continue_state:<mad0> completed state change to READY
0:00:00.048255516 24400 0xe1a8f0 INFO GST_STATES gstelement.c:2233:_priv_gst_element_state_changed:<mad0> notifying about state-changed NULL to READY (VOID_PENDING pending)
0:00:00.048277674 24400 0xe1a8f0 INFO GST_ELEMENT_PADS gstelement.c:895:gst_element_get_static_pad: found pad mad0:src
0:00:00.048290688 24400 0xe1a8f0 INFO GST_PADS gstpad.c:2186:gst_pad_link_prepare: trying to link mad0:src and decodepad0:proxypad3
0:00:00.048298529 24400 0xe1a8f0 INFO GST_PADS gstpad.c:2388:gst_pad_link_full: linked mad0:src and decodepad0:proxypad3, successful
0:00:00.048305162 24400 0xe1a8f0 INFO GST_EVENT gstevent.c:1373:gst_event_new_reconfigure: creating reconfigure event
0:00:00.048310552 24400 0xe1a8f0 INFO GST_EVENT gstpad.c:5182:gst_pad_send_event_unchecked:<mad0:src> Received event on flushing pad. Discarding
0:00:00.048332879 24400 0xe1a8f0 INFO GST_STATES gstelement.c:2328:gst_element_continue_state:<mad0> completed state change to PAUSED
0:00:00.048340549 24400 0xe1a8f0 INFO GST_STATES gstelement.c:2233:_priv_gst_element_state_changed:<mad0> notifying about state-changed READY to PAUSED (VOID_PENDING pending)
0:00:00.048601324 24400 0xe1a8f0 INFO GST_EVENT gstevent.c:678:gst_event_new_caps: creating caps event audio/x-raw, format=(string)S32LE, layout=(string)interleaved, rate=(int)44100, channels=(int)2, channel-mask=(bitmask)0x0000000000000003
0:00:00.048629297 24400 0xe1a8f0 INFO GST_ELEMENT_PADS gstelement.c:643:gst_element_add_pad:<decodebin0> adding pad 'src_0'
0:00:00.048667111 24400 0xe1a8f0 INFO GST_PADS gstpad.c:2186:gst_pad_link_prepare: trying to link decodebin0:src_0 and src_0:proxypad4
0:00:00.048676529 24400 0xe1a8f0 INFO GST_PADS gstpad.c:2388:gst_pad_link_full: linked decodebin0:src_0 and src_0:proxypad4, successful
0:00:00.048683345 24400 0xe1a8f0 INFO GST_EVENT gstevent.c:1373:gst_event_new_reconfigure: creating reconfigure event
0:00:00.048705587 24400 0xe1a8f0 INFO GST_ELEMENT_PADS gstelement.c:643:gst_element_add_pad:<uridecodebin0> adding pad 'src_0'
0:00:00.048718711 24400 0xe1a8f0 INFO GST_ELEMENT_FACTORY gstelementfactory.c:364:gst_element_factory_create: creating element "input-selector"
0:00:00.048774784 24400 0xe1a8f0 INFO GST_ELEMENT_PADS gstelement.c:643:gst_element_add_pad:<GstInputSelector@0x7f660c034000> adding pad 'src'
0:00:00.048803759 24400 0xe1a8f0 INFO GST_STATES gstelement.c:2303:gst_element_continue_state:<inputselector0> committing state from NULL to READY, pending PAUSED, next PAUSED
0:00:00.048813084 24400 0xe1a8f0 INFO GST_STATES gstelement.c:2233:_priv_gst_element_state_changed:<inputselector0> notifying about state-changed NULL to READY (PAUSED pending)
0:00:00.048822740 24400 0xe1a8f0 INFO GST_STATES gstelement.c:2310:gst_element_continue_state:<inputselector0> continue state change READY to PAUSED, final PAUSED
0:00:00.048832411 24400 0xe1a8f0 INFO GST_STATES gstelement.c:2328:gst_element_continue_state:<inputselector0> completed state change to PAUSED
0:00:00.048838694 24400 0xe1a8f0 INFO GST_STATES gstelement.c:2233:_priv_gst_element_state_changed:<inputselector0> notifying about state-changed READY to PAUSED (VOID_PENDING pending)
0:00:00.048853060 24400 0xe1a8f0 INFO GST_ELEMENT_PADS gstelement.c:895:gst_element_get_static_pad: found pad inputselector0:src
0:00:00.048891225 24400 0xe1a8f0 INFO GST_ELEMENT_PADS gstelement.c:643:gst_element_add_pad:<inputselector0> adding pad 'sink_0'
0:00:00.048909787 24400 0xe1a8f0 INFO GST_PADS gstpad.c:2186:gst_pad_link_prepare: trying to link uridecodebin0:src_0 and inputselector0:sink_0
0:00:00.048928631 24400 0xe1a8f0 INFO GST_PADS gstpad.c:3745:gst_pad_peer_query:<inputselector0:src> pad has no peer
0:00:00.048944355 24400 0xe1a8f0 INFO GST_PADS gstpad.c:2388:gst_pad_link_full: linked uridecodebin0:src_0 and inputselector0:sink_0, successful
0:00:00.048952016 24400 0xe1a8f0 INFO GST_EVENT gstevent.c:1373:gst_event_new_reconfigure: creating reconfigure event
0:00:00.048982424 24400 0xe1a8f0 INFO decodebin gstdecodebin2.c:4049:gst_decode_bin_expose:<decodebin0:src_0> added new decoded pad
0:00:00.048994220 24400 0xe1a8f0 INFO GST_ELEMENT_FACTORY gstelementfactory.c:362:gst_element_factory_create: creating element "tee" named "audiotee"
0:00:00.049043762 24400 0xe1a8f0 INFO GST_ELEMENT_PADS gstelement.c:643:gst_element_add_pad:<GstTee@0x7f660c034150> adding pad 'sink'
0:00:00.049061246 24400 0xe1a8f0 INFO GST_ELEMENT_PADS gstelement.c:895:gst_element_get_static_pad: found pad audiotee:sink
0:00:00.049075562 24400 0xe1a8f0 INFO GST_STATES gstelement.c:2303:gst_element_continue_state:<audiotee> committing state from NULL to READY, pending PAUSED, next PAUSED
0:00:00.049083553 24400 0xe1a8f0 INFO GST_STATES gstelement.c:2233:_priv_gst_element_state_changed:<audiotee> notifying about state-changed NULL to READY (PAUSED pending)
0:00:00.049093938 24400 0xe1a8f0 INFO GST_STATES gstelement.c:2310:gst_element_continue_state:<audiotee> continue state change READY to PAUSED, final PAUSED
0:00:00.049102995 24400 0xe1a8f0 INFO GST_STATES gstelement.c:2328:gst_element_continue_state:<audiotee> completed state change to PAUSED
0:00:00.049108803 24400 0xe1a8f0 INFO GST_STATES gstelement.c:2233:_priv_gst_element_state_changed:<audiotee> notifying about state-changed READY to PAUSED (VOID_PENDING pending)
0:00:00.049132446 24400 0xe1a8f0 INFO GST_PADS gstpad.c:2186:gst_pad_link_prepare: trying to link audio_sink:proxypad5 and audiotee:sink
0:00:00.049141395 24400 0xe1a8f0 INFO GST_PADS gstpad.c:2388:gst_pad_link_full: linked audio_sink:proxypad5 and audiotee:sink, successful
0:00:00.049148259 24400 0xe1a8f0 INFO GST_EVENT gstevent.c:1373:gst_event_new_reconfigure: creating reconfigure event
0:00:00.049159667 24400 0xe1a8f0 INFO GST_ELEMENT_PADS gstelement.c:643:gst_element_add_pad:<playsink> adding pad 'audio_sink'
0:00:00.049171788 24400 0xe1a8f0 INFO GST_PADS gstpad.c:2186:gst_pad_link_prepare: trying to link inputselector0:src and playsink:audio_sink
0:00:00.049194402 24400 0xe1a8f0 INFO GST_PADS gstpad.c:2388:gst_pad_link_full: linked inputselector0:src and playsink:audio_sink, successful
0:00:00.049202242 24400 0xe1a8f0 INFO GST_EVENT gstevent.c:1373:gst_event_new_reconfigure: creating reconfigure event
0:00:00.049221469 24400 0xe1a8f0 INFO playbin gstplaybin2.c:3536:no_more_pads_cb:<playbin0> setting custom audio sink <out1>
0:00:00.049239095 24400 0xe1a8f0 INFO GST_STATES gstbin.c:3129:bin_handle_async_done:<decodebin0> committing state from READY to PAUSED, old pending PAUSED
0:00:00.049247159 24400 0xe1a8f0 INFO GST_STATES gstbin.c:3149:bin_handle_async_done:<decodebin0> completed state change, pending VOID
0:00:00.049252325 24400 0xe1a8f0 INFO GST_STATES gstelement.c:2233:_priv_gst_element_state_changed:<decodebin0> notifying about state-changed READY to PAUSED (VOID_PENDING pending)
0:00:00.049263060 24400 0xe1a8f0 INFO GST_STATES gstbin.c:3129:bin_handle_async_done:<uridecodebin0> committing state from READY to PAUSED, old pending PAUSED
0:00:00.049269830 24400 0xe1a8f0 INFO GST_STATES gstbin.c:3149:bin_handle_async_done:<uridecodebin0> completed state change, pending VOID
0:00:00.049274670 24400 0xe1a8f0 INFO GST_STATES gstelement.c:2233:_priv_gst_element_state_changed:<uridecodebin0> notifying about state-changed READY to PAUSED (VOID_PENDING pending)
0:00:00.049333223 24400 0xe1a8f0 INFO GST_STATES gstelement.c:2328:gst_element_continue_state:<out1> completed state change to READY
0:00:00.049344221 24400 0xe1a8f0 INFO GST_ELEMENT_FACTORY gstelementfactory.c:362:gst_element_factory_create: creating element "bin" named "abin"
0:00:00.049368601 24400 0xe1a8f0 INFO GST_ELEMENT_FACTORY gstelementfactory.c:362:gst_element_factory_create: creating element "queue" named "aqueue"
0:00:00.049449841 24400 0xe1a8f0 INFO GST_ELEMENT_PADS gstelement.c:643:gst_element_add_pad:<GstQueue@0x7f660c03c010> adding pad 'sink'
0:00:00.049469160 24400 0xe1a8f0 INFO GST_ELEMENT_PADS gstelement.c:643:gst_element_add_pad:<GstQueue@0x7f660c03c010> adding pad 'src'
0:00:00.049549133 24400 0xe1a8f0 INFO GST_ELEMENT_PADS gstelement.c:643:gst_element_add_pad:<GstPlaySinkConvertBin@0xfc69c0> adding pad 'sink'
0:00:00.049575546 24400 0xe1a8f0 INFO GST_ELEMENT_PADS gstelement.c:643:gst_element_add_pad:<GstPlaySinkConvertBin@0xfc69c0> adding pad 'src'
0:00:00.049584061 24400 0xe1a8f0 INFO GST_ELEMENT_FACTORY gstelementfactory.c:362:gst_element_factory_create: creating element "identity" named "identity"
0:00:00.049663923 24400 0xe1a8f0 INFO GST_ELEMENT_PADS gstelement.c:643:gst_element_add_pad:<GstBaseTransform@0xfdef00> adding pad 'sink'
0:00:00.049679855 24400 0xe1a8f0 INFO GST_ELEMENT_PADS gstelement.c:643:gst_element_add_pad:<GstBaseTransform@0xfdef00> adding pad 'src'
0:00:00.049847425 24400 0xe1a8f0 INFO GST_PLUGIN_LOADING gstplugin.c:833:gst_plugin_load_file: plugin "/usr/lib64/gstreamer-1.0/libgstvolume.so" loaded
0:00:00.049862259 24400 0xe1a8f0 INFO GST_ELEMENT_FACTORY gstelementfactory.c:362:gst_element_factory_create: creating element "volume" named "volume"
0:00:00.049922513 24400 0xe1a8f0 INFO GST_ELEMENT_PADS gstelement.c:643:gst_element_add_pad:<GstBaseTransform@0x7f660c0458d0> adding pad 'sink'
0:00:00.049944923 24400 0xe1a8f0 INFO GST_ELEMENT_PADS gstelement.c:643:gst_element_add_pad:<GstBaseTransform@0x7f660c0458d0> adding pad 'src'
0:00:00.049957634 24400 0xe1a8f0 INFO playsinkconvertbin gstplaysinkconvertbin.c:558:gst_play_sink_convert_bin_cache_converter_caps:<GstPlaySinkAudioConvert@0xfc69c0> No conversion elements
0:00:00.050113350 24400 0xe1a8f0 INFO GST_PLUGIN_LOADING gstplugin.c:833:gst_plugin_load_file: plugin "/usr/lib64/gstreamer-1.0/libgstaudioconvert.so" loaded
0:00:00.050128422 24400 0xe1a8f0 INFO GST_ELEMENT_FACTORY gstelementfactory.c:362:gst_element_factory_create: creating element "audioconvert" named "conv"
0:00:00.050206316 24400 0xe1a8f0 INFO GST_ELEMENT_PADS gstelement.c:643:gst_element_add_pad:<GstBaseTransform@0x7f660c0480d0> adding pad 'sink'
0:00:00.050221684 24400 0xe1a8f0 INFO GST_ELEMENT_PADS gstelement.c:643:gst_element_add_pad:<GstBaseTransform@0x7f660c0480d0> adding pad 'src'
0:00:00.051763972 24400 0xe1a8f0 INFO audioresample gstaudioresample.c:1515:_benchmark_integer_resampling: Using float resampler for everything: 33452.000000 <= 106540.571429
0:00:00.051791965 24400 0xe1a8f0 INFO GST_PLUGIN_LOADING gstplugin.c:833:gst_plugin_load_file: plugin "/usr/lib64/gstreamer-1.0/libgstaudioresample.so" loaded
0:00:00.051800075 24400 0xe1a8f0 INFO GST_ELEMENT_FACTORY gstelementfactory.c:362:gst_element_factory_create: creating element "audioresample" named "resample"
0:00:00.051877843 24400 0xe1a8f0 INFO GST_ELEMENT_PADS gstelement.c:643:gst_element_add_pad:<GstBaseTransform@0x7f660c054ce0> adding pad 'sink'
0:00:00.051894007 24400 0xe1a8f0 INFO GST_ELEMENT_PADS gstelement.c:643:gst_element_add_pad:<GstBaseTransform@0x7f660c054ce0> adding pad 'src'
0:00:00.051912056 24400 0xe1a8f0 INFO GST_ELEMENT_PADS gstutils.c:1545:gst_element_link_pads_full: trying to link element conv:src to element resample:sink
0:00:00.051921457 24400 0xe1a8f0 INFO GST_ELEMENT_PADS gstelement.c:895:gst_element_get_static_pad: found pad conv:src
0:00:00.051928144 24400 0xe1a8f0 INFO GST_ELEMENT_PADS gstelement.c:895:gst_element_get_static_pad: found pad resample:sink
0:00:00.051941140 24400 0xe1a8f0 INFO GST_PADS gstutils.c:1445:prepare_link_maybe_ghosting: conv and resample in same bin, no need for ghost pads
0:00:00.051952213 24400 0xe1a8f0 INFO GST_PADS gstpad.c:2186:gst_pad_link_prepare: trying to link conv:src and resample:sink
0:00:00.051963043 24400 0xe1a8f0 INFO GST_PADS gstpad.c:2388:gst_pad_link_full: linked conv:src and resample:sink, successful
0:00:00.051969688 24400 0xe1a8f0 INFO GST_EVENT gstevent.c:1373:gst_event_new_reconfigure: creating reconfigure event
0:00:00.051975475 24400 0xe1a8f0 INFO GST_EVENT gstpad.c:5182:gst_pad_send_event_unchecked:<conv:src> Received event on flushing pad. Discarding
0:00:00.051985007 24400 0xe1a8f0 INFO GST_ELEMENT_PADS gstelement.c:895:gst_element_get_static_pad: found pad conv:sink
0:00:00.051995866 24400 0xe1a8f0 INFO GST_PADS gstpad.c:3745:gst_pad_peer_query:<resample:src> pad has no peer
0:00:00.052040532 24400 0xe1a8f0 INFO structure gststructure.c:2919:gst_structure_get_valist: Expected field 'channel-mask' in structure: audio/x-raw, rate=(int)[ 1, 2147483647 ], channels=(int)[ 1, 2147483647 ], layout=(string)interleaved;
0:00:00.052081333 24400 0xe1a8f0 INFO playsinkconvertbin gstplaysinkconvertbin.c:571:gst_play_sink_convert_bin_cache_converter_caps:<aconv> Converter caps: audio/x-raw, format=(string){ F32LE, F64LE, S32LE, S24LE, S16LE, S8 }, rate=(int)[ 1, 2147483647 ], channels=(int)[ 1, 2147483647 ], layout=(string)interleaved; audio/x-raw, rate=(int)[ 1, 2147483647 ], layout=(string)interleaved, format=(string){ S8, U8, S16LE, S16BE, U16LE, U16BE, S24_32LE, S24_32BE, U24_32LE, U24_32BE, S32LE, S32BE, U32LE, U32BE, S24LE, S24BE, U24LE, U24BE, S20LE, S20BE, U20LE, U20BE, S18LE, S18BE, U18LE, U18BE, F32LE, F32BE, F64LE, F64BE }, channels=(int)[ 1, 2147483647 ]
0:00:00.052105692 24400 0xe1a8f0 INFO GST_STATES gstelement.c:2328:gst_element_continue_state:<conv> completed state change to NULL
0:00:00.052115958 24400 0xe1a8f0 INFO GST_ELEMENT_PADS gstpad.c:1943:gst_pad_unlink: unlinking conv:src(0x7f6614009d60) and resample:sink(0x7f660c056030)
0:00:00.052133304 24400 0xe1a8f0 INFO GST_ELEMENT_PADS gstpad.c:1997:gst_pad_unlink: unlinked conv:src and resample:sink
0:00:00.052143492 24400 0xe1a8f0 INFO GST_PARENTAGE gstbin.c:1554:gst_bin_remove_func:<aconv> removed child "conv"
0:00:00.052153309 24400 0xe1a8f0 INFO GST_REFCOUNTING gstelement.c:2873:gst_element_dispose:<conv> dispose
0:00:00.052159009 24400 0xe1a8f0 INFO GST_ELEMENT_PADS gstelement.c:763:gst_element_remove_pad:<conv> removing pad 'sink'
0:00:00.052167926 24400 0xe1a8f0 INFO GST_ELEMENT_PADS gstelement.c:763:gst_element_remove_pad:<conv> removing pad 'src'
0:00:00.052175608 24400 0xe1a8f0 INFO GST_REFCOUNTING gstelement.c:2917:gst_element_dispose:<conv> parent class dispose
0:00:00.052181319 24400 0xe1a8f0 INFO GST_REFCOUNTING gstelement.c:2948:gst_element_finalize:<conv> finalize
0:00:00.052186145 24400 0xe1a8f0 INFO GST_REFCOUNTING gstelement.c:2953:gst_element_finalize:<conv> finalize parent
0:00:00.052192705 24400 0xe1a8f0 INFO GST_STATES gstelement.c:2328:gst_element_continue_state:<resample> completed state change to NULL
0:00:00.052201392 24400 0xe1a8f0 INFO GST_PARENTAGE gstbin.c:1554:gst_bin_remove_func:<aconv> removed child "resample"
0:00:00.052209203 24400 0xe1a8f0 INFO GST_REFCOUNTING gstelement.c:2873:gst_element_dispose:<resample> dispose
0:00:00.052214340 24400 0xe1a8f0 INFO GST_ELEMENT_PADS gstelement.c:763:gst_element_remove_pad:<resample> removing pad 'sink'
0:00:00.052221628 24400 0xe1a8f0 INFO GST_ELEMENT_PADS gstelement.c:763:gst_element_remove_pad:<resample> removing pad 'src'
0:00:00.052228745 24400 0xe1a8f0 INFO GST_REFCOUNTING gstelement.c:2917:gst_element_dispose:<resample> parent class dispose
0:00:00.052234266 24400 0xe1a8f0 INFO GST_REFCOUNTING gstelement.c:2948:gst_element_finalize:<resample> finalize
0:00:00.052238874 24400 0xe1a8f0 INFO GST_REFCOUNTING gstelement.c:2953:gst_element_finalize:<resample> finalize parent
0:00:00.052247669 24400 0xe1a8f0 INFO GST_ELEMENT_FACTORY gstelementfactory.c:362:gst_element_factory_create: creating element "audioconvert" named "conv"
0:00:00.052266449 24400 0xe1a8f0 INFO GST_ELEMENT_PADS gstelement.c:643:gst_element_add_pad:<GstBaseTransform@0x7f660c0480d0> adding pad 'sink'
0:00:00.052279948 24400 0xe1a8f0 INFO GST_ELEMENT_PADS gstelement.c:643:gst_element_add_pad:<GstBaseTransform@0x7f660c0480d0> adding pad 'src'
0:00:00.052293468 24400 0xe1a8f0 INFO GST_ELEMENT_FACTORY gstelementfactory.c:362:gst_element_factory_create: creating element "audioresample" named "resample"
0:00:00.052309192 24400 0xe1a8f0 INFO GST_ELEMENT_PADS gstelement.c:643:gst_element_add_pad:<GstBaseTransform@0x7f660c055920> adding pad 'sink'
0:00:00.052322024 24400 0xe1a8f0 INFO GST_ELEMENT_PADS gstelement.c:643:gst_element_add_pad:<GstBaseTransform@0x7f660c055920> adding pad 'src'
0:00:00.052334893 24400 0xe1a8f0 INFO GST_ELEMENT_PADS gstutils.c:1545:gst_element_link_pads_full: trying to link element conv:src to element resample:sink
0:00:00.052343259 24400 0xe1a8f0 INFO GST_ELEMENT_PADS gstelement.c:895:gst_element_get_static_pad: found pad conv:src
0:00:00.052349268 24400 0xe1a8f0 INFO GST_ELEMENT_PADS gstelement.c:895:gst_element_get_static_pad: found pad resample:sink
0:00:00.052354890 24400 0xe1a8f0 INFO GST_PADS gstutils.c:1445:prepare_link_maybe_ghosting: conv and resample in same bin, no need for ghost pads
0:00:00.052364191 24400 0xe1a8f0 INFO GST_PADS gstpad.c:2186:gst_pad_link_prepare: trying to link conv:src and resample:sink
0:00:00.052373713 24400 0xe1a8f0 INFO GST_PADS gstpad.c:2388:gst_pad_link_full: linked conv:src and resample:sink, successful
0:00:00.052380258 24400 0xe1a8f0 INFO GST_EVENT gstevent.c:1373:gst_event_new_reconfigure: creating reconfigure event
0:00:00.052390443 24400 0xe1a8f0 INFO GST_EVENT gstpad.c:5182:gst_pad_send_event_unchecked:<conv:src> Received event on flushing pad. Discarding
0:00:00.052403361 24400 0xe1a8f0 INFO GST_ELEMENT_PADS gstutils.c:1545:gst_element_link_pads_full: trying to link element resample:src to element volume:sink
0:00:00.052411468 24400 0xe1a8f0 INFO GST_ELEMENT_PADS gstelement.c:895:gst_element_get_static_pad: found pad resample:src
0:00:00.052417532 24400 0xe1a8f0 INFO GST_ELEMENT_PADS gstelement.c:895:gst_element_get_static_pad: found pad volume:sink
0:00:00.052423128 24400 0xe1a8f0 INFO GST_PADS gstutils.c:1445:prepare_link_maybe_ghosting: resample and volume in same bin, no need for ghost pads
0:00:00.052431465 24400 0xe1a8f0 INFO GST_PADS gstpad.c:2186:gst_pad_link_prepare: trying to link resample:src and volume:sink
0:00:00.052440483 24400 0xe1a8f0 INFO GST_PADS gstpad.c:2388:gst_pad_link_full: linked resample:src and volume:sink, successful
0:00:00.052447030 24400 0xe1a8f0 INFO GST_EVENT gstevent.c:1373:gst_event_new_reconfigure: creating reconfigure event
0:00:00.052452241 24400 0xe1a8f0 INFO GST_EVENT gstpad.c:5182:gst_pad_send_event_unchecked:<resample:src> Received event on flushing pad. Discarding
0:00:00.052460769 24400 0xe1a8f0 INFO GST_ELEMENT_PADS gstelement.c:895:gst_element_get_static_pad: found pad conv:sink
0:00:00.052471544 24400 0xe1a8f0 INFO GST_PADS gstpad.c:3745:gst_pad_peer_query:<volume:src> pad has no peer
0:00:00.052519935 24400 0xe1a8f0 INFO structure gststructure.c:2919:gst_structure_get_valist: Expected field 'channel-mask' in structure: audio/x-raw, rate=(int)[ 1, 2147483647 ], channels=(int)[ 1, 2147483647 ], layout=(string)interleaved;
0:00:00.052557154 24400 0xe1a8f0 INFO playsinkconvertbin gstplaysinkconvertbin.c:571:gst_play_sink_convert_bin_cache_converter_caps:<aconv> Converter caps: audio/x-raw, format=(string){ F32LE, F64LE, S8, S16LE, S24LE, S32LE }, rate=(int)[ 1, 2147483647 ], channels=(int)[ 1, 2147483647 ], layout=(string)interleaved; audio/x-raw, rate=(int)[ 1, 2147483647 ], layout=(string)interleaved, format=(string){ S8, U8, S16LE, S16BE, U16LE, U16BE, S24_32LE, S24_32BE, U24_32LE, U24_32BE, S32LE, S32BE, U32LE, U32BE, S24LE, S24BE, U24LE, U24BE, S20LE, S20BE, U20LE, U20BE, S18LE, S18BE, U18LE, U18BE, F32LE, F32BE, F64LE, F64BE }, channels=(int)[ 1, 2147483647 ]
0:00:00.052585624 24400 0xe1a8f0 INFO GST_ELEMENT_PADS gstutils.c:1545:gst_element_link_pads_full: trying to link element aqueue:src to element aconv:sink
0:00:00.052594322 24400 0xe1a8f0 INFO GST_ELEMENT_PADS gstelement.c:895:gst_element_get_static_pad: found pad aqueue:src
0:00:00.052600196 24400 0xe1a8f0 INFO GST_ELEMENT_PADS gstelement.c:895:gst_element_get_static_pad: found pad aconv:sink
0:00:00.052605744 24400 0xe1a8f0 INFO GST_PADS gstutils.c:1445:prepare_link_maybe_ghosting: aqueue and aconv in same bin, no need for ghost pads
0:00:00.052614260 24400 0xe1a8f0 INFO GST_PADS gstpad.c:2186:gst_pad_link_prepare: trying to link aqueue:src and aconv:sink
0:00:00.052621517 24400 0xe1a8f0 INFO GST_PADS gstpad.c:2388:gst_pad_link_full: linked aqueue:src and aconv:sink, successful
0:00:00.052627771 24400 0xe1a8f0 INFO GST_EVENT gstevent.c:1373:gst_event_new_reconfigure: creating reconfigure event
0:00:00.052633316 24400 0xe1a8f0 INFO GST_EVENT gstpad.c:5182:gst_pad_send_event_unchecked:<aqueue:src> Received event on flushing pad. Discarding
0:00:00.052661663 24400 0xe1a8f0 INFO GST_ELEMENT_PADS gstutils.c:1545:gst_element_link_pads_full: trying to link element aconv:src to element out1:(any)
0:00:00.052670451 24400 0xe1a8f0 INFO GST_ELEMENT_PADS gstelement.c:895:gst_element_get_static_pad: found pad aconv:src
0:00:00.052682181 24400 0xe1a8f0 INFO GST_PADS gstutils.c:937:gst_pad_check_link: trying to link aconv:src and out1:sink
0:00:00.052694613 24400 0xe1a8f0 INFO GST_PADS gstpad.c:3745:gst_pad_peer_query:<aqueue:sink> pad has no peer
0:00:00.053118041 24400 0xe1a8f0 INFO GST_PADS gstutils.c:1445:prepare_link_maybe_ghosting: aconv and out1 in same bin, no need for ghost pads
0:00:00.053141852 24400 0xe1a8f0 INFO GST_PADS gstpad.c:2186:gst_pad_link_prepare: trying to link aconv:src and out1:sink
0:00:00.053151469 24400 0xe1a8f0 INFO GST_PADS gstpad.c:2388:gst_pad_link_full: linked aconv:src and out1:sink, successful
0:00:00.053158264 24400 0xe1a8f0 INFO GST_EVENT gstevent.c:1373:gst_event_new_reconfigure: creating reconfigure event
0:00:00.053164744 24400 0xe1a8f0 INFO GST_EVENT gstpad.c:5182:gst_pad_send_event_unchecked:<aconv:src> Received event on flushing pad. Discarding
0:00:00.053174396 24400 0xe1a8f0 INFO GST_ELEMENT_PADS gstelement.c:895:gst_element_get_static_pad: found pad aqueue:sink
0:00:00.053216184 24400 0xe1a8f0 INFO GST_PADS gstpad.c:2186:gst_pad_link_prepare: trying to link sink:proxypad8 and aqueue:sink
0:00:00.053225723 24400 0xe1a8f0 INFO GST_PADS gstpad.c:2388:gst_pad_link_full: linked sink:proxypad8 and aqueue:sink, successful
0:00:00.053232696 24400 0xe1a8f0 INFO GST_EVENT gstevent.c:1373:gst_event_new_reconfigure: creating reconfigure event
0:00:00.053242031 24400 0xe1a8f0 INFO GST_ELEMENT_PADS gstelement.c:643:gst_element_add_pad:<abin> adding pad 'sink'
0:00:00.053278110 24400 0xe1a8f0 INFO GST_ELEMENT_PADS gstelement.c:643:gst_element_add_pad:<streamsynchronizer0> adding pad 'src_0'
0:00:00.053286426 24400 0xe1a8f0 INFO GST_ELEMENT_PADS gstelement.c:643:gst_element_add_pad:<streamsynchronizer0> adding pad 'sink_0'
0:00:00.053311031 24400 0xe1a8f0 INFO GST_ELEMENT_PADS gstelement.c:643:gst_element_add_pad:<audiotee> adding pad 'src_0'
0:00:00.053338543 24400 0xe1a8f0 INFO GST_STATES gstbin.c:2230:gst_bin_element_set_state:<out1> current READY pending VOID_PENDING, desired next READY
0:00:00.053351602 24400 0xe1a8f0 INFO GST_STATES gstelement.c:2328:gst_element_continue_state:<out1> completed state change to READY
0:00:00.053358840 24400 0xe1a8f0 INFO GST_STATES gstbin.c:2673:gst_bin_change_state_func:<abin> child 'out1' changed state to 2(READY) successfully
0:00:00.053367924 24400 0xe1a8f0 INFO GST_STATES gstbin.c:2230:gst_bin_element_set_state:<aconv> current NULL pending VOID_PENDING, desired next READY
0:00:00.053380985 24400 0xe1a8f0 INFO GST_STATES gstbin.c:2230:gst_bin_element_set_state:<volume> current NULL pending VOID_PENDING, desired next READY
0:00:00.053389650 24400 0xe1a8f0 INFO GST_STATES gstelement.c:2328:gst_element_continue_state:<volume> completed state change to READY
0:00:00.053395763 24400 0xe1a8f0 INFO GST_STATES gstelement.c:2233:_priv_gst_element_state_changed:<volume> notifying about state-changed NULL to READY (VOID_PENDING pending)
0:00:00.053408053 24400 0xe1a8f0 INFO GST_STATES gstbin.c:2673:gst_bin_change_state_func:<aconv> child 'volume' changed state to 2(READY) successfully
0:00:00.053417194 24400 0xe1a8f0 INFO GST_STATES gstbin.c:2230:gst_bin_element_set_state:<resample> current NULL pending VOID_PENDING, desired next READY
0:00:00.053425234 24400 0xe1a8f0 INFO GST_STATES gstelement.c:2328:gst_element_continue_state:<resample> completed state change to READY
0:00:00.053431112 24400 0xe1a8f0 INFO GST_STATES gstelement.c:2233:_priv_gst_element_state_changed:<resample> notifying about state-changed NULL to READY (VOID_PENDING pending)
0:00:00.053441084 24400 0xe1a8f0 INFO GST_STATES gstbin.c:2673:gst_bin_change_state_func:<aconv> child 'resample' changed state to 2(READY) successfully
0:00:00.053455994 24400 0xe1a8f0 INFO GST_STATES gstbin.c:2230:gst_bin_element_set_state:<conv> current NULL pending VOID_PENDING, desired next READY
0:00:00.053464427 24400 0xe1a8f0 INFO GST_STATES gstelement.c:2328:gst_element_continue_state:<conv> completed state change to READY
0:00:00.053470376 24400 0xe1a8f0 INFO GST_STATES gstelement.c:2233:_priv_gst_element_state_changed:<conv> notifying about state-changed NULL to READY (VOID_PENDING pending)
0:00:00.053480157 24400 0xe1a8f0 INFO GST_STATES gstbin.c:2673:gst_bin_change_state_func:<aconv> child 'conv' changed state to 2(READY) successfully
0:00:00.053488632 24400 0xe1a8f0 INFO GST_STATES gstbin.c:2230:gst_bin_element_set_state:<identity> current NULL pending VOID_PENDING, desired next READY
0:00:00.053496528 24400 0xe1a8f0 INFO GST_STATES gstelement.c:2328:gst_element_continue_state:<identity> completed state change to READY
0:00:00.053502168 24400 0xe1a8f0 INFO GST_STATES gstelement.c:2233:_priv_gst_element_state_changed:<identity> notifying about state-changed NULL to READY (VOID_PENDING pending)
0:00:00.053511653 24400 0xe1a8f0 INFO GST_STATES gstbin.c:2673:gst_bin_change_state_func:<aconv> child 'identity' changed state to 2(READY) successfully
0:00:00.053523173 24400 0xe1a8f0 INFO GST_STATES gstelement.c:2328:gst_element_continue_state:<aconv> completed state change to READY
0:00:00.053529014 24400 0xe1a8f0 INFO GST_STATES gstelement.c:2233:_priv_gst_element_state_changed:<aconv> notifying about state-changed NULL to READY (VOID_PENDING pending)
0:00:00.053539088 24400 0xe1a8f0 INFO GST_STATES gstbin.c:2673:gst_bin_change_state_func:<abin> child 'aconv' changed state to 2(READY) successfully
0:00:00.053547659 24400 0xe1a8f0 INFO GST_STATES gstbin.c:2230:gst_bin_element_set_state:<aqueue> current NULL pending VOID_PENDING, desired next READY
0:00:00.053555100 24400 0xe1a8f0 INFO GST_STATES gstelement.c:2328:gst_element_continue_state:<aqueue> completed state change to READY
0:00:00.053560688 24400 0xe1a8f0 INFO GST_STATES gstelement.c:2233:_priv_gst_element_state_changed:<aqueue> notifying about state-changed NULL to READY (VOID_PENDING pending)
0:00:00.053569608 24400 0xe1a8f0 INFO GST_STATES gstbin.c:2673:gst_bin_change_state_func:<abin> child 'aqueue' changed state to 2(READY) successfully
0:00:00.053577542 24400 0xe1a8f0 INFO GST_STATES gstelement.c:2303:gst_element_continue_state:<abin> committing state from NULL to READY, pending PAUSED, next PAUSED
0:00:00.053584658 24400 0xe1a8f0 INFO GST_STATES gstelement.c:2233:_priv_gst_element_state_changed:<abin> notifying about state-changed NULL to READY (PAUSED pending)
0:00:00.053593227 24400 0xe1a8f0 INFO GST_STATES gstelement.c:2310:gst_element_continue_state:<abin> continue state change READY to PAUSED, final PAUSED
0:00:00.053604359 24400 0xe1a8f0 INFO GST_STATES gstbin.c:2230:gst_bin_element_set_state:<out1> current READY pending VOID_PENDING, desired next PAUSED
0:00:00.053616992 24400 0xe1a8f0 INFO GST_STATES gstelement.c:2328:gst_element_continue_state:<out1> completed state change to PAUSED
0:00:00.053623551 24400 0xe1a8f0 INFO GST_STATES gstelement.c:2233:_priv_gst_element_state_changed:<out1> notifying about state-changed READY to PAUSED (VOID_PENDING pending)
0:00:00.053633452 24400 0xe1a8f0 INFO GST_STATES gstbin.c:2673:gst_bin_change_state_func:<abin> child 'out1' changed state to 3(PAUSED) successfully
0:00:00.053642068 24400 0xe1a8f0 INFO GST_STATES gstbin.c:2230:gst_bin_element_set_state:<aconv> current READY pending VOID_PENDING, desired next PAUSED
0:00:00.053654173 24400 0xe1a8f0 INFO GST_ELEMENT_PADS gstelement.c:895:gst_element_get_static_pad: found pad identity:sink
0:00:00.053661076 24400 0xe1a8f0 INFO GST_PADS gstpad.c:2186:gst_pad_link_prepare: trying to link sink:proxypad6 and identity:sink
0:00:00.053668347 24400 0xe1a8f0 INFO GST_PADS gstpad.c:2388:gst_pad_link_full: linked sink:proxypad6 and identity:sink, successful
0:00:00.053674684 24400 0xe1a8f0 INFO GST_EVENT gstevent.c:1373:gst_event_new_reconfigure: creating reconfigure event
0:00:00.053682469 24400 0xe1a8f0 INFO GST_ELEMENT_PADS gstelement.c:895:gst_element_get_static_pad: found pad identity:src
0:00:00.053691609 24400 0xe1a8f0 INFO GST_PADS gstpad.c:2186:gst_pad_link_prepare: trying to link identity:src and src:proxypad7
0:00:00.053698754 24400 0xe1a8f0 INFO GST_PADS gstpad.c:2388:gst_pad_link_full: linked identity:src and src:proxypad7, successful
0:00:00.053705007 24400 0xe1a8f0 INFO GST_EVENT gstevent.c:1373:gst_event_new_reconfigure: creating reconfigure event
0:00:00.053710164 24400 0xe1a8f0 INFO GST_EVENT gstpad.c:5182:gst_pad_send_event_unchecked:<identity:src> Received event on flushing pad. Discarding
0:00:00.053724380 24400 0xe1a8f0 INFO GST_STATES gstbin.c:2230:gst_bin_element_set_state:<volume> current READY pending VOID_PENDING, desired next PAUSED
0:00:00.053735995 24400 0xe1a8f0 INFO GST_STATES gstelement.c:2328:gst_element_continue_state:<volume> completed state change to PAUSED
0:00:00.053742501 24400 0xe1a8f0 INFO GST_STATES gstelement.c:2233:_priv_gst_element_state_changed:<volume> notifying about state-changed READY to PAUSED (VOID_PENDING pending)
0:00:00.053752801 24400 0xe1a8f0 INFO GST_STATES gstbin.c:2673:gst_bin_change_state_func:<aconv> child 'volume' changed state to 3(PAUSED) successfully
0:00:00.053761524 24400 0xe1a8f0 INFO GST_STATES gstbin.c:2230:gst_bin_element_set_state:<resample> current READY pending VOID_PENDING, desired next PAUSED
0:00:00.053771398 24400 0xe1a8f0 INFO GST_STATES gstelement.c:2328:gst_element_continue_state:<resample> completed state change to PAUSED
0:00:00.053777403 24400 0xe1a8f0 INFO GST_STATES gstelement.c:2233:_priv_gst_element_state_changed:<resample> notifying about state-changed READY to PAUSED (VOID_PENDING pending)
0:00:00.053786811 24400 0xe1a8f0 INFO GST_STATES gstbin.c:2673:gst_bin_change_state_func:<aconv> child 'resample' changed state to 3(PAUSED) successfully
0:00:00.053794952 24400 0xe1a8f0 INFO GST_STATES gstbin.c:2230:gst_bin_element_set_state:<conv> current READY pending VOID_PENDING, desired next PAUSED
0:00:00.053804254 24400 0xe1a8f0 INFO GST_STATES gstelement.c:2328:gst_element_continue_state:<conv> completed state change to PAUSED
0:00:00.053810228 24400 0xe1a8f0 INFO GST_STATES gstelement.c:2233:_priv_gst_element_state_changed:<conv> notifying about state-changed READY to PAUSED (VOID_PENDING pending)
0:00:00.053819341 24400 0xe1a8f0 INFO GST_STATES gstbin.c:2673:gst_bin_change_state_func:<aconv> child 'conv' changed state to 3(PAUSED) successfully
0:00:00.053827716 24400 0xe1a8f0 INFO GST_STATES gstbin.c:2230:gst_bin_element_set_state:<identity> current READY pending VOID_PENDING, desired next PAUSED
0:00:00.053837249 24400 0xe1a8f0 INFO GST_STATES gstelement.c:2328:gst_element_continue_state:<identity> completed state change to PAUSED
0:00:00.053843158 24400 0xe1a8f0 INFO GST_STATES gstelement.c:2233:_priv_gst_element_state_changed:<identity> notifying about state-changed READY to PAUSED (VOID_PENDING pending)
0:00:00.053852429 24400 0xe1a8f0 INFO GST_STATES gstbin.c:2673:gst_bin_change_state_func:<aconv> child 'identity' changed state to 3(PAUSED) successfully
0:00:00.053868727 24400 0xe1a8f0 INFO GST_STATES gstelement.c:2328:gst_element_continue_state:<aconv> completed state change to PAUSED
0:00:00.053875603 24400 0xe1a8f0 INFO GST_STATES gstelement.c:2233:_priv_gst_element_state_changed:<aconv> notifying about state-changed READY to PAUSED (VOID_PENDING pending)
0:00:00.053885326 24400 0xe1a8f0 INFO GST_STATES gstbin.c:2673:gst_bin_change_state_func:<abin> child 'aconv' changed state to 3(PAUSED) successfully
0:00:00.053893735 24400 0xe1a8f0 INFO GST_STATES gstbin.c:2230:gst_bin_element_set_state:<aqueue> current READY pending VOID_PENDING, desired next PAUSED
0:00:00.053910877 24400 0xe1a8f0 INFO task gsttask.c:431:gst_task_set_lock: setting stream lock 0x7f66140090b0 on task 0x7f6614004170
0:00:00.053919081 24400 0xe1a8f0 INFO GST_PADS gstpad.c:5515:gst_pad_start_task:<aqueue:src> created task 0x7f6614004170
0:00:00.053966237 24400 0xe1a8f0 INFO GST_STATES gstelement.c:2328:gst_element_continue_state:<aqueue> completed state change to PAUSED
0:00:00.053983257 24400 0xe1a8f0 INFO GST_STATES gstelement.c:2233:_priv_gst_element_state_changed:<aqueue> notifying about state-changed READY to PAUSED (VOID_PENDING pending)
0:00:00.053993928 24400 0xe1a8f0 INFO GST_STATES gstbin.c:2673:gst_bin_change_state_func:<abin> child 'aqueue' changed state to 3(PAUSED) successfully
0:00:00.054003866 24400 0xe1a8f0 INFO GST_STATES gstelement.c:2328:gst_element_continue_state:<abin> completed state change to PAUSED
0:00:00.054017390 24400 0xe1a8f0 INFO GST_STATES gstelement.c:2233:_priv_gst_element_state_changed:<abin> notifying about state-changed READY to PAUSED (VOID_PENDING pending)
0:00:00.054039714 24400 0xe1a8f0 INFO GST_PADS gstpad.c:2186:gst_pad_link_prepare: trying to link audiotee:src_0 and streamsynchronizer0:sink_0
0:00:00.054048544 24400 0xe1a8f0 INFO GST_PADS gstpad.c:2388:gst_pad_link_full: linked audiotee:src_0 and streamsynchronizer0:sink_0, successful
0:00:00.054055211 24400 0xe1a8f0 INFO GST_EVENT gstevent.c:1373:gst_event_new_reconfigure: creating reconfigure event
0:00:00.054088633 24400 0xe1a8f0 INFO GST_PADS gstpad.c:2186:gst_pad_link_prepare: trying to link streamsynchronizer0:src_0 and abin:sink
0:00:00.054098281 24400 0xe1a8f0 INFO GST_PADS gstpad.c:2388:gst_pad_link_full: linked streamsynchronizer0:src_0 and abin:sink, successful
0:00:00.054104925 24400 0xe1a8f0 INFO GST_EVENT gstevent.c:1373:gst_event_new_reconfigure: creating reconfigure event
0:00:00.054125236 24400 0xe1a8f0 INFO playsink gstplaysink.c:1412:do_async_done:<playsink> Sending async_done message
0:00:00.054133659 24400 0xe1a8f0 INFO GST_STATES gstbin.c:3129:bin_handle_async_done:<playsink> committing state from READY to PAUSED, old pending PAUSED
0:00:00.054141113 24400 0xe1a8f0 INFO GST_STATES gstbin.c:3149:bin_handle_async_done:<playsink> completed state change, pending VOID
0:00:00.054146236 24400 0xe1a8f0 INFO GST_STATES gstelement.c:2233:_priv_gst_element_state_changed:<playsink> notifying about state-changed READY to PAUSED (VOID_PENDING pending)
0:00:00.054156410 24400 0xe1a8f0 INFO GST_STATES gstbin.c:3129:bin_handle_async_done:<playbin0> committing state from READY to PAUSED, old pending PAUSED
0:00:00.054163038 24400 0xe1a8f0 INFO GST_STATES gstbin.c:3149:bin_handle_async_done:<playbin0> completed state change, pending VOID
0:00:00.054167691 24400 0xe1a8f0 INFO GST_STATES gstelement.c:2233:_priv_gst_element_state_changed:<playbin0> notifying about state-changed READY to PAUSED (VOID_PENDING pending)
0:00:00.056878941 24400 0xe1a8f0 INFO GST_EVENT gstevent.c:759:gst_event_new_segment: creating segment event time segment start=0:00:00.000000000, offset=0:00:00.000000000, stop=99:99:99.999999999, rate=1.000000, applied_rate=1.000000, flags=0x00, time=0:00:00.000000000, base=0:00:00.000000000, position 0:00:00.000000000, duration 99:99:99.999999999
0:00:00.057207379 24400 0xfa8990 INFO GST_ELEMENT_PADS gstpad.c:1943:gst_pad_unlink: unlinking sink:proxypad6(0xfe76c0) and identity:sink(0x7f6614009270)
0:00:00.057229423 24400 0xfa8990 INFO GST_ELEMENT_PADS gstpad.c:1997:gst_pad_unlink: unlinked sink:proxypad6 and identity:sink
0:00:00.057237770 24400 0xfa8990 INFO GST_ELEMENT_PADS gstpad.c:1943:gst_pad_unlink: unlinking identity:src(0x7f66140094a0) and src:proxypad7(0xfe7900)
0:00:00.057250180 24400 0xfa8990 INFO GST_ELEMENT_PADS gstpad.c:1997:gst_pad_unlink: unlinked identity:src and src:proxypad7
0:00:00.057271704 24400 0xfa8990 INFO GST_STATES gstelement.c:2328:gst_element_continue_state:<conv> completed state change to PAUSED
0:00:00.057280549 24400 0xfa8990 INFO GST_STATES gstelement.c:2328:gst_element_continue_state:<resample> completed state change to PAUSED
0:00:00.057287699 24400 0xfa8990 INFO GST_STATES gstelement.c:2328:gst_element_continue_state:<volume> completed state change to PAUSED
0:00:00.057294010 24400 0xfa8990 INFO GST_ELEMENT_PADS gstelement.c:895:gst_element_get_static_pad: found pad conv:sink
0:00:00.057300551 24400 0xfa8990 INFO GST_PADS gstpad.c:2186:gst_pad_link_prepare: trying to link sink:proxypad6 and conv:sink
0:00:00.057307623 24400 0xfa8990 INFO GST_PADS gstpad.c:2388:gst_pad_link_full: linked sink:proxypad6 and conv:sink, successful
0:00:00.057313657 24400 0xfa8990 INFO GST_EVENT gstevent.c:1373:gst_event_new_reconfigure: creating reconfigure event
0:00:00.057350010 24400 0xfa8990 INFO GST_ELEMENT_PADS gstelement.c:895:gst_element_get_static_pad: found pad volume:src
0:00:00.057361810 24400 0xfa8990 INFO GST_PADS gstpad.c:2186:gst_pad_link_prepare: trying to link volume:src and src:proxypad7
0:00:00.057369520 24400 0xfa8990 INFO GST_PADS gstpad.c:2388:gst_pad_link_full: linked volume:src and src:proxypad7, successful
0:00:00.057375827 24400 0xfa8990 INFO GST_EVENT gstevent.c:1373:gst_event_new_reconfigure: creating reconfigure event
0:00:00.057892220 24400 0xfa8990 INFO structure gststructure.c:2919:gst_structure_get_valist: Expected field 'channel-mask' in structure: audio/x-raw, layout=(string)interleaved, rate=(int)44100, channels=(int)[ 1, 32 ];
0:00:00.058787508 24400 0xfa8990 INFO basetransform gstbasetransform.c:1359:gst_base_transform_setcaps:<conv> reuse caps
0:00:00.058808490 24400 0xfa8990 INFO audioconvert audioconvert.c:620:audio_convert_prepare_context: depth in 32, out 32
0:00:00.058816991 24400 0xfa8990 INFO audioconvert audioconvert.c:634:audio_convert_prepare_context: using no dither and noise shaping
0:00:00.058829639 24400 0xfa8990 INFO audioconvert audioconvert.c:650:audio_convert_prepare_context: func index in 13, out 13
0:00:00.058835818 24400 0xfa8990 INFO audioconvert audioconvert.c:655:audio_convert_prepare_context: use int mixing
0:00:00.058840247 24400 0xfa8990 INFO audioconvert audioconvert.c:661:audio_convert_prepare_context: unitsizes: 8 -> 8
0:00:00.058845852 24400 0xfa8990 INFO audioconvert audioconvert.c:671:audio_convert_prepare_context: in default 1, mix passthrough 1, out default 1
0:00:00.058851672 24400 0xfa8990 INFO audioconvert audioconvert.c:678:audio_convert_prepare_context: scale in 0, out 0
0:00:00.058857958 24400 0xfa8990 INFO GST_EVENT gstevent.c:678:gst_event_new_caps: creating caps event audio/x-raw, format=(string)S32LE, layout=(string)interleaved, rate=(int)44100, channels=(int)2, channel-mask=(bitmask)0x0000000000000003
0:00:00.059733357 24400 0xfa8990 INFO basetransform gstbasetransform.c:1359:gst_base_transform_setcaps:<resample> reuse caps
0:00:00.059749111 24400 0xfa8990 INFO GST_EVENT gstevent.c:678:gst_event_new_caps: creating caps event audio/x-raw, format=(string)S32LE, layout=(string)interleaved, rate=(int)44100, channels=(int)2, channel-mask=(bitmask)0x0000000000000003
0:00:00.060244308 24400 0xfa8990 INFO basetransform gstbasetransform.c:1359:gst_base_transform_setcaps:<volume> reuse caps
0:00:00.060259991 24400 0xfa8990 INFO GST_EVENT gstevent.c:678:gst_event_new_caps: creating caps event audio/x-raw, format=(string)S32LE, layout=(string)interleaved, rate=(int)44100, channels=(int)2, channel-mask=(bitmask)0x0000000000000003
0:00:00.060879367 24400 0xfa8990 INFO structure gststructure.c:2919:gst_structure_get_valist: Expected field 'channel-mask' in structure: audio/x-raw, format=(string)S32LE, layout=(string)interleaved, rate=(int)44100, channels=(int)2;
0:00:00.060897319 24400 0xfa8990 INFO adder gstadder.c:378:gst_adder_setcaps:<adder0:sink_0> setting caps to audio/x-raw, format=(string)S32LE, layout=(string)interleaved, rate=(int)44100, channels=(int)2
0:00:00.060907879 24400 0xfa8990 INFO adder gstadder.c:385:gst_adder_setcaps:<adder0:sink_0> handle caps change to audio/x-raw, format=(string)S32LE, layout=(string)interleaved, rate=(int)44100, channels=(int)2
0:00:00.060961763 24400 0xfa8990 INFO adder gstadder.c:1198:gst_adder_collected:<adder0:src> send pending stream start event
0:00:00.061023505 24400 0xfa8990 INFO GST_EVENT gstevent.c:678:gst_event_new_caps: creating caps event audio/x-raw, format=(string)S32LE, layout=(string)interleaved, rate=(int)44100, channels=(int)2
0:00:00.061037786 24400 0xfa8990 INFO adder gstadder.c:1217:gst_adder_collected:<adder0:src> send pending caps event caps event: 0x7f6610003040, time 99:99:99.999999999, seq-num 209, GstEventCaps, caps=(GstCaps)"audio/x-raw\,\ format\=\(string\)S32LE\,\ layout\=\(string\)interleaved\,\ rate\=\(int\)44100\,\ channels\=\(int\)2";
0:00:00.061082148 24400 0xfa8990 INFO structure gststructure.c:2919:gst_structure_get_valist: Expected field 'channel-mask' in structure: audio/x-raw, format=(string)S32LE, layout=(string)interleaved, rate=(int)44100, channels=(int)2;
0:00:00.061276381 24400 0xfa8990 INFO structure gststructure.c:2919:gst_structure_get_valist: Expected field 'channel-mask' in structure: audio/x-raw, format=(string)S32LE, layout=(string)interleaved, rate=(int)44100, channels=(int)2;
0:00:00.061450971 24400 0xfa8990 INFO structure gststructure.c:2919:gst_structure_get_valist: Expected field 'channel-mask' in structure: audio/x-raw, format=(string)S32LE, layout=(string)interleaved, rate=(int)44100, channels=(int)2;
0:00:00.063147701 24400 0xfa8990 INFO pulse pulsesink.c:968:gst_pulseringbuffer_acquire:<autoaudiosink0-actual-sink-pulse> tlength: 70560
0:00:00.063169177 24400 0xfa8990 INFO pulse pulsesink.c:969:gst_pulseringbuffer_acquire:<autoaudiosink0-actual-sink-pulse> maxlength: -1
0:00:00.063175396 24400 0xfa8990 INFO pulse pulsesink.c:970:gst_pulseringbuffer_acquire:<autoaudiosink0-actual-sink-pulse> prebuf: 0
0:00:00.063180684 24400 0xfa8990 INFO pulse pulsesink.c:971:gst_pulseringbuffer_acquire:<autoaudiosink0-actual-sink-pulse> minreq: 3528
0:00:00.063668517 24400 0xfa8990 INFO pulse pulsesink.c:1021:gst_pulseringbuffer_acquire:<autoaudiosink0-actual-sink-pulse> negotiated to: pcm, format.sample_format = "\"s32le\"" format.channels = "2" format.rate = "44100" format.channel_map = "\"front-left,front-right\""
0:00:00.063685277 24400 0xfa8990 INFO pulse pulsesink.c:1034:gst_pulseringbuffer_acquire:<autoaudiosink0-actual-sink-pulse> tlength: 38808 (wanted: 70560)
0:00:00.063707543 24400 0xfa8990 INFO pulse pulsesink.c:1035:gst_pulseringbuffer_acquire:<autoaudiosink0-actual-sink-pulse> maxlength: 4194304
0:00:00.063713836 24400 0xfa8990 INFO pulse pulsesink.c:1036:gst_pulseringbuffer_acquire:<autoaudiosink0-actual-sink-pulse> prebuf: 0
0:00:00.063719371 24400 0xfa8990 INFO pulse pulsesink.c:1038:gst_pulseringbuffer_acquire:<autoaudiosink0-actual-sink-pulse> minreq: 3528 (wanted 3528)
0:00:00.063729910 24400 0xfa8990 INFO ringbuffer gstaudioringbuffer.c:573:gst_audio_ring_buffer_acquire:<pulseringbuffer0> Allocating an array for 11 timestamps
0:00:00.063973691 24400 0xfa8990 INFO GST_EVENT gstevent.c:759:gst_event_new_segment: creating segment event time segment start=0:00:00.000000000, offset=0:00:00.000000000, stop=99:99:99.999999999, rate=1.000000, applied_rate=1.000000, flags=0x00, time=0:00:00.000000000, base=0:00:00.000000000, position 0:00:00.000000000, duration 99:99:99.999999999
0:00:00.063995665 24400 0xfa8990 INFO adder gstadder.c:1247:gst_adder_collected:<adder0:src> sending pending new segment event time segment start=0:00:00.000000000, offset=0:00:00.000000000, stop=99:99:99.999999999, rate=1.000000, applied_rate=1.000000, flags=0x00, time=0:00:00.000000000, base=0:00:00.000000000, position 0:00:00.000000000, duration 99:99:99.999999999
0:00:00.064304853 24400 0xfa8990 INFO GST_STATES gstbin.c:3129:bin_handle_async_done:<autoaudiosink0> committing state from READY to PAUSED, old pending PAUSED
0:00:00.064321674 24400 0xfa8990 INFO GST_STATES gstbin.c:3149:bin_handle_async_done:<autoaudiosink0> completed state change, pending VOID
0:00:00.064327676 24400 0xfa8990 INFO GST_STATES gstelement.c:2233:_priv_gst_element_state_changed:<autoaudiosink0> notifying about state-changed READY to PAUSED (VOID_PENDING pending)
0:00:00.064339691 24400 0xfa8990 INFO GST_STATES gstbin.c:3129:bin_handle_async_done:<pipe> committing state from READY to PAUSED, old pending PLAYING
0:00:00.064373281 24400 0xfa8990 INFO GST_STATES gstbin.c:3158:bin_handle_async_done:<pipe> continue state change, pending PLAYING
0:00:00.064379965 24400 0xfa8990 INFO GST_STATES gstelement.c:2233:_priv_gst_element_state_changed:<pipe> notifying about state-changed READY to PAUSED (PLAYING pending)
0:00:00.064446170 24400 0xfab850 INFO GST_STATES gstbin.c:2952:gst_bin_continue_func:<pipe> continue state change PAUSED to PLAYING, final PLAYING
0:00:00.064609346 24400 0xfab850 INFO GST_EVENT gstevent.c:1244:gst_event_new_latency: creating latency event 0:00:00.000000000
0:00:00.064663462 24400 0xfab850 INFO bin gstbin.c:2502:gst_bin_do_latency_func:<pipe> configured latency of 0:00:00.000000000
0:00:00.064679408 24400 0xfab850 INFO GST_STATES gstbin.c:2230:gst_bin_element_set_state:<playbin0> current PAUSED pending VOID_PENDING, desired next PLAYING
0:00:00.064692606 24400 0xfab850 INFO GST_STATES gstbin.c:2230:gst_bin_element_set_state:<playsink> current PAUSED pending VOID_PENDING, desired next PLAYING
0:00:00.064703965 24400 0xfab850 INFO GST_STATES gstbin.c:2230:gst_bin_element_set_state:<abin> current PAUSED pending VOID_PENDING, desired next PLAYING
0:00:00.064715229 24400 0xfab850 INFO GST_STATES gstbin.c:2230:gst_bin_element_set_state:<out1> current PAUSED pending VOID_PENDING, desired next PLAYING
0:00:00.064725042 24400 0xfab850 INFO GST_STATES gstelement.c:2328:gst_element_continue_state:<out1> completed state change to PLAYING
0:00:00.064731226 24400 0xfab850 INFO GST_STATES gstelement.c:2233:_priv_gst_element_state_changed:<out1> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)
0:00:00.064742680 24400 0xfab850 INFO GST_STATES gstbin.c:2673:gst_bin_change_state_func:<abin> child 'out1' changed state to 4(PLAYING) successfully
0:00:00.064756989 24400 0xfab850 INFO GST_STATES gstbin.c:2230:gst_bin_element_set_state:<aconv> current PAUSED pending VOID_PENDING, desired next PLAYING
0:00:00.064768990 24400 0xfab850 INFO GST_STATES gstbin.c:2230:gst_bin_element_set_state:<volume> current PAUSED pending VOID_PENDING, desired next PLAYING
0:00:00.064777275 24400 0xfab850 INFO GST_STATES gstelement.c:2328:gst_element_continue_state:<volume> completed state change to PLAYING
0:00:00.064782975 24400 0xfab850 INFO GST_STATES gstelement.c:2233:_priv_gst_element_state_changed:<volume> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)
0:00:00.064793321 24400 0xfab850 INFO GST_STATES gstbin.c:2673:gst_bin_change_state_func:<aconv> child 'volume' changed state to 4(PLAYING) successfully
0:00:00.064801951 24400 0xfab850 INFO GST_STATES gstbin.c:2230:gst_bin_element_set_state:<resample> current PAUSED pending VOID_PENDING, desired next PLAYING
0:00:00.064809553 24400 0xfab850 INFO GST_STATES gstelement.c:2328:gst_element_continue_state:<resample> completed state change to PLAYING
0:00:00.064815257 24400 0xfab850 INFO GST_STATES gstelement.c:2233:_priv_gst_element_state_changed:<resample> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)
0:00:00.064824133 24400 0xfab850 INFO GST_STATES gstbin.c:2673:gst_bin_change_state_func:<aconv> child 'resample' changed state to 4(PLAYING) successfully
0:00:00.064832417 24400 0xfab850 INFO GST_STATES gstbin.c:2230:gst_bin_element_set_state:<conv> current PAUSED pending VOID_PENDING, desired next PLAYING
0:00:00.064839976 24400 0xfab850 INFO GST_STATES gstelement.c:2328:gst_element_continue_state:<conv> completed state change to PLAYING
0:00:00.064845478 24400 0xfab850 INFO GST_STATES gstelement.c:2233:_priv_gst_element_state_changed:<conv> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)
0:00:00.064854229 24400 0xfab850 INFO GST_STATES gstbin.c:2673:gst_bin_change_state_func:<aconv> child 'conv' changed state to 4(PLAYING) successfully
0:00:00.064861860 24400 0xfab850 INFO GST_STATES gstbin.c:2230:gst_bin_element_set_state:<identity> current PAUSED pending VOID_PENDING, desired next PLAYING
0:00:00.064868863 24400 0xfab850 INFO GST_STATES gstelement.c:2328:gst_element_continue_state:<identity> completed state change to PLAYING
0:00:00.064874089 24400 0xfab850 INFO GST_STATES gstelement.c:2233:_priv_gst_element_state_changed:<identity> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)
0:00:00.064885244 24400 0xfab850 INFO GST_STATES gstbin.c:2673:gst_bin_change_state_func:<aconv> child 'identity' changed state to 4(PLAYING) successfully
0:00:00.064893182 24400 0xfab850 INFO GST_STATES gstelement.c:2328:gst_element_continue_state:<aconv> completed state change to PLAYING
0:00:00.064898551 24400 0xfab850 INFO GST_STATES gstelement.c:2233:_priv_gst_element_state_changed:<aconv> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)
0:00:00.064907384 24400 0xfab850 INFO GST_STATES gstbin.c:2673:gst_bin_change_state_func:<abin> child 'aconv' changed state to 4(PLAYING) successfully
0:00:00.064914925 24400 0xfab850 INFO GST_STATES gstbin.c:2230:gst_bin_element_set_state:<aqueue> current PAUSED pending VOID_PENDING, desired next PLAYING
0:00:00.064921784 24400 0xfab850 INFO GST_STATES gstelement.c:2328:gst_element_continue_state:<aqueue> completed state change to PLAYING
0:00:00.064927061 24400 0xfab850 INFO GST_STATES gstelement.c:2233:_priv_gst_element_state_changed:<aqueue> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)
0:00:00.064948342 24400 0xfab850 INFO GST_STATES gstbin.c:2673:gst_bin_change_state_func:<abin> child 'aqueue' changed state to 4(PLAYING) successfully
0:00:00.064956834 24400 0xfab850 INFO GST_STATES gstelement.c:2328:gst_element_continue_state:<abin> completed state change to PLAYING
0:00:00.064962421 24400 0xfab850 INFO GST_STATES gstelement.c:2233:_priv_gst_element_state_changed:<abin> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)
0:00:00.064971299 24400 0xfab850 INFO GST_STATES gstbin.c:2673:gst_bin_change_state_func:<playsink> child 'abin' changed state to 4(PLAYING) successfully
0:00:00.064979579 24400 0xfab850 INFO GST_STATES gstbin.c:2230:gst_bin_element_set_state:<streamsynchronizer0> current PAUSED pending VOID_PENDING, desired next PLAYING
0:00:00.064987407 24400 0xfab850 INFO GST_STATES gstelement.c:2328:gst_element_continue_state:<streamsynchronizer0> completed state change to PLAYING
0:00:00.064992828 24400 0xfab850 INFO GST_STATES gstelement.c:2233:_priv_gst_element_state_changed:<streamsynchronizer0> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)
0:00:00.065000897 24400 0xfab850 INFO GST_STATES gstbin.c:2673:gst_bin_change_state_func:<playsink> child 'streamsynchronizer0' changed state to 4(PLAYING) successfully
0:00:00.065008698 24400 0xfab850 INFO GST_STATES gstbin.c:2230:gst_bin_element_set_state:<audiotee> current PAUSED pending VOID_PENDING, desired next PLAYING
0:00:00.065015594 24400 0xfab850 INFO GST_STATES gstelement.c:2328:gst_element_continue_state:<audiotee> completed state change to PLAYING
0:00:00.065020601 24400 0xfab850 INFO GST_STATES gstelement.c:2233:_priv_gst_element_state_changed:<audiotee> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)
0:00:00.065028589 24400 0xfab850 INFO GST_STATES gstbin.c:2673:gst_bin_change_state_func:<playsink> child 'audiotee' changed state to 4(PLAYING) successfully
0:00:00.065035875 24400 0xfab850 INFO GST_STATES gstelement.c:2328:gst_element_continue_state:<playsink> completed state change to PLAYING
0:00:00.065041227 24400 0xfab850 INFO GST_STATES gstelement.c:2233:_priv_gst_element_state_changed:<playsink> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)
0:00:00.065049533 24400 0xfab850 INFO GST_STATES gstbin.c:2673:gst_bin_change_state_func:<playbin0> child 'playsink' changed state to 4(PLAYING) successfully
0:00:00.065057381 24400 0xfab850 INFO GST_STATES gstbin.c:2230:gst_bin_element_set_state:<inputselector0> current PAUSED pending VOID_PENDING, desired next PLAYING
0:00:00.065064430 24400 0xfab850 INFO GST_STATES gstelement.c:2328:gst_element_continue_state:<inputselector0> completed state change to PLAYING
0:00:00.065069763 24400 0xfab850 INFO GST_STATES gstelement.c:2233:_priv_gst_element_state_changed:<inputselector0> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)
0:00:00.065083123 24400 0xfab850 INFO GST_STATES gstbin.c:2673:gst_bin_change_state_func:<playbin0> child 'inputselector0' changed state to 4(PLAYING) successfully
0:00:00.065091660 24400 0xfab850 INFO GST_STATES gstbin.c:2230:gst_bin_element_set_state:<uridecodebin0> current PAUSED pending VOID_PENDING, desired next PLAYING
0:00:00.065102826 24400 0xfab850 INFO GST_STATES gstbin.c:2230:gst_bin_element_set_state:<decodebin0> current PAUSED pending VOID_PENDING, desired next PLAYING
0:00:00.065114274 24400 0xfab850 INFO GST_STATES gstbin.c:2230:gst_bin_element_set_state:<mad0> current PAUSED pending VOID_PENDING, desired next PLAYING
0:00:00.065122121 24400 0xfab850 INFO GST_STATES gstelement.c:2328:gst_element_continue_state:<mad0> completed state change to PLAYING
0:00:00.065131236 24400 0xfab850 INFO GST_STATES gstelement.c:2233:_priv_gst_element_state_changed:<mad0> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)
0:00:00.065141453 24400 0xfab850 INFO GST_STATES gstbin.c:2673:gst_bin_change_state_func:<decodebin0> child 'mad0' changed state to 4(PLAYING) successfully
0:00:00.065150022 24400 0xfab850 INFO GST_STATES gstbin.c:2230:gst_bin_element_set_state:<mpegaudioparse0> current PAUSED pending VOID_PENDING, desired next PLAYING
0:00:00.065157673 24400 0xfab850 INFO GST_STATES gstelement.c:2328:gst_element_continue_state:<mpegaudioparse0> completed state change to PLAYING
0:00:00.065163012 24400 0xfab850 INFO GST_STATES gstelement.c:2233:_priv_gst_element_state_changed:<mpegaudioparse0> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)
0:00:00.065171890 24400 0xfab850 INFO GST_STATES gstbin.c:2673:gst_bin_change_state_func:<decodebin0> child 'mpegaudioparse0' changed state to 4(PLAYING) successfully
0:00:00.065180100 24400 0xfab850 INFO GST_STATES gstbin.c:2230:gst_bin_element_set_state:<id3demux0> current PAUSED pending VOID_PENDING, desired next PLAYING
0:00:00.065187426 24400 0xfab850 INFO GST_STATES gstelement.c:2328:gst_element_continue_state:<id3demux0> completed state change to PLAYING
0:00:00.065192736 24400 0xfab850 INFO GST_STATES gstelement.c:2233:_priv_gst_element_state_changed:<id3demux0> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)
0:00:00.065201323 24400 0xfab850 INFO GST_STATES gstbin.c:2673:gst_bin_change_state_func:<decodebin0> child 'id3demux0' changed state to 4(PLAYING) successfully
0:00:00.065209006 24400 0xfab850 INFO GST_STATES gstbin.c:2230:gst_bin_element_set_state:<typefind> current PAUSED pending VOID_PENDING, desired next PLAYING
0:00:00.065216246 24400 0xfab850 INFO GST_STATES gstelement.c:2328:gst_element_continue_state:<typefind> completed state change to PLAYING
0:00:00.065221378 24400 0xfab850 INFO GST_STATES gstelement.c:2233:_priv_gst_element_state_changed:<typefind> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)
0:00:00.065229868 24400 0xfab850 INFO GST_STATES gstbin.c:2673:gst_bin_change_state_func:<decodebin0> child 'typefind' changed state to 4(PLAYING) successfully
0:00:00.065237840 24400 0xfab850 INFO GST_STATES gstelement.c:2328:gst_element_continue_state:<decodebin0> completed state change to PLAYING
0:00:00.065243575 24400 0xfab850 INFO GST_STATES gstelement.c:2233:_priv_gst_element_state_changed:<decodebin0> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)
0:00:00.065252651 24400 0xfab850 INFO GST_STATES gstbin.c:2673:gst_bin_change_state_func:<uridecodebin0> child 'decodebin0' changed state to 4(PLAYING) successfully
0:00:00.065260287 24400 0xfab850 INFO GST_STATES gstbin.c:2230:gst_bin_element_set_state:<source> current PAUSED pending VOID_PENDING, desired next PLAYING
0:00:00.065267641 24400 0xfab850 INFO GST_STATES gstelement.c:2328:gst_element_continue_state:<source> completed state change to PLAYING
0:00:00.065272840 24400 0xfab850 INFO GST_STATES gstelement.c:2233:_priv_gst_element_state_changed:<source> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)
0:00:00.065281250 24400 0xfab850 INFO GST_STATES gstbin.c:2673:gst_bin_change_state_func:<uridecodebin0> child 'source' changed state to 4(PLAYING) successfully
0:00:00.065288601 24400 0xfab850 INFO GST_STATES gstelement.c:2328:gst_element_continue_state:<uridecodebin0> completed state change to PLAYING
0:00:00.065294058 24400 0xfab850 INFO GST_STATES gstelement.c:2233:_priv_gst_element_state_changed:<uridecodebin0> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)
0:00:00.065308625 24400 0xfab850 INFO GST_STATES gstbin.c:2673:gst_bin_change_state_func:<playbin0> child 'uridecodebin0' changed state to 4(PLAYING) successfully
0:00:00.065316431 24400 0xfab850 INFO GST_STATES gstelement.c:2328:gst_element_continue_state:<playbin0> completed state change to PLAYING
0:00:00.065321830 24400 0xfab850 INFO GST_STATES gstelement.c:2233:_priv_gst_element_state_changed:<playbin0> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)
0:00:00.065330333 24400 0xfab850 INFO GST_STATES gstbin.c:2673:gst_bin_change_state_func:<pipe> child 'playbin0' changed state to 4(PLAYING) successfully
0:00:00.065338301 24400 0xfab850 INFO GST_STATES gstbin.c:2230:gst_bin_element_set_state:<autoaudiosink0> current PAUSED pending VOID_PENDING, desired next PLAYING
0:00:00.065348361 24400 0xfab850 INFO GST_STATES gstbin.c:2230:gst_bin_element_set_state:<autoaudiosink0-actual-sink-pulse> current PAUSED pending VOID_PENDING, desired next PLAYING
0:00:00.065359935 24400 0xfab850 INFO GST_STATES gstelement.c:2328:gst_element_continue_state:<autoaudiosink0-actual-sink-pulse> completed state change to PLAYING
0:00:00.065365650 24400 0xfab850 INFO GST_STATES gstelement.c:2233:_priv_gst_element_state_changed:<autoaudiosink0-actual-sink-pulse> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)
0:00:00.065374040 24400 0xfab850 INFO GST_STATES gstbin.c:2673:gst_bin_change_state_func:<autoaudiosink0> child 'autoaudiosink0-actual-sink-pulse' changed state to 4(PLAYING) successfully
0:00:00.065383173 24400 0xfab850 INFO GST_STATES gstelement.c:2328:gst_element_continue_state:<autoaudiosink0> completed state change to PLAYING
0:00:00.065388542 24400 0xfab850 INFO GST_STATES gstelement.c:2233:_priv_gst_element_state_changed:<autoaudiosink0> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)
0:00:00.065397411 24400 0xfab850 INFO GST_STATES gstbin.c:2673:gst_bin_change_state_func:<pipe> child 'autoaudiosink0' changed state to 4(PLAYING) successfully
0:00:00.065405358 24400 0xfab850 INFO GST_STATES gstbin.c:2230:gst_bin_element_set_state:<adder0> current PAUSED pending VOID_PENDING, desired next PLAYING
0:00:00.065412773 24400 0xfab850 INFO GST_STATES gstelement.c:2328:gst_element_continue_state:<adder0> completed state change to PLAYING
0:00:00.065418016 24400 0xfab850 INFO GST_STATES gstelement.c:2233:_priv_gst_element_state_changed:<adder0> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)
0:00:00.065426142 24400 0xfab850 INFO GST_STATES gstbin.c:2673:gst_bin_change_state_func:<pipe> child 'adder0' changed state to 4(PLAYING) successfully
0:00:00.065433521 24400 0xfab850 INFO GST_STATES gstelement.c:2328:gst_element_continue_state:<pipe> completed state change to PLAYING
0:00:00.065438877 24400 0xfab850 INFO GST_STATES gstelement.c:2233:_priv_gst_element_state_changed:<pipe> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)
0:00:01.031631030 24400 0xd5e720 INFO GST_STATES gstbin.c:2230:gst_bin_element_set_state:<playsink> current PLAYING pending VOID_PENDING, desired next PAUSED
0:00:01.031679552 24400 0xd5e720 INFO GST_STATES gstbin.c:2230:gst_bin_element_set_state:<abin> current PLAYING pending VOID_PENDING, desired next PAUSED
0:00:01.031700840 24400 0xd5e720 INFO GST_STATES gstbin.c:2230:gst_bin_element_set_state:<out1> current PLAYING pending VOID_PENDING, desired next PAUSED
0:00:01.031717839 24400 0xd5e720 INFO GST_STATES gstelement.c:2328:gst_element_continue_state:<out1> completed state change to PAUSED
0:00:01.031740649 24400 0xd5e720 INFO GST_STATES gstelement.c:2233:_priv_gst_element_state_changed:<out1> notifying about state-changed PLAYING to PAUSED (VOID_PENDING pending)
0:00:01.031767489 24400 0xd5e720 INFO GST_STATES gstbin.c:2673:gst_bin_change_state_func:<abin> child 'out1' changed state to 3(PAUSED) successfully
0:00:01.031789467 24400 0xd5e720 INFO GST_STATES gstbin.c:2230:gst_bin_element_set_state:<aconv> current PLAYING pending VOID_PENDING, desired next PAUSED
0:00:01.031810509 24400 0xd5e720 INFO GST_STATES gstbin.c:2230:gst_bin_element_set_state:<volume> current PLAYING pending VOID_PENDING, desired next PAUSED
0:00:01.031823775 24400 0xd5e720 INFO GST_STATES gstelement.c:2328:gst_element_continue_state:<volume> completed state change to PAUSED
0:00:01.031832996 24400 0xd5e720 INFO GST_STATES gstelement.c:2233:_priv_gst_element_state_changed:<volume> notifying about state-changed PLAYING to PAUSED (VOID_PENDING pending)
0:00:01.031877066 24400 0xd5e720 INFO GST_STATES gstbin.c:2673:gst_bin_change_state_func:<aconv> child 'volume' changed state to 3(PAUSED) successfully
0:00:01.031892664 24400 0xd5e720 INFO GST_STATES gstbin.c:2230:gst_bin_element_set_state:<resample> current PLAYING pending VOID_PENDING, desired next PAUSED
0:00:01.031905210 24400 0xd5e720 INFO GST_STATES gstelement.c:2328:gst_element_continue_state:<resample> completed state change to PAUSED
0:00:01.031914125 24400 0xd5e720 INFO GST_STATES gstelement.c:2233:_priv_gst_element_state_changed:<resample> notifying about state-changed PLAYING to PAUSED (VOID_PENDING pending)
0:00:01.031929680 24400 0xd5e720 INFO GST_STATES gstbin.c:2673:gst_bin_change_state_func:<aconv> child 'resample' changed state to 3(PAUSED) successfully
0:00:01.031962778 24400 0xd5e720 INFO GST_STATES gstbin.c:2230:gst_bin_element_set_state:<conv> current PLAYING pending VOID_PENDING, desired next PAUSED
0:00:01.031975106 24400 0xd5e720 INFO GST_STATES gstelement.c:2328:gst_element_continue_state:<conv> completed state change to PAUSED
0:00:01.031983999 24400 0xd5e720 INFO GST_STATES gstelement.c:2233:_priv_gst_element_state_changed:<conv> notifying about state-changed PLAYING to PAUSED (VOID_PENDING pending)
0:00:01.031999949 24400 0xd5e720 INFO GST_STATES gstbin.c:2673:gst_bin_change_state_func:<aconv> child 'conv' changed state to 3(PAUSED) successfully
0:00:01.032013634 24400 0xd5e720 INFO GST_STATES gstbin.c:2230:gst_bin_element_set_state:<identity> current PLAYING pending VOID_PENDING, desired next PAUSED
0:00:01.032025608 24400 0xd5e720 INFO GST_STATES gstelement.c:2328:gst_element_continue_state:<identity> completed state change to PAUSED
0:00:01.032034496 24400 0xd5e720 INFO GST_STATES gstelement.c:2233:_priv_gst_element_state_changed:<identity> notifying about state-changed PLAYING to PAUSED (VOID_PENDING pending)
0:00:01.032049477 24400 0xd5e720 INFO GST_STATES gstbin.c:2673:gst_bin_change_state_func:<aconv> child 'identity' changed state to 3(PAUSED) successfully
0:00:01.032062862 24400 0xd5e720 INFO GST_STATES gstelement.c:2328:gst_element_continue_state:<aconv> completed state change to PAUSED
0:00:01.032072177 24400 0xd5e720 INFO GST_STATES gstelement.c:2233:_priv_gst_element_state_changed:<aconv> notifying about state-changed PLAYING to PAUSED (VOID_PENDING pending)
0:00:01.032087531 24400 0xd5e720 INFO GST_STATES gstbin.c:2673:gst_bin_change_state_func:<abin> child 'aconv' changed state to 3(PAUSED) successfully
0:00:01.032100523 24400 0xd5e720 INFO GST_STATES gstbin.c:2230:gst_bin_element_set_state:<aqueue> current PLAYING pending VOID_PENDING, desired next PAUSED
0:00:01.032119907 24400 0xd5e720 INFO GST_STATES gstelement.c:2328:gst_element_continue_state:<aqueue> completed state change to PAUSED
0:00:01.032129627 24400 0xd5e720 INFO GST_STATES gstelement.c:2233:_priv_gst_element_state_changed:<aqueue> notifying about state-changed PLAYING to PAUSED (VOID_PENDING pending)
0:00:01.032149945 24400 0xd5e720 INFO GST_STATES gstbin.c:2673:gst_bin_change_state_func:<abin> child 'aqueue' changed state to 3(PAUSED) successfully
0:00:01.032163681 24400 0xd5e720 INFO GST_STATES gstelement.c:2328:gst_element_continue_state:<abin> completed state change to PAUSED
0:00:01.032173130 24400 0xd5e720 INFO GST_STATES gstelement.c:2233:_priv_gst_element_state_changed:<abin> notifying about state-changed PLAYING to PAUSED (VOID_PENDING pending)
0:00:01.032188305 24400 0xd5e720 INFO GST_STATES gstbin.c:2673:gst_bin_change_state_func:<playsink> child 'abin' changed state to 3(PAUSED) successfully
0:00:01.032202142 24400 0xd5e720 INFO GST_STATES gstbin.c:2230:gst_bin_element_set_state:<streamsynchronizer0> current PLAYING pending VOID_PENDING, desired next PAUSED
0:00:01.032214877 24400 0xd5e720 INFO GST_STATES gstelement.c:2328:gst_element_continue_state:<streamsynchronizer0> completed state change to PAUSED
0:00:01.032223663 24400 0xd5e720 INFO GST_STATES gstelement.c:2233:_priv_gst_element_state_changed:<streamsynchronizer0> notifying about state-changed PLAYING to PAUSED (VOID_PENDING pending)
0:00:01.032238110 24400 0xd5e720 INFO GST_STATES gstbin.c:2673:gst_bin_change_state_func:<playsink> child 'streamsynchronizer0' changed state to 3(PAUSED) successfully
0:00:01.032251586 24400 0xd5e720 INFO GST_STATES gstbin.c:2230:gst_bin_element_set_state:<audiotee> current PLAYING pending VOID_PENDING, desired next PAUSED
0:00:01.032263320 24400 0xd5e720 INFO GST_STATES gstelement.c:2328:gst_element_continue_state:<audiotee> completed state change to PAUSED
0:00:01.032272351 24400 0xd5e720 INFO GST_STATES gstelement.c:2233:_priv_gst_element_state_changed:<audiotee> notifying about state-changed PLAYING to PAUSED (VOID_PENDING pending)
0:00:01.032286676 24400 0xd5e720 INFO GST_STATES gstbin.c:2673:gst_bin_change_state_func:<playsink> child 'audiotee' changed state to 3(PAUSED) successfully
0:00:01.032299435 24400 0xd5e720 INFO GST_STATES gstelement.c:2328:gst_element_continue_state:<playsink> completed state change to PAUSED
0:00:01.032308299 24400 0xd5e720 INFO GST_STATES gstelement.c:2233:_priv_gst_element_state_changed:<playsink> notifying about state-changed PLAYING to PAUSED (VOID_PENDING pending)
0:00:01.032325313 24400 0xd5e720 INFO GST_STATES gstbin.c:2673:gst_bin_change_state_func:<playbin0> child 'playsink' changed state to 3(PAUSED) successfully
0:00:01.032339169 24400 0xd5e720 INFO GST_STATES gstbin.c:2230:gst_bin_element_set_state:<inputselector0> current PLAYING pending VOID_PENDING, desired next PAUSED
0:00:01.032351515 24400 0xd5e720 INFO GST_STATES gstelement.c:2328:gst_element_continue_state:<inputselector0> completed state change to PAUSED
0:00:01.032360947 24400 0xd5e720 INFO GST_STATES gstelement.c:2233:_priv_gst_element_state_changed:<inputselector0> notifying about state-changed PLAYING to PAUSED (VOID_PENDING pending)
0:00:01.032375069 24400 0xd5e720 INFO GST_STATES gstbin.c:2673:gst_bin_change_state_func:<playbin0> child 'inputselector0' changed state to 3(PAUSED) successfully
0:00:01.032387537 24400 0xd5e720 INFO GST_STATES gstbin.c:2230:gst_bin_element_set_state:<uridecodebin0> current PLAYING pending VOID_PENDING, desired next PAUSED
0:00:01.032405343 24400 0xd5e720 INFO GST_STATES gstbin.c:2230:gst_bin_element_set_state:<decodebin0> current PLAYING pending VOID_PENDING, desired next PAUSED
0:00:01.032431499 24400 0xd5e720 INFO GST_STATES gstbin.c:2230:gst_bin_element_set_state:<mad0> current PLAYING pending VOID_PENDING, desired next PAUSED
0:00:01.032445300 24400 0xd5e720 INFO GST_STATES gstelement.c:2328:gst_element_continue_state:<mad0> completed state change to PAUSED
0:00:01.032454822 24400 0xd5e720 INFO GST_STATES gstelement.c:2233:_priv_gst_element_state_changed:<mad0> notifying about state-changed PLAYING to PAUSED (VOID_PENDING pending)
0:00:01.032470864 24400 0xd5e720 INFO GST_STATES gstbin.c:2673:gst_bin_change_state_func:<decodebin0> child 'mad0' changed state to 3(PAUSED) successfully
0:00:01.032484457 24400 0xd5e720 INFO GST_STATES gstbin.c:2230:gst_bin_element_set_state:<mpegaudioparse0> current PLAYING pending VOID_PENDING, desired next PAUSED
0:00:01.032496717 24400 0xd5e720 INFO GST_STATES gstelement.c:2328:gst_element_continue_state:<mpegaudioparse0> completed state change to PAUSED
0:00:01.032505683 24400 0xd5e720 INFO GST_STATES gstelement.c:2233:_priv_gst_element_state_changed:<mpegaudioparse0> notifying about state-changed PLAYING to PAUSED (VOID_PENDING pending)
0:00:01.032529327 24400 0xd5e720 INFO GST_STATES gstbin.c:2673:gst_bin_change_state_func:<decodebin0> child 'mpegaudioparse0' changed state to 3(PAUSED) successfully
0:00:01.032544509 24400 0xd5e720 INFO GST_STATES gstbin.c:2230:gst_bin_element_set_state:<id3demux0> current PLAYING pending VOID_PENDING, desired next PAUSED
0:00:01.032557154 24400 0xd5e720 INFO GST_STATES gstelement.c:2328:gst_element_continue_state:<id3demux0> completed state change to PAUSED
0:00:01.032566348 24400 0xd5e720 INFO GST_STATES gstelement.c:2233:_priv_gst_element_state_changed:<id3demux0> notifying about state-changed PLAYING to PAUSED (VOID_PENDING pending)
0:00:01.032581433 24400 0xd5e720 INFO GST_STATES gstbin.c:2673:gst_bin_change_state_func:<decodebin0> child 'id3demux0' changed state to 3(PAUSED) successfully
0:00:01.032594296 24400 0xd5e720 INFO GST_STATES gstbin.c:2230:gst_bin_element_set_state:<typefind> current PLAYING pending VOID_PENDING, desired next PAUSED
0:00:01.032606386 24400 0xd5e720 INFO GST_STATES gstelement.c:2328:gst_element_continue_state:<typefind> completed state change to PAUSED
0:00:01.032615086 24400 0xd5e720 INFO GST_STATES gstelement.c:2233:_priv_gst_element_state_changed:<typefind> notifying about state-changed PLAYING to PAUSED (VOID_PENDING pending)
0:00:01.032629719 24400 0xd5e720 INFO GST_STATES gstbin.c:2673:gst_bin_change_state_func:<decodebin0> child 'typefind' changed state to 3(PAUSED) successfully
0:00:01.032642564 24400 0xd5e720 INFO GST_STATES gstelement.c:2328:gst_element_continue_state:<decodebin0> completed state change to PAUSED
0:00:01.032651717 24400 0xd5e720 INFO GST_STATES gstelement.c:2233:_priv_gst_element_state_changed:<decodebin0> notifying about state-changed PLAYING to PAUSED (VOID_PENDING pending)
0:00:01.032666422 24400 0xd5e720 INFO GST_STATES gstbin.c:2673:gst_bin_change_state_func:<uridecodebin0> child 'decodebin0' changed state to 3(PAUSED) successfully
0:00:01.032679137 24400 0xd5e720 INFO GST_STATES gstbin.c:2230:gst_bin_element_set_state:<source> current PLAYING pending VOID_PENDING, desired next PAUSED
0:00:01.032691685 24400 0xd5e720 INFO GST_STATES gstelement.c:2328:gst_element_continue_state:<source> completed state change to PAUSED
0:00:01.032700535 24400 0xd5e720 INFO GST_STATES gstelement.c:2233:_priv_gst_element_state_changed:<source> notifying about state-changed PLAYING to PAUSED (VOID_PENDING pending)
0:00:01.032714595 24400 0xd5e720 INFO GST_STATES gstbin.c:2673:gst_bin_change_state_func:<uridecodebin0> child 'source' changed state to 3(PAUSED) successfully
0:00:01.032733650 24400 0xd5e720 INFO GST_STATES gstelement.c:2328:gst_element_continue_state:<uridecodebin0> completed state change to PAUSED
0:00:01.032743325 24400 0xd5e720 INFO GST_STATES gstelement.c:2233:_priv_gst_element_state_changed:<uridecodebin0> notifying about state-changed PLAYING to PAUSED (VOID_PENDING pending)
0:00:01.032757940 24400 0xd5e720 INFO GST_STATES gstbin.c:2673:gst_bin_change_state_func:<playbin0> child 'uridecodebin0' changed state to 3(PAUSED) successfully
0:00:01.032775197 24400 0xd5e720 INFO GST_STATES gstelement.c:2328:gst_element_continue_state:<playbin0> completed state change to PAUSED
0:00:01.032785029 24400 0xd5e720 INFO GST_STATES gstelement.c:2233:_priv_gst_element_state_changed:<playbin0> notifying about state-changed PLAYING to PAUSED (VOID_PENDING pending)
0:00:01.032842545 24400 0xd5e720 INFO GST_STATES gstbin.c:2230:gst_bin_element_set_state:<playbin0> current PAUSED pending VOID_PENDING, desired next PAUSED
0:00:01.032865189 24400 0xd5e720 INFO GST_STATES gstbin.c:2230:gst_bin_element_set_state:<playsink> current PAUSED pending VOID_PENDING, desired next PAUSED
0:00:01.032883059 24400 0xd5e720 INFO GST_STATES gstbin.c:2230:gst_bin_element_set_state:<abin> current PAUSED pending VOID_PENDING, desired next PAUSED
0:00:01.032900313 24400 0xd5e720 INFO GST_STATES gstbin.c:2230:gst_bin_element_set_state:<out1> current PAUSED pending VOID_PENDING, desired next PAUSED
0:00:01.032915852 24400 0xd5e720 INFO GST_STATES gstelement.c:2328:gst_element_continue_state:<out1> completed state change to PAUSED
0:00:01.032926601 24400 0xd5e720 INFO GST_STATES gstbin.c:2673:gst_bin_change_state_func:<abin> child 'out1' changed state to 3(PAUSED) successfully
0:00:01.032950210 24400 0xd5e720 INFO GST_STATES gstbin.c:2230:gst_bin_element_set_state:<aconv> current PAUSED pending VOID_PENDING, desired next PAUSED
0:00:01.032968115 24400 0xd5e720 INFO GST_STATES gstbin.c:2230:gst_bin_element_set_state:<volume> current PAUSED pending VOID_PENDING, desired next PAUSED
0:00:01.032979340 24400 0xd5e720 INFO GST_STATES gstbin.c:2347:gst_bin_element_set_state:<volume> skipping transition from PAUSED to PAUSED
0:00:01.032988737 24400 0xd5e720 INFO GST_STATES gstbin.c:2673:gst_bin_change_state_func:<aconv> child 'volume' changed state to 3(PAUSED) successfully
0:00:01.033001373 24400 0xd5e720 INFO GST_STATES gstbin.c:2230:gst_bin_element_set_state:<resample> current PAUSED pending VOID_PENDING, desired next PAUSED
0:00:01.033011644 24400 0xd5e720 INFO GST_STATES gstbin.c:2347:gst_bin_element_set_state:<resample> skipping transition from PAUSED to PAUSED
0:00:01.033020747 24400 0xd5e720 INFO GST_STATES gstbin.c:2673:gst_bin_change_state_func:<aconv> child 'resample' changed state to 3(PAUSED) successfully
0:00:01.033032862 24400 0xd5e720 INFO GST_STATES gstbin.c:2230:gst_bin_element_set_state:<conv> current PAUSED pending VOID_PENDING, desired next PAUSED
0:00:01.033042884 24400 0xd5e720 INFO GST_STATES gstbin.c:2347:gst_bin_element_set_state:<conv> skipping transition from PAUSED to PAUSED
0:00:01.033051750 24400 0xd5e720 INFO GST_STATES gstbin.c:2673:gst_bin_change_state_func:<aconv> child 'conv' changed state to 3(PAUSED) successfully
0:00:01.033063441 24400 0xd5e720 INFO GST_STATES gstbin.c:2230:gst_bin_element_set_state:<identity> current PAUSED pending VOID_PENDING, desired next PAUSED
0:00:01.033073536 24400 0xd5e720 INFO GST_STATES gstbin.c:2347:gst_bin_element_set_state:<identity> skipping transition from PAUSED to PAUSED
0:00:01.033082354 24400 0xd5e720 INFO GST_STATES gstbin.c:2673:gst_bin_change_state_func:<aconv> child 'identity' changed state to 3(PAUSED) successfully
0:00:01.033100984 24400 0xd5e720 INFO GST_STATES gstelement.c:2328:gst_element_continue_state:<aconv> completed state change to PAUSED
0:00:01.033111871 24400 0xd5e720 INFO GST_STATES gstbin.c:2673:gst_bin_change_state_func:<abin> child 'aconv' changed state to 3(PAUSED) successfully
0:00:01.033124412 24400 0xd5e720 INFO GST_STATES gstbin.c:2230:gst_bin_element_set_state:<aqueue> current PAUSED pending VOID_PENDING, desired next PAUSED
0:00:01.033134815 24400 0xd5e720 INFO GST_STATES gstbin.c:2347:gst_bin_element_set_state:<aqueue> skipping transition from PAUSED to PAUSED
0:00:01.033143769 24400 0xd5e720 INFO GST_STATES gstbin.c:2673:gst_bin_change_state_func:<abin> child 'aqueue' changed state to 3(PAUSED) successfully
0:00:01.033155468 24400 0xd5e720 INFO GST_STATES gstelement.c:2328:gst_element_continue_state:<abin> completed state change to PAUSED
0:00:01.033165398 24400 0xd5e720 INFO GST_STATES gstbin.c:2673:gst_bin_change_state_func:<playsink> child 'abin' changed state to 3(PAUSED) successfully
0:00:01.033177926 24400 0xd5e720 INFO GST_STATES gstbin.c:2230:gst_bin_element_set_state:<streamsynchronizer0> current PAUSED pending VOID_PENDING, desired next PAUSED
0:00:01.033188310 24400 0xd5e720 INFO GST_STATES gstbin.c:2347:gst_bin_element_set_state:<streamsynchronizer0> skipping transition from PAUSED to PAUSED
0:00:01.033197455 24400 0xd5e720 INFO GST_STATES gstbin.c:2673:gst_bin_change_state_func:<playsink> child 'streamsynchronizer0' changed state to 3(PAUSED) successfully
0:00:01.033209490 24400 0xd5e720 INFO GST_STATES gstbin.c:2230:gst_bin_element_set_state:<audiotee> current PAUSED pending VOID_PENDING, desired next PAUSED
0:00:01.033219445 24400 0xd5e720 INFO GST_STATES gstbin.c:2347:gst_bin_element_set_state:<audiotee> skipping transition from PAUSED to PAUSED
0:00:01.033228408 24400 0xd5e720 INFO GST_STATES gstbin.c:2673:gst_bin_change_state_func:<playsink> child 'audiotee' changed state to 3(PAUSED) successfully
0:00:01.033240020 24400 0xd5e720 INFO GST_STATES gstelement.c:2328:gst_element_continue_state:<playsink> completed state change to PAUSED
0:00:01.033249947 24400 0xd5e720 INFO GST_STATES gstbin.c:2673:gst_bin_change_state_func:<playbin0> child 'playsink' changed state to 3(PAUSED) successfully
0:00:01.033262493 24400 0xd5e720 INFO GST_STATES gstbin.c:2230:gst_bin_element_set_state:<inputselector0> current PAUSED pending VOID_PENDING, desired next PAUSED
0:00:01.033273017 24400 0xd5e720 INFO GST_STATES gstbin.c:2347:gst_bin_element_set_state:<inputselector0> skipping transition from PAUSED to PAUSED
0:00:01.033282158 24400 0xd5e720 INFO GST_STATES gstbin.c:2673:gst_bin_change_state_func:<playbin0> child 'inputselector0' changed state to 3(PAUSED) successfully
0:00:01.033293543 24400 0xd5e720 INFO GST_STATES gstbin.c:2230:gst_bin_element_set_state:<uridecodebin0> current PAUSED pending VOID_PENDING, desired next PAUSED
0:00:01.033309487 24400 0xd5e720 INFO GST_STATES gstbin.c:2230:gst_bin_element_set_state:<decodebin0> current PAUSED pending VOID_PENDING, desired next PAUSED
0:00:01.033327097 24400 0xd5e720 INFO GST_STATES gstbin.c:2230:gst_bin_element_set_state:<mad0> current PAUSED pending VOID_PENDING, desired next PAUSED
0:00:01.033337786 24400 0xd5e720 INFO GST_STATES gstbin.c:2347:gst_bin_element_set_state:<mad0> skipping transition from PAUSED to PAUSED
0:00:01.033347318 24400 0xd5e720 INFO GST_STATES gstbin.c:2673:gst_bin_change_state_func:<decodebin0> child 'mad0' changed state to 3(PAUSED) successfully
0:00:01.033359651 24400 0xd5e720 INFO GST_STATES gstbin.c:2230:gst_bin_element_set_state:<mpegaudioparse0> current PAUSED pending VOID_PENDING, desired next PAUSED
0:00:01.033375525 24400 0xd5e720 INFO GST_STATES gstbin.c:2347:gst_bin_element_set_state:<mpegaudioparse0> skipping transition from PAUSED to PAUSED
0:00:01.033384943 24400 0xd5e720 INFO GST_STATES gstbin.c:2673:gst_bin_change_state_func:<decodebin0> child 'mpegaudioparse0' changed state to 3(PAUSED) successfully
0:00:01.033397765 24400 0xd5e720 INFO GST_STATES gstbin.c:2230:gst_bin_element_set_state:<id3demux0> current PAUSED pending VOID_PENDING, desired next PAUSED
0:00:01.033407925 24400 0xd5e720 INFO GST_STATES gstbin.c:2347:gst_bin_element_set_state:<id3demux0> skipping transition from PAUSED to PAUSED
0:00:01.033416921 24400 0xd5e720 INFO GST_STATES gstbin.c:2673:gst_bin_change_state_func:<decodebin0> child 'id3demux0' changed state to 3(PAUSED) successfully
0:00:01.033428806 24400 0xd5e720 INFO GST_STATES gstbin.c:2230:gst_bin_element_set_state:<typefind> current PAUSED pending VOID_PENDING, desired next PAUSED
0:00:01.033438728 24400 0xd5e720 INFO GST_STATES gstbin.c:2347:gst_bin_element_set_state:<typefind> skipping transition from PAUSED to PAUSED
0:00:01.033447686 24400 0xd5e720 INFO GST_STATES gstbin.c:2673:gst_bin_change_state_func:<decodebin0> child 'typefind' changed state to 3(PAUSED) successfully
0:00:01.033459390 24400 0xd5e720 INFO GST_STATES gstelement.c:2328:gst_element_continue_state:<decodebin0> completed state change to PAUSED
0:00:01.033469513 24400 0xd5e720 INFO GST_STATES gstbin.c:2673:gst_bin_change_state_func:<uridecodebin0> child 'decodebin0' changed state to 3(PAUSED) successfully
0:00:01.033481249 24400 0xd5e720 INFO GST_STATES gstbin.c:2230:gst_bin_element_set_state:<source> current PAUSED pending VOID_PENDING, desired next PAUSED
0:00:01.033491192 24400 0xd5e720 INFO GST_STATES gstbin.c:2347:gst_bin_element_set_state:<source> skipping transition from PAUSED to PAUSED
0:00:01.033499960 24400 0xd5e720 INFO GST_STATES gstbin.c:2673:gst_bin_change_state_func:<uridecodebin0> child 'source' changed state to 3(PAUSED) successfully
0:00:01.033511338 24400 0xd5e720 INFO GST_STATES gstelement.c:2328:gst_element_continue_state:<uridecodebin0> completed state change to PAUSED
0:00:01.033521310 24400 0xd5e720 INFO GST_STATES gstbin.c:2673:gst_bin_change_state_func:<playbin0> child 'uridecodebin0' changed state to 3(PAUSED) successfully
0:00:01.033533380 24400 0xd5e720 INFO GST_STATES gstelement.c:2328:gst_element_continue_state:<playbin0> completed state change to PAUSED
0:00:01.033543145 24400 0xd5e720 INFO GST_STATES gstbin.c:2673:gst_bin_change_state_func:<pipe> child 'playbin0' changed state to 3(PAUSED) successfully
0:00:01.033556082 24400 0xd5e720 INFO GST_STATES gstbin.c:2230:gst_bin_element_set_state:<autoaudiosink0> current PLAYING pending VOID_PENDING, desired next PAUSED
0:00:01.033573100 24400 0xd5e720 INFO GST_STATES gstbin.c:2230:gst_bin_element_set_state:<autoaudiosink0-actual-sink-pulse> current PLAYING pending VOID_PENDING, desired next PAUSED
0:00:01.034413098 24400 0xd5e720 INFO GST_STATES gstelement.c:2328:gst_element_continue_state:<autoaudiosink0-actual-sink-pulse> completed state change to PAUSED
0:00:01.034440642 24400 0xd5e720 INFO GST_STATES gstelement.c:2233:_priv_gst_element_state_changed:<autoaudiosink0-actual-sink-pulse> notifying about state-changed PLAYING to PAUSED (VOID_PENDING pending)
0:00:01.034463926 24400 0xd5e720 INFO GST_STATES gstbin.c:2673:gst_bin_change_state_func:<autoaudiosink0> child 'autoaudiosink0-actual-sink-pulse' changed state to 3(PAUSED) successfully
0:00:01.034481344 24400 0xd5e720 INFO GST_STATES gstelement.c:2328:gst_element_continue_state:<autoaudiosink0> completed state change to PAUSED
0:00:01.034500534 24400 0xd5e720 INFO GST_STATES gstelement.c:2233:_priv_gst_element_state_changed:<autoaudiosink0> notifying about state-changed PLAYING to PAUSED (VOID_PENDING pending)
0:00:01.034516405 24400 0xd5e720 INFO GST_STATES gstbin.c:2673:gst_bin_change_state_func:<pipe> child 'autoaudiosink0' changed state to 3(PAUSED) successfully
0:00:01.034532658 24400 0xd5e720 INFO GST_STATES gstbin.c:2230:gst_bin_element_set_state:<adder0> current PLAYING pending VOID_PENDING, desired next PAUSED
0:00:01.034546109 24400 0xd5e720 INFO GST_STATES gstelement.c:2328:gst_element_continue_state:<adder0> completed state change to PAUSED
0:00:01.034554512 24400 0xd5e720 INFO GST_STATES gstelement.c:2233:_priv_gst_element_state_changed:<adder0> notifying about state-changed PLAYING to PAUSED (VOID_PENDING pending)
0:00:01.034567261 24400 0xd5e720 INFO GST_STATES gstbin.c:2673:gst_bin_change_state_func:<pipe> child 'adder0' changed state to 3(PAUSED) successfully
0:00:01.034583674 24400 0xd5e720 INFO GST_STATES gstelement.c:2328:gst_element_continue_state:<pipe> completed state change to PAUSED
0:00:01.034592946 24400 0xd5e720 INFO GST_STATES gstelement.c:2233:_priv_gst_element_state_changed:<pipe> notifying about state-changed PLAYING to PAUSED (VOID_PENDING pending)
0:00:02.035839650 24400 0xd5e720 INFO playbin gstplaybin2.c:2227:gst_play_bin_set_sink:<playbin0> Setting audio sink to (NULL)
0:00:02.035970569 24400 0xd5e720 INFO GST_STATES gstbin.c:2230:gst_bin_element_set_state:<playsink> current PAUSED pending VOID_PENDING, desired next READY
0:00:02.036004687 24400 0xd5e720 INFO GST_STATES gstbin.c:2230:gst_bin_element_set_state:<abin> current PAUSED pending VOID_PENDING, desired next READY
0:00:02.036026759 24400 0xd5e720 INFO GST_STATES gstbin.c:2230:gst_bin_element_set_state:<out1> current PAUSED pending VOID_PENDING, desired next READY
Raw
test.py
#!/usr/bin/env python
from gi.repository import Gst, GObject, GLib
import threading
import time
Gst.init(None)
pipe = Gst.Pipeline.new('pipe')
player1 = Gst.ElementFactory.make('playbin')
player1.props.uri = "file:///home/virtuald/Music/DJ/emusic/Artie Shaw - You're A Lucky Guy.mp3"
output_sink = Gst.ElementFactory.make("autoaudiosink")
adder = Gst.ElementFactory.make("adder")
pipe.add(adder)
pipe.add(output_sink)
adder.link(output_sink)
out_bin1 = Gst.Bin.new('out1')
player1.props.audio_sink = out_bin1
pipe.add(player1)
player1.sync_state_with_parent()
out_bin1.add_pad(Gst.GhostPad.new('sink', adder.get_request_pad('sink_%u')))
pipe.set_state(Gst.State.PLAYING)
def pause():
print 'pause'
player1.set_state(Gst.State.PAUSED)
pipe.set_state(Gst.State.PAUSED)
GLib.timeout_add(1000, stop)
def dump_dot():
# set GST_DEBUG_DUMP_DOT_DIR env variable to dump the pipeline to a dot file
time.sleep(1)
Gst.debug_bin_to_dot_file(pipe, Gst.DebugGraphDetails.STATES, "stop")
print 'wrote debug output'
def stop():
print 'stop'
threading.Thread(target=dump_dot).start()
player1.props.audio_sink = None
player1.set_state(Gst.State.NULL)
pipe.set_state(Gst.State.NULL)
# Never gets here :(
print 'done'
ml.quit()
GLib.timeout_add(1000, pause)
ml = GObject.MainLoop()
ml.run()
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment