0:00:00.000800200 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31m            GST_INIT gst.c:605:init_pre:[00m Initializing GStreamer Core Library version 0.10.32
0:00:00.001293450 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31m            GST_INIT gst.c:606:init_pre:[00m Using library installed in /usr/lib
0:00:00.001419400 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31m            GST_INIT gst.c:616:init_pre:[00m Linux omap3evm 2.6.37-rc3 #1 Wed Jul 27 09:55:12 IST 2011 armv7l
0:00:00.002174650 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31m            GST_INIT gstquery.c:108:_gst_query_initialize:[00m init queries
0:00:00.009087100 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31m            GST_INIT gstmessage.c:73:_gst_message_initialize:[00m init messages
0:00:00.010776350 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;36m  GST_PLUGIN_LOADING gstplugin.c:350:_gst_plugin_initialize:[00m registering 0 static plugins
0:00:00.011980150 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;36m  GST_PLUGIN_LOADING gstplugin.c:255:gst_plugin_register_static:[00m registered static plugin "staticelements"
0:00:00.012096900 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;36m  GST_PLUGIN_LOADING gstplugin.c:257:gst_plugin_register_static:[00m added static plugin "staticelements", result: 1
0:00:00.014313900 [336m  587[00m    0x16050 [32;01mINFO   [00m [00m        GST_REGISTRY gstregistry.c:1599:ensure_current_registry:[00m reading registry cache: /home/root/.gstreamer-0.10/registry.arm.bin
0:00:00.038938600 [336m  587[00m    0x16050 [32;01mINFO   [00m [00m        GST_REGISTRY gstregistrybinary.c:614:gst_registry_binary_read_cache:[00m loaded /home/root/.gstreamer-0.10/registry.arm.bin in 0.024442 seconds
0:00:00.039263900 [336m  587[00m    0x16050 [32;01mINFO   [00m [00m        GST_REGISTRY gstregistry.c:1469:scan_and_update_registry:[00m Validating plugins from registry cache: /home/root/.gstreamer-0.10/registry.arm.bin
0:00:00.043997150 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;36m  GST_PLUGIN_LOADING gstpluginloader.c:409:gst_plugin_loader_spawn:[00m No gst-plugin-scanner available, or not working

(gst-launch-0.10:587): GStreamer-WARNING **: External plugin loader failed. This most likely means that the plugin loader helper binary was not found or could not be run. 
0:00:00.046426300 [336m  587[00m    0x16050 [33;01mWARN   [00m [00;01;36m  GST_PLUGIN_LOADING gstplugin.c:769:gst_plugin_load_file:[00m module_open failed: libogg.so.0: cannot open shared object file: No such file or directory

(gst-launch-0.10:587): GStreamer-WARNING **: Failed to load plugin '/usr/lib/gstreamer-0.10/libgstogg.so': libogg.so.0: cannot open shared object file: No such file or directory
0:00:00.048140450 [336m  587[00m    0x16050 [33;01mWARN   [00m [00;01;36m  GST_PLUGIN_LOADING gstplugin.c:769:gst_plugin_load_file:[00m module_open failed: libvorbisenc.so.2: cannot open shared object file: No such file or directory

(gst-launch-0.10:587): GStreamer-WARNING **: Failed to load plugin '/usr/lib/gstreamer-0.10/libgstvorbis.so': libvorbisenc.so.2: cannot open shared object file: No such file or directory
0:00:00.048738950 [336m  587[00m    0x16050 [32;01mINFO   [00m [00m        GST_REGISTRY gstregistry.c:1561:scan_and_update_registry:[00m Registry cache has not changed
0:00:00.048839550 [336m  587[00m    0x16050 [32;01mINFO   [00m [00m        GST_REGISTRY gstregistry.c:1628:ensure_current_registry:[00m registry reading and updating done, result = 1
0:00:00.048915100 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31m            GST_INIT gst.c:792:init_post:[00m GLib runtime version: 2.28.0
0:00:00.048995250 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31m            GST_INIT gst.c:794:init_post:[00m GLib headers version: 2.28.0
0:00:00.049267150 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;37;41m        GST_PIPELINE gstparse.c:299:gst_parse_launch_full:[00m parsing pipeline description 'filesrc location=/media/Toss_the_feathers.mp3 ! mad ! audioconvert ! pulsesink latency-time=25000 buffer-time=2000000 '
0:00:00.054868350 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;36m  GST_PLUGIN_LOADING gstplugin.c:859:gst_plugin_load_file:[00m plugin "/usr/lib/gstreamer-0.10/libgstcoreelements.so" loaded
0:00:00.055032950 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;37;41m GST_ELEMENT_FACTORY gstelementfactory.c:371:gst_element_factory_create:[00m creating element "filesrc"
0:00:00.056526800 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;37;41m    GST_ELEMENT_PADS gstelement.c:716:gst_element_add_pad:<GstBaseSrc@0x54000>[00m adding pad 'src'
0:00:00.065246700 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;36m  GST_PLUGIN_LOADING gstplugin.c:859:gst_plugin_load_file:[00m plugin "/usr/lib/gstreamer-0.10/libgstmad.so" loaded
0:00:00.065436850 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;37;41m GST_ELEMENT_FACTORY gstelementfactory.c:371:gst_element_factory_create:[00m creating element "mad"
0:00:00.066969200 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;37;41m    GST_ELEMENT_PADS gstelement.c:716:gst_element_add_pad:<GstMad@0x58d98>[00m adding pad 'sink'
0:00:00.067433600 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;37;41m    GST_ELEMENT_PADS gstelement.c:716:gst_element_add_pad:<GstMad@0x58d98>[00m adding pad 'src'
0:00:00.069406150 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;36m  GST_PLUGIN_LOADING gstplugin.c:859:gst_plugin_load_file:[00m plugin "/usr/lib/gstreamer-0.10/libgstaudioconvert.so" loaded
0:00:00.069537000 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;37;41m GST_ELEMENT_FACTORY gstelementfactory.c:371:gst_element_factory_create:[00m creating element "audioconvert"
0:00:00.071809250 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;37;41m    GST_ELEMENT_PADS gstelement.c:716:gst_element_add_pad:<GstBaseTransform@0x66018>[00m adding pad 'sink'
0:00:00.072119700 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;37;41m    GST_ELEMENT_PADS gstelement.c:716:gst_element_add_pad:<GstBaseTransform@0x66018>[00m adding pad 'src'
0:00:00.089492650 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;36m  GST_PLUGIN_LOADING gstplugin.c:859:gst_plugin_load_file:[00m plugin "/usr/lib/gstreamer-0.10/libgstpulse.so" loaded
0:00:00.089675950 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;37;41m GST_ELEMENT_FACTORY gstelementfactory.c:371:gst_element_factory_create:[00m creating element "pulsesink"
0:00:00.091875200 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;37;41m    GST_ELEMENT_PADS gstelement.c:716:gst_element_add_pad:<GstBaseSink@0x6c008>[00m adding pad 'sink'
0:00:00.093240550 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;37;41m GST_ELEMENT_FACTORY gstelementfactory.c:371:gst_element_factory_create:[00m creating element "pipeline"
0:00:00.094434800 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;37;41m        GST_PIPELINE ./grammar.y:568:gst_parse_perform_link:[00m linking filesrc0:(any) to mad0:(any) (0/0) with caps "(NULL)"
0:00:00.094629350 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;37;41m    GST_ELEMENT_PADS gstutils.c:1568:gst_element_link_pads_full:[00m trying to link element filesrc0:(any) to element mad0:(any)
0:00:00.094750950 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31;41m            GST_PADS gstutils.c:1028:gst_pad_check_link:[00m trying to link filesrc0:src and mad0:sink
0:00:00.094904800 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31;41m            GST_PADS gstutils.c:1468:prepare_link_maybe_ghosting:[00m filesrc0 and mad0 in same bin, no need for ghost pads
0:00:00.095091500 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31;41m            GST_PADS gstpad.c:1941:gst_pad_link_prepare:[00m trying to link filesrc0:src and mad0:sink
0:00:00.095211750 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31;41m            GST_PADS gstpad.c:2124:gst_pad_link_full:[00m linked filesrc0:src and mad0:sink, successful
0:00:00.095484600 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;37;41m        GST_PIPELINE ./grammar.y:568:gst_parse_perform_link:[00m linking mad0:(any) to audioconvert0:(any) (0/0) with caps "(NULL)"
0:00:00.095600150 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;37;41m    GST_ELEMENT_PADS gstutils.c:1568:gst_element_link_pads_full:[00m trying to link element mad0:(any) to element audioconvert0:(any)
0:00:00.095701950 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31;41m            GST_PADS gstutils.c:1028:gst_pad_check_link:[00m trying to link mad0:src and audioconvert0:sink
0:00:00.096231450 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31;41m            GST_PADS gstutils.c:1468:prepare_link_maybe_ghosting:[00m mad0 and audioconvert0 in same bin, no need for ghost pads
0:00:00.096383900 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31;41m            GST_PADS gstpad.c:1941:gst_pad_link_prepare:[00m trying to link mad0:src and audioconvert0:sink
0:00:00.096727700 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31;41m            GST_PADS gstpad.c:2124:gst_pad_link_full:[00m linked mad0:src and audioconvert0:sink, successful
0:00:00.096903950 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;37;41m        GST_PIPELINE ./grammar.y:568:gst_parse_perform_link:[00m linking audioconvert0:(any) to pulsesink0:(any) (0/0) with caps "(NULL)"
0:00:00.097012200 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;37;41m    GST_ELEMENT_PADS gstutils.c:1568:gst_element_link_pads_full:[00m trying to link element audioconvert0:(any) to element pulsesink0:(any)
0:00:00.097113300 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31;41m            GST_PADS gstutils.c:1028:gst_pad_check_link:[00m trying to link audioconvert0:src and pulsesink0:sink
0:00:00.100113700 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31;41m            GST_PADS gstutils.c:1468:prepare_link_maybe_ghosting:[00m audioconvert0 and pulsesink0 in same bin, no need for ghost pads
0:00:00.100278400 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31;41m            GST_PADS gstpad.c:1941:gst_pad_link_prepare:[00m trying to link audioconvert0:src and pulsesink0:sink
0:00:00.103000150 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31;41m            GST_PADS gstpad.c:2124:gst_pad_link_full:[00m linked audioconvert0:src and pulsesink0:sink, successful
Setting pipeline to PAUSED ...
0:00:00.108605450 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31m          GST_STATES gstelement.c:2341:gst_element_continue_state:<pulsesink0>[00m completed state change to READY
0:00:00.108766300 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31m          GST_STATES gstelement.c:2354:gst_element_continue_state:<pulsesink0>[00m posting state-changed NULL to READY
0:00:00.109047900 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31m          GST_STATES gstbin.c:2492:gst_bin_change_state_func:<pipeline0>[00m child 'pulsesink0' changed state to 2(READY) successfully
0:00:00.109206000 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31m          GST_STATES gstelement.c:2341:gst_element_continue_state:<audioconvert0>[00m completed state change to READY
0:00:00.109302500 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31m          GST_STATES gstelement.c:2354:gst_element_continue_state:<audioconvert0>[00m posting state-changed NULL to READY
0:00:00.109435900 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31m          GST_STATES gstbin.c:2492:gst_bin_change_state_func:<pipeline0>[00m child 'audioconvert0' changed state to 2(READY) successfully
0:00:00.109564500 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31m          GST_STATES gstelement.c:2341:gst_element_continue_state:<mad0>[00m completed state change to READY
0:00:00.109658450 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31m          GST_STATES gstelement.c:2354:gst_element_continue_state:<mad0>[00m posting state-changed NULL to READY
0:00:00.109875750 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31m          GST_STATES gstbin.c:2492:gst_bin_change_state_func:<pipeline0>[00m child 'mad0' changed state to 2(READY) successfully
0:00:00.110015100 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31m          GST_STATES gstelement.c:2341:gst_element_continue_state:<filesrc0>[00m completed state change to READY
0:00:00.110110050 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31m          GST_STATES gstelement.c:2354:gst_element_continue_state:<filesrc0>[00m posting state-changed NULL to READY
0:00:00.110268650 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31m          GST_STATES gstbin.c:2492:gst_bin_change_state_func:<pipeline0>[00m child 'filesrc0' changed state to 2(READY) successfully
0:00:00.110415800 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31m          GST_STATES gstelement.c:2314:gst_element_continue_state:<pipeline0>[00m committing state from NULL to READY, pending PAUSED, next PAUSED
0:00:00.110691100 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31m          GST_STATES gstelement.c:2323:gst_element_continue_state:<pipeline0>[00m continue state change READY to PAUSED, final PAUSED
0:00:00.111093450 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31m          GST_STATES gstbin.c:2498:gst_bin_change_state_func:<pipeline0>[00m child 'pulsesink0' is changing state asynchronously to PAUSED
0:00:00.111267000 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31m          GST_STATES gstelement.c:2341:gst_element_continue_state:<audioconvert0>[00m completed state change to PAUSED
0:00:00.111359550 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31m          GST_STATES gstelement.c:2354:gst_element_continue_state:<audioconvert0>[00m posting state-changed READY to PAUSED
0:00:00.111485800 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31m          GST_STATES gstbin.c:2492:gst_bin_change_state_func:<pipeline0>[00m child 'audioconvert0' changed state to 3(PAUSED) successfully
0:00:00.111708100 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31m          GST_STATES gstelement.c:2341:gst_element_continue_state:<mad0>[00m completed state change to PAUSED
0:00:00.111805000 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31m          GST_STATES gstelement.c:2354:gst_element_continue_state:<mad0>[00m posting state-changed READY to PAUSED
0:00:00.111932400 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31m          GST_STATES gstbin.c:2492:gst_bin_change_state_func:<pipeline0>[00m child 'mad0' changed state to 3(PAUSED) successfully
0:00:00.112083150 [336m  587[00m    0x16050 [32;01mINFO   [00m [00m             filesrc gstfilesrc.c:963:gst_file_src_start:<filesrc0>[00m opening file /media/Toss_the_feathers.mp3
0:00:00.112301750 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;34m           GST_EVENT gstevent.c:606:gst_event_new_new_segment_full:[00m creating newsegment update 0, rate 1.000000, format bytes, start 0, stop 4823040, position 0
0:00:00.113080600 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31m          GST_STATES gstelement.c:2341:gst_element_continue_state:<filesrc0>[00m completed state change to PAUSED
0:00:00.113250800 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31m          GST_STATES gstelement.c:2354:gst_element_continue_state:<filesrc0>[00m posting state-changed READY to PAUSED
0:00:00.113392600 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31m          GST_STATES gstbin.c:2492:gst_bin_change_state_func:<pipeline0>[00m child 'filesrc0' changed state to 3(PAUSED) successfully
Pipeline is PREROLLING ...
0:00:00.114394850 [336m  587[00m    0x742c8 [33;01mWARN   [00m [00m                 mad gstmad.c:1365:gst_mad_chain:[00m mad_header_decode had an error: lost synchronization
0:00:00.114606250 [336m  587[00m    0x742c8 [33;01mWARN   [00m [00m                 mad gstmad.c:1392:gst_mad_chain:[00m mad_frame_decode had an error: reserved sample frequency value
0:00:00.114780550 [336m  587[00m    0x742c8 [33;01mWARN   [00m [00m                 mad gstmad.c:1365:gst_mad_chain:[00m mad_header_decode had an error: lost synchronization
0:00:00.114870500 [336m  587[00m    0x742c8 [33;01mWARN   [00m [00m                 mad gstmad.c:1392:gst_mad_chain:[00m mad_frame_decode had an error: reserved sample frequency value
0:00:00.114968200 [336m  587[00m    0x742c8 [33;01mWARN   [00m [00m                 mad gstmad.c:1365:gst_mad_chain:[00m mad_header_decode had an error: lost synchronization
0:00:00.115048050 [336m  587[00m    0x742c8 [33;01mWARN   [00m [00m                 mad gstmad.c:1392:gst_mad_chain:[00m mad_frame_decode had an error: reserved sample frequency value
0:00:00.115143000 [336m  587[00m    0x742c8 [33;01mWARN   [00m [00m                 mad gstmad.c:1365:gst_mad_chain:[00m mad_header_decode had an error: lost synchronization
0:00:00.115220850 [336m  587[00m    0x742c8 [33;01mWARN   [00m [00m                 mad gstmad.c:1392:gst_mad_chain:[00m mad_frame_decode had an error: reserved sample frequency value
0:00:00.115314050 [336m  587[00m    0x742c8 [33;01mWARN   [00m [00m                 mad gstmad.c:1365:gst_mad_chain:[00m mad_header_decode had an error: lost synchronization
0:00:00.115391700 [336m  587[00m    0x742c8 [33;01mWARN   [00m [00m                 mad gstmad.c:1392:gst_mad_chain:[00m mad_frame_decode had an error: reserved sample frequency value
0:00:00.115485100 [336m  587[00m    0x742c8 [33;01mWARN   [00m [00m                 mad gstmad.c:1365:gst_mad_chain:[00m mad_header_decode had an error: lost synchronization
0:00:00.115558050 [336m  587[00m    0x742c8 [33;01mWARN   [00m [00m                 mad gstmad.c:1392:gst_mad_chain:[00m mad_frame_decode had an error: reserved sample frequency value
0:00:00.115651600 [336m  587[00m    0x742c8 [33;01mWARN   [00m [00m                 mad gstmad.c:1365:gst_mad_chain:[00m mad_header_decode had an error: lost synchronization
0:00:00.117278900 [336m  587[00m    0x742c8 [32;01mINFO   [00m [00;01;34m           GST_EVENT gstevent.c:600:gst_event_new_new_segment_full:[00m creating newsegment update 0, rate 1.000000, format GST_FORMAT_TIME, start 0:00:00.000000000, stop 99:99:99.999999999, position 0:00:00.000000000
0:00:00.123358650 [336m  587[00m    0x742c8 [32;01mINFO   [00m [00m       basetransform gstbasetransform.c:1148:gst_base_transform_setcaps:<audioconvert0>[00m reuse caps
0:00:00.123707400 [336m  587[00m    0x742c8 [32;01mINFO   [00m [00m        audioconvert audioconvert.c:655:audio_convert_prepare_context:[00m use int mixing
0:00:00.125715300 [336m  587[00m    0x742c8 [32;01mINFO   [00m [00m        audioconvert audioconvert.c:661:audio_convert_prepare_context:[00m unitsizes: 4 -> 4
0:00:00.125806600 [336m  587[00m    0x742c8 [32;01mINFO   [00m [00m        audioconvert audioconvert.c:671:audio_convert_prepare_context:[00m in default 0, mix passthrough 1, out default 0
0:00:00.132338250 [336m  587[00m    0x742c8 [32;01mINFO   [00m [00;01;31m          GST_STATES gstbin.c:2905:bin_handle_async_done:<pipeline0>[00m committing state from READY to PAUSED, old pending PAUSED
0:00:00.132502750 [336m  587[00m    0x742c8 [32;01mINFO   [00m [00;01;31m          GST_STATES gstbin.c:2925:bin_handle_async_done:<pipeline0>[00m completed state change, pending VOID
Pipeline is PREROLLED ...
Setting pipeline to PLAYING ...
0:00:00.134147750 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;34m           GST_EVENT gstevent.c:1068:gst_event_new_latency:[00m creating latency event 0:00:00.000000000
0:00:00.134383500 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01m                 bin gstbin.c:2368:gst_bin_do_latency_func:<pipeline0>[00m configured latency of 0:00:00.000000000
0:00:00.143830400 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31m          GST_STATES gstelement.c:2341:gst_element_continue_state:<pulsesink0>[00m completed state change to PLAYING
0:00:00.144078500 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31m          GST_STATES gstelement.c:2354:gst_element_continue_state:<pulsesink0>[00m posting state-changed PAUSED to PLAYING
0:00:00.144239550 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31m          GST_STATES gstbin.c:2492:gst_bin_change_state_func:<pipeline0>[00m child 'pulsesink0' changed state to 4(PLAYING) successfully
0:00:00.144381550 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31m          GST_STATES gstelement.c:2341:gst_element_continue_state:<audioconvert0>[00m completed state change to PLAYING
0:00:00.144474650 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31m          GST_STATES gstelement.c:2354:gst_element_continue_state:<audioconvert0>[00m posting state-changed PAUSED to PLAYING
0:00:00.144602100 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31m          GST_STATES gstbin.c:2492:gst_bin_change_state_func:<pipeline0>[00m child 'audioconvert0' changed state to 4(PLAYING) successfully
0:00:00.144724900 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31m          GST_STATES gstelement.c:2341:gst_element_continue_state:<mad0>[00m completed state change to PLAYING
0:00:00.144816150 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31m          GST_STATES gstelement.c:2354:gst_element_continue_state:<mad0>[00m posting state-changed PAUSED to PLAYING
0:00:00.144943600 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31m          GST_STATES gstbin.c:2492:gst_bin_change_state_func:<pipeline0>[00m child 'mad0' changed state to 4(PLAYING) successfully
0:00:00.145055650 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31m          GST_STATES gstelement.c:2341:gst_element_continue_state:<filesrc0>[00m completed state change to PLAYING
0:00:00.145143750 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31m          GST_STATES gstelement.c:2354:gst_element_continue_state:<filesrc0>[00m posting state-changed PAUSED to PLAYING
0:00:00.145267800 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31m          GST_STATES gstbin.c:2492:gst_bin_change_state_func:<pipeline0>[00m child 'filesrc0' changed state to 4(PLAYING) successfully
0:00:00.145384300 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31m          GST_STATES gstelement.c:2341:gst_element_continue_state:<pipeline0>[00m completed state change to PLAYING
0:00:00.145474200 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31m          GST_STATES gstelement.c:2354:gst_element_continue_state:<pipeline0>[00m posting state-changed PAUSED to PLAYING
New clock: GstAudioSinkClock
Caught interrupt -- handling interrupt.
Interrupt: Stopping pipeline ...
Execution ended after 17318851249 ns.
Setting pipeline to PAUSED ...
0:00:17.469248249 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31m          GST_STATES gstbin.c:2498:gst_bin_change_state_func:<pipeline0>[00m child 'pulsesink0' is changing state asynchronously to PAUSED
0:00:17.469485649 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31m          GST_STATES gstelement.c:2341:gst_element_continue_state:<audioconvert0>[00m completed state change to PAUSED
0:00:17.469589499 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31m          GST_STATES gstelement.c:2354:gst_element_continue_state:<audioconvert0>[00m posting state-changed PLAYING to PAUSED
0:00:17.469729499 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31m          GST_STATES gstbin.c:2492:gst_bin_change_state_func:<pipeline0>[00m child 'audioconvert0' changed state to 3(PAUSED) successfully
0:00:17.469855699 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31m          GST_STATES gstelement.c:2341:gst_element_continue_state:<mad0>[00m completed state change to PAUSED
0:00:17.469947299 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31m          GST_STATES gstelement.c:2354:gst_element_continue_state:<mad0>[00m posting state-changed PLAYING to PAUSED
0:00:17.470072999 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31m          GST_STATES gstbin.c:2492:gst_bin_change_state_func:<pipeline0>[00m child 'mad0' changed state to 3(PAUSED) successfully
0:00:17.470298799 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31m          GST_STATES gstelement.c:2341:gst_element_continue_state:<filesrc0>[00m completed state change to PAUSED
0:00:17.470396649 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31m          GST_STATES gstelement.c:2354:gst_element_continue_state:<filesrc0>[00m posting state-changed PLAYING to PAUSED
0:00:17.470527749 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31m          GST_STATES gstbin.c:2492:gst_bin_change_state_func:<pipeline0>[00m child 'filesrc0' changed state to 3(PAUSED) successfully
Setting pipeline to READY ...
0:00:17.475419549 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31m          GST_STATES gstelement.c:2341:gst_element_continue_state:<pulsesink0>[00m completed state change to READY
0:00:17.475577399 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31m          GST_STATES gstelement.c:2354:gst_element_continue_state:<pulsesink0>[00m posting state-changed PLAYING to READY
0:00:17.475729599 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31m          GST_STATES gstbin.c:2492:gst_bin_change_state_func:<pipeline0>[00m child 'pulsesink0' changed state to 2(READY) successfully
0:00:17.476039749 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31m          GST_STATES gstelement.c:2341:gst_element_continue_state:<audioconvert0>[00m completed state change to READY
0:00:17.476139399 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31m          GST_STATES gstelement.c:2354:gst_element_continue_state:<audioconvert0>[00m posting state-changed PAUSED to READY
0:00:17.476271099 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31m          GST_STATES gstbin.c:2492:gst_bin_change_state_func:<pipeline0>[00m child 'audioconvert0' changed state to 2(READY) successfully
0:00:17.479329299 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31m          GST_STATES gstelement.c:2341:gst_element_continue_state:<mad0>[00m completed state change to READY
0:00:17.479462799 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31m          GST_STATES gstelement.c:2354:gst_element_continue_state:<mad0>[00m posting state-changed PAUSED to READY
0:00:17.479602099 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31m          GST_STATES gstbin.c:2492:gst_bin_change_state_func:<pipeline0>[00m child 'mad0' changed state to 2(READY) successfully
0:00:17.479770499 [336m  587[00m    0x742c8 [32;01mINFO   [00m [00m             basesrc gstbasesrc.c:2511:gst_base_src_loop:<filesrc0>[00m pausing after gst_pad_push() = wrong-state
0:00:17.480069749 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;34m           GST_EVENT gstpad.c:5406:gst_pad_send_event:<mad0:sink>[00m Received event on flushing pad. Discarding
0:00:17.480233699 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31m          GST_STATES gstelement.c:2341:gst_element_continue_state:<filesrc0>[00m completed state change to READY
0:00:17.480324949 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31m          GST_STATES gstelement.c:2354:gst_element_continue_state:<filesrc0>[00m posting state-changed PAUSED to READY
0:00:17.480453299 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31m          GST_STATES gstbin.c:2492:gst_bin_change_state_func:<pipeline0>[00m child 'filesrc0' changed state to 2(READY) successfully
0:00:17.480596399 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31m          GST_STATES gstelement.c:2341:gst_element_continue_state:<pipeline0>[00m completed state change to READY
0:00:17.480688699 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31m          GST_STATES gstelement.c:2354:gst_element_continue_state:<pipeline0>[00m posting state-changed PLAYING to READY
0:00:17.480922799 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31m          GST_STATES gstbin.c:1759:gst_bin_get_state_func:<pipeline0>[00m getting state
Setting pipeline to NULL ...
0:00:17.484459949 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31m          GST_STATES gstelement.c:2341:gst_element_continue_state:<pulsesink0>[00m completed state change to NULL
0:00:17.484600449 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31m          GST_STATES gstelement.c:2354:gst_element_continue_state:<pulsesink0>[00m posting state-changed READY to NULL
0:00:17.484749899 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31m          GST_STATES gstbin.c:2492:gst_bin_change_state_func:<pipeline0>[00m child 'pulsesink0' changed state to 1(NULL) successfully
0:00:17.484923899 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31m          GST_STATES gstelement.c:2341:gst_element_continue_state:<audioconvert0>[00m completed state change to NULL
0:00:17.485016799 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31m          GST_STATES gstelement.c:2354:gst_element_continue_state:<audioconvert0>[00m posting state-changed READY to NULL
0:00:17.485141899 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31m          GST_STATES gstbin.c:2492:gst_bin_change_state_func:<pipeline0>[00m child 'audioconvert0' changed state to 1(NULL) successfully
0:00:17.485301349 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31m          GST_STATES gstelement.c:2341:gst_element_continue_state:<mad0>[00m completed state change to NULL
0:00:17.485393599 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31m          GST_STATES gstelement.c:2354:gst_element_continue_state:<mad0>[00m posting state-changed READY to NULL
0:00:17.485520449 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31m          GST_STATES gstbin.c:2492:gst_bin_change_state_func:<pipeline0>[00m child 'mad0' changed state to 1(NULL) successfully
0:00:17.485656199 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31m          GST_STATES gstelement.c:2341:gst_element_continue_state:<filesrc0>[00m completed state change to NULL
0:00:17.485747749 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31m          GST_STATES gstelement.c:2354:gst_element_continue_state:<filesrc0>[00m posting state-changed READY to NULL
0:00:17.485874049 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31m          GST_STATES gstbin.c:2492:gst_bin_change_state_func:<pipeline0>[00m child 'filesrc0' changed state to 1(NULL) successfully
0:00:17.486326599 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31m          GST_STATES gstelement.c:2341:gst_element_continue_state:<pipeline0>[00m completed state change to NULL
0:00:17.486427949 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31m          GST_STATES gstelement.c:2354:gst_element_continue_state:<pipeline0>[00m posting state-changed READY to NULL
0:00:17.486559099 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31m          GST_STATES gstbin.c:1759:gst_bin_get_state_func:<pipeline0>[00m getting state
Freeing pipeline ...
0:00:17.486782199 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;37;41m    GST_ELEMENT_PADS gstpad.c:1713:gst_pad_unlink:[00m unlinking audioconvert0:src(0x53328) and pulsesink0:sink(0x533f0)
0:00:17.486944799 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;37;41m    GST_ELEMENT_PADS gstpad.c:1758:gst_pad_unlink:[00m unlinked audioconvert0:src and pulsesink0:sink
0:00:17.487137099 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;37;41m       GST_PARENTAGE gstbin.c:1440:gst_bin_remove_func:<pipeline0>[00m removed child "pulsesink0"
0:00:17.487438899 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31;44m     GST_REFCOUNTING gstelement.c:2955:gst_element_dispose:<pulsesink0>[00m dispose
0:00:17.487548199 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;37;41m    GST_ELEMENT_PADS gstelement.c:835:gst_element_remove_pad:<pulsesink0>[00m removing pad 'sink'
0:00:17.487706149 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31;44m     GST_REFCOUNTING gstelement.c:2979:gst_element_dispose:<pulsesink0>[00m parent class dispose
0:00:17.488195949 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31;44m     GST_REFCOUNTING gstelement.c:3010:gst_element_finalize:<pulsesink0>[00m finalize
0:00:17.488320249 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31;44m     GST_REFCOUNTING gstelement.c:3021:gst_element_finalize:<pulsesink0>[00m finalize parent
0:00:17.488434699 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;37;41m    GST_ELEMENT_PADS gstpad.c:1713:gst_pad_unlink:[00m unlinking mad0:src(0x53198) and audioconvert0:sink(0x53260)
0:00:17.488591099 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;37;41m    GST_ELEMENT_PADS gstpad.c:1758:gst_pad_unlink:[00m unlinked mad0:src and audioconvert0:sink
0:00:17.488777799 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;37;41m       GST_PARENTAGE gstbin.c:1440:gst_bin_remove_func:<pipeline0>[00m removed child "audioconvert0"
0:00:17.488922849 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31;44m     GST_REFCOUNTING gstelement.c:2955:gst_element_dispose:<audioconvert0>[00m dispose
0:00:17.489014599 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;37;41m    GST_ELEMENT_PADS gstelement.c:835:gst_element_remove_pad:<audioconvert0>[00m removing pad 'src'
0:00:17.489143149 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;37;41m    GST_ELEMENT_PADS gstelement.c:835:gst_element_remove_pad:<audioconvert0>[00m removing pad 'sink'
0:00:17.489271749 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31;44m     GST_REFCOUNTING gstelement.c:2979:gst_element_dispose:<audioconvert0>[00m parent class dispose
0:00:17.489374349 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31;44m     GST_REFCOUNTING gstelement.c:3010:gst_element_finalize:<audioconvert0>[00m finalize
0:00:17.489468599 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31;44m     GST_REFCOUNTING gstelement.c:3021:gst_element_finalize:<audioconvert0>[00m finalize parent
0:00:17.489574149 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;37;41m    GST_ELEMENT_PADS gstpad.c:1713:gst_pad_unlink:[00m unlinking filesrc0:src(0x53008) and mad0:sink(0x530d0)
0:00:17.489716749 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;37;41m    GST_ELEMENT_PADS gstpad.c:1758:gst_pad_unlink:[00m unlinked filesrc0:src and mad0:sink
0:00:17.489893399 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;37;41m       GST_PARENTAGE gstbin.c:1440:gst_bin_remove_func:<pipeline0>[00m removed child "mad0"
0:00:17.490026149 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31;44m     GST_REFCOUNTING gstelement.c:2955:gst_element_dispose:<mad0>[00m dispose
0:00:17.490118349 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;37;41m    GST_ELEMENT_PADS gstelement.c:835:gst_element_remove_pad:<mad0>[00m removing pad 'src'
0:00:17.490278699 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;37;41m    GST_ELEMENT_PADS gstelement.c:835:gst_element_remove_pad:<mad0>[00m removing pad 'sink'
0:00:17.490435799 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31;44m     GST_REFCOUNTING gstelement.c:2979:gst_element_dispose:<mad0>[00m parent class dispose
0:00:17.490535549 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31;44m     GST_REFCOUNTING gstelement.c:3010:gst_element_finalize:<mad0>[00m finalize
0:00:17.490629749 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31;44m     GST_REFCOUNTING gstelement.c:3021:gst_element_finalize:<mad0>[00m finalize parent
0:00:17.490745649 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;37;41m       GST_PARENTAGE gstbin.c:1440:gst_bin_remove_func:<pipeline0>[00m removed child "filesrc0"
0:00:17.490892299 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31;44m     GST_REFCOUNTING gstelement.c:2955:gst_element_dispose:<filesrc0>[00m dispose
0:00:17.490985449 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;37;41m    GST_ELEMENT_PADS gstelement.c:835:gst_element_remove_pad:<filesrc0>[00m removing pad 'src'
0:00:17.491161449 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31;44m     GST_REFCOUNTING gstelement.c:2979:gst_element_dispose:<filesrc0>[00m parent class dispose
0:00:17.491272049 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31;44m     GST_REFCOUNTING gstelement.c:3010:gst_element_finalize:<filesrc0>[00m finalize
0:00:17.491368249 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31;44m     GST_REFCOUNTING gstelement.c:3021:gst_element_finalize:<filesrc0>[00m finalize parent
0:00:17.491466849 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31;44m     GST_REFCOUNTING gstelement.c:2955:gst_element_dispose:<pipeline0>[00m dispose
0:00:17.491598399 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31;44m     GST_REFCOUNTING gstelement.c:2979:gst_element_dispose:<pipeline0>[00m parent class dispose
0:00:17.491696149 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31;44m     GST_REFCOUNTING gstelement.c:3010:gst_element_finalize:<pipeline0>[00m finalize
0:00:17.491790049 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31;44m     GST_REFCOUNTING gstelement.c:3021:gst_element_finalize:<pipeline0>[00m finalize parent
0:00:17.491888149 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31m            GST_INIT gst.c:1010:gst_deinit:[00m deinitializing GStreamer
0:00:17.496883099 [336m  587[00m    0x16050 [32;01mINFO   [00m [00;01;31m            GST_INIT gst.c:1113:gst_deinit:[00m deinitialized GStreamer
