xpra icon
Bug tracker and wiki

Ticket #1275: autoaudiosink-err.txt

File autoaudiosink-err.txt, 31.2 KB (added by Antoine Martin, 4 years ago)

sound error with wheezy client

Line 
12016-08-06 08:17:05,697 sound output safe_exec(['which', 'pactl'])=(0, '/usr/bin/pactl\n')
22016-08-06 08:17:05,697 sound output is_pa_installed() pactl_bin=/usr/bin/pactl
32016-08-06 08:17:05,697 sound output get_default_sink() no pulsesink: cannot import name get_pactl_server
42016-08-06 08:17:05,697 sound output SoundSink(..) found matching codecs ['wav']
52016-08-06 08:17:05,698 sound output pipeline elements=['appsrc do-timestamp=1 name=src emit-signals=0 block=0 is-live=0 stream-type=0 format=4', 'wavparse', 'audioconvert', 'audioresample', 'volume name=volume volume=0', 'queue name=queue min-threshold-time=0 max-size-buffers=0 max-size-bytes=0 max-size-time=450000000 leaky=2', 'autoaudiosink async=True qos=True sync=False']
62016-08-06 08:17:05,698 sound output pipeline=appsrc do-timestamp=1 name=src emit-signals=0 block=0 is-live=0 stream-type=0 format=4 ! wavparse ! audioconvert ! audioresample ! volume name=volume volume=0 ! queue name=queue min-threshold-time=0 max-size-buffers=0 max-size-bytes=0 max-size-time=450000000 leaky=2 ! autoaudiosink async=True qos=True sync=False
70:00:00.050868183 12228  0x8c55420 INFO            GST_PIPELINE gstparse.c:334:gst_parse_launch_full: parsing pipeline description 'appsrc do-timestamp=1 name=src emit-signals=0 block=0 is-live=0 stream-type=0 format=4 ! wavparse ! audioconvert ! audioresample ! volume name=volume volume=0 ! queue name=queue min-threshold-time=0 max-size-buffers=0 max-size-bytes=0 max-size-time=450000000 leaky=2 ! autoaudiosink async=True qos=True sync=False'
80:00:00.051227352 12228  0x8c55420 INFO      GST_PLUGIN_LOADING gstplugin.c:859:gst_plugin_load_file: plugin "/usr/lib/i386-linux-gnu/gstreamer-0.10/libgstapp.so" loaded
90:00:00.051238896 12228  0x8c55420 INFO     GST_ELEMENT_FACTORY gstelementfactory.c:376:gst_element_factory_create: creating element "appsrc"
100:00:00.051410992 12228  0x8c55420 INFO        GST_ELEMENT_PADS gstelement.c:728:gst_element_add_pad:<GstBaseSrc@0x914a018> adding pad 'src'
110:00:00.052043995 12228  0x8c55420 INFO      GST_PLUGIN_LOADING gstplugin.c:859:gst_plugin_load_file: plugin "/usr/lib/i386-linux-gnu/gstreamer-0.10/libgstwavparse.so" loaded
120:00:00.052052290 12228  0x8c55420 INFO     GST_ELEMENT_FACTORY gstelementfactory.c:376:gst_element_factory_create: creating element "wavparse"
130:00:00.052204528 12228  0x8c55420 INFO        GST_ELEMENT_PADS gstelement.c:728:gst_element_add_pad:<GstWavParse@0x914f008> adding pad 'sink'
140:00:00.065793697 12228  0x8c55420 INFO      GST_PLUGIN_LOADING gstplugin.c:859:gst_plugin_load_file: plugin "/usr/lib/i386-linux-gnu/gstreamer-0.10/libgstaudioconvert.so" loaded
150:00:00.065864540 12228  0x8c55420 INFO     GST_ELEMENT_FACTORY gstelementfactory.c:376:gst_element_factory_create: creating element "audioconvert"
160:00:00.066020217 12228  0x8c55420 INFO        GST_ELEMENT_PADS gstelement.c:728:gst_element_add_pad:<GstBaseTransform@0x914a288> adding pad 'sink'
170:00:00.066065933 12228  0x8c55420 INFO        GST_ELEMENT_PADS gstelement.c:728:gst_element_add_pad:<GstBaseTransform@0x914a288> adding pad 'src'
180:00:00.066892582 12228  0x8c55420 INFO           audioresample gstaudioresample.c:1557:_benchmark_integer_resampling: Using integer resampler if appropriate: 63565.444444 < 111842.750000
190:00:00.066941992 12228  0x8c55420 INFO      GST_PLUGIN_LOADING gstplugin.c:859:gst_plugin_load_file: plugin "/usr/lib/i386-linux-gnu/gstreamer-0.10/libgstaudioresample.so" loaded
200:00:00.066974036 12228  0x8c55420 INFO     GST_ELEMENT_FACTORY gstelementfactory.c:376:gst_element_factory_create: creating element "audioresample"
210:00:00.067075808 12228  0x8c55420 INFO        GST_ELEMENT_PADS gstelement.c:728:gst_element_add_pad:<GstBaseTransform@0x928a138> adding pad 'sink'
220:00:00.067118625 12228  0x8c55420 INFO        GST_ELEMENT_PADS gstelement.c:728:gst_element_add_pad:<GstBaseTransform@0x928a138> adding pad 'src'
230:00:00.069416854 12228  0x8c55420 INFO      GST_PLUGIN_LOADING gstplugin.c:859:gst_plugin_load_file: plugin "/usr/lib/i386-linux-gnu/gstreamer-0.10/libgstvolume.so" loaded
240:00:00.069462413 12228  0x8c55420 INFO     GST_ELEMENT_FACTORY gstelementfactory.c:376:gst_element_factory_create: creating element "volume"
250:00:00.069604765 12228  0x8c55420 INFO        GST_ELEMENT_PADS gstelement.c:728:gst_element_add_pad:<GstBaseTransform@0x92f60f8> adding pad 'sink'
260:00:00.069651406 12228  0x8c55420 INFO        GST_ELEMENT_PADS gstelement.c:728:gst_element_add_pad:<GstBaseTransform@0x92f60f8> adding pad 'src'
270:00:00.069995207 12228  0x8c55420 INFO      GST_PLUGIN_LOADING gstplugin.c:859:gst_plugin_load_file: plugin "/usr/lib/i386-linux-gnu/gstreamer-0.10/libgstcoreelements.so" loaded
280:00:00.070187098 12228  0x8c55420 INFO     GST_ELEMENT_FACTORY gstelementfactory.c:376:gst_element_factory_create: creating element "queue"
290:00:00.070300888 12228  0x8c55420 INFO        GST_ELEMENT_PADS gstelement.c:728:gst_element_add_pad:<GstQueue@0x92f8100> adding pad 'sink'
300:00:00.070348398 12228  0x8c55420 INFO        GST_ELEMENT_PADS gstelement.c:728:gst_element_add_pad:<GstQueue@0x92f8100> adding pad 'src'
310:00:00.096678281 12228  0x8c55420 INFO      GST_PLUGIN_LOADING gstplugin.c:859:gst_plugin_load_file: plugin "/usr/lib/i386-linux-gnu/gstreamer-0.10/libgstautodetect.so" loaded
320:00:00.096734641 12228  0x8c55420 INFO     GST_ELEMENT_FACTORY gstelementfactory.c:376:gst_element_factory_create: creating element "autoaudiosink"
330:00:00.096852487 12228  0x8c55420 INFO        GST_ELEMENT_PADS gstelement.c:728:gst_element_add_pad:<GstAutoAudioSink@0x92fa000> adding pad 'sink'
340:00:00.096891468 12228  0x8c55420 INFO     GST_ELEMENT_FACTORY gstelementfactory.c:374:gst_element_factory_create: creating element "fakesink" named "tempsink"
350:00:00.115465945 12228  0x8c55420 INFO        GST_ELEMENT_PADS gstelement.c:728:gst_element_add_pad:<GstBaseSink@0x92fe1a8> adding pad 'sink'
360:00:00.115508862 12228  0x8c55420 INFO        GST_ELEMENT_PADS gstelement.c:975:gst_element_get_static_pad: found pad tempsink:sink
370:00:00.115518549 12228  0x8c55420 INFO                GST_PADS gstpad.c:1978:gst_pad_link_prepare: trying to link sink:proxypad0 and tempsink:sink
380:00:00.115527019 12228  0x8c55420 INFO                GST_PADS gstpad.c:2161:gst_pad_link_full: linked sink:proxypad0 and tempsink:sink, successful
390:00:00.115543860 12228  0x8c55420 INFO                 default gstchildproxy.c:209:gst_child_proxy_lookup: no param spec named async
400:00:00.115555540 12228  0x8c55420 INFO           GST_PARENTAGE gstbin.c:3762:gst_bin_get_by_name: [autoaudiosink0]: looking up child element async
410:00:00.115565965 12228  0x8c55420 INFO                 default gstchildproxy.c:209:gst_child_proxy_lookup: no param spec named qos
420:00:00.115573037 12228  0x8c55420 INFO           GST_PARENTAGE gstbin.c:3762:gst_bin_get_by_name: [autoaudiosink0]: looking up child element qos
430:00:00.115580876 12228  0x8c55420 INFO                 default gstchildproxy.c:209:gst_child_proxy_lookup: no param spec named sync
440:00:00.115587188 12228  0x8c55420 INFO           GST_PARENTAGE gstbin.c:3762:gst_bin_get_by_name: [autoaudiosink0]: looking up child element sync
450:00:00.115604242 12228  0x8c55420 INFO     GST_ELEMENT_FACTORY gstelementfactory.c:376:gst_element_factory_create: creating element "pipeline"
460:00:00.115658820 12228  0x8c55420 INFO            GST_PIPELINE ./grammar.y:568:gst_parse_perform_link: linking src:(any) to wavparse0:(any) (0/0) with caps "(NULL)"
470:00:00.115671266 12228  0x8c55420 INFO        GST_ELEMENT_PADS gstutils.c:1698:gst_element_link_pads_full: trying to link element src:(any) to element wavparse0:(any)
480:00:00.115678868 12228  0x8c55420 INFO                GST_PADS gstutils.c:1032:gst_pad_check_link: trying to link src:src and wavparse0:sink
490:00:00.115691477 12228  0x8c55420 INFO                GST_PADS gstutils.c:1596:prepare_link_maybe_ghosting: src and wavparse0 in same bin, no need for ghost pads
500:00:00.115702801 12228  0x8c55420 INFO                GST_PADS gstpad.c:1978:gst_pad_link_prepare: trying to link src:src and wavparse0:sink
510:00:00.115709972 12228  0x8c55420 INFO                GST_PADS gstpad.c:2161:gst_pad_link_full: linked src:src and wavparse0:sink, successful
520:00:00.115721448 12228  0x8c55420 INFO            GST_PIPELINE ./grammar.y:568:gst_parse_perform_link: linking wavparse0:(any) to audioconvert0:(any) (0/0) with caps "(NULL)"
530:00:00.115728744 12228  0x8c55420 INFO        GST_ELEMENT_PADS gstutils.c:1698:gst_element_link_pads_full: trying to link element wavparse0:(any) to element audioconvert0:(any)
540:00:00.116080528 12228  0x8c55420 INFO        GST_ELEMENT_PADS gstelement.c:972:gst_element_get_static_pad: no such pad 'wavparse_src' in element "wavparse0"
550:00:00.116096899 12228  0x8c55420 INFO        GST_ELEMENT_PADS gstutils.c:1216:gst_element_get_compatible_pad:<wavparse0> Could not find a compatible pad to link to audioconvert0:sink
560:00:00.116103948 12228  0x8c55420 INFO                 default gstutils.c:2037:gst_element_link_pads_filtered: Could not link pads: wavparse0:(null) - audioconvert0:(null)
570:00:00.116111805 12228  0x8c55420 INFO            GST_PIPELINE ./grammar.y:568:gst_parse_perform_link: linking audioconvert0:(any) to audioresample0:(any) (0/0) with caps "(NULL)"
580:00:00.116118767 12228  0x8c55420 INFO        GST_ELEMENT_PADS gstutils.c:1698:gst_element_link_pads_full: trying to link element audioconvert0:(any) to element audioresample0:(any)
590:00:00.116125690 12228  0x8c55420 INFO                GST_PADS gstutils.c:1032:gst_pad_check_link: trying to link audioconvert0:src and audioresample0:sink
600:00:00.120497492 12228  0x8c55420 INFO                GST_PADS gstutils.c:1596:prepare_link_maybe_ghosting: audioconvert0 and audioresample0 in same bin, no need for ghost pads
610:00:00.120526658 12228  0x8c55420 INFO                GST_PADS gstpad.c:1978:gst_pad_link_prepare: trying to link audioconvert0:src and audioresample0:sink
620:00:00.120868284 12228  0x8c55420 INFO                GST_PADS gstpad.c:2161:gst_pad_link_full: linked audioconvert0:src and audioresample0:sink, successful
630:00:00.120882295 12228  0x8c55420 INFO            GST_PIPELINE ./grammar.y:568:gst_parse_perform_link: linking audioresample0:(any) to volume:(any) (0/0) with caps "(NULL)"
640:00:00.120891686 12228  0x8c55420 INFO        GST_ELEMENT_PADS gstutils.c:1698:gst_element_link_pads_full: trying to link element audioresample0:(any) to element volume:(any)
650:00:00.120899772 12228  0x8c55420 INFO                GST_PADS gstutils.c:1032:gst_pad_check_link: trying to link audioresample0:src and volume:sink
660:00:00.121345510 12228  0x8c55420 INFO                GST_PADS gstutils.c:1596:prepare_link_maybe_ghosting: audioresample0 and volume in same bin, no need for ghost pads
670:00:00.121355974 12228  0x8c55420 INFO                GST_PADS gstpad.c:1978:gst_pad_link_prepare: trying to link audioresample0:src and volume:sink
680:00:00.121695124 12228  0x8c55420 INFO                GST_PADS gstpad.c:2161:gst_pad_link_full: linked audioresample0:src and volume:sink, successful
690:00:00.121708059 12228  0x8c55420 INFO            GST_PIPELINE ./grammar.y:568:gst_parse_perform_link: linking volume:(any) to queue:(any) (0/0) with caps "(NULL)"
700:00:00.121715861 12228  0x8c55420 INFO        GST_ELEMENT_PADS gstutils.c:1698:gst_element_link_pads_full: trying to link element volume:(any) to element queue:(any)
710:00:00.121723016 12228  0x8c55420 INFO                GST_PADS gstutils.c:1032:gst_pad_check_link: trying to link volume:src and queue:sink
720:00:00.122114592 12228  0x8c55420 INFO                GST_PADS gstutils.c:1596:prepare_link_maybe_ghosting: volume and queue in same bin, no need for ghost pads
730:00:00.122126187 12228  0x8c55420 INFO                GST_PADS gstpad.c:1978:gst_pad_link_prepare: trying to link volume:src and queue:sink
740:00:00.122316087 12228  0x8c55420 INFO                GST_PADS gstpad.c:2161:gst_pad_link_full: linked volume:src and queue:sink, successful
750:00:00.122596548 12228  0x8c55420 INFO            GST_PIPELINE ./grammar.y:568:gst_parse_perform_link: linking queue:(any) to autoaudiosink0:(any) (0/0) with caps "(NULL)"
760:00:00.122699288 12228  0x8c55420 INFO        GST_ELEMENT_PADS gstutils.c:1698:gst_element_link_pads_full: trying to link element queue:(any) to element autoaudiosink0:(any)
770:00:00.122741818 12228  0x8c55420 INFO                GST_PADS gstutils.c:1032:gst_pad_check_link: trying to link queue:src and autoaudiosink0:sink
780:00:00.123065082 12228  0x8c55420 INFO                GST_PADS gstutils.c:1596:prepare_link_maybe_ghosting: queue and autoaudiosink0 in same bin, no need for ghost pads
790:00:00.123076241 12228  0x8c55420 INFO                GST_PADS gstpad.c:1978:gst_pad_link_prepare: trying to link queue:src and autoaudiosink0:sink
800:00:00.123377506 12228  0x8c55420 INFO                GST_PADS gstpad.c:2161:gst_pad_link_full: linked queue:src and autoaudiosink0:sink, successful
810:00:00.123468564 12228  0x8c55420 INFO           GST_PARENTAGE gstbin.c:3762:gst_bin_get_by_name: [pipeline0]: looking up child element volume
820:00:00.123621278 12228  0x8c55420 INFO           GST_PARENTAGE gstbin.c:3762:gst_bin_get_by_name: [pipeline0]: looking up child element src
830:00:00.125561173 12228  0x8c55420 INFO           GST_PARENTAGE gstbin.c:3762:gst_bin_get_by_name: [pipeline0]: looking up child element queue
842016-08-06 08:17:05,773 sound output SoundPipeline.start() codec=wav
852016-08-06 08:17:05,773 sound output update_state(active)
860:00:00.126450864 12228  0x8c55420 INFO              GST_STATES gstelement.c:2460:gst_element_continue_state:<tempsink> completed state change to NULL
870:00:00.126499249 12228  0x8c55420 INFO        GST_ELEMENT_PADS gstpad.c:1750:gst_pad_unlink: unlinking sink:proxypad0(0x92fb800) and tempsink:sink(0x92f9008)
880:00:00.126527627 12228  0x8c55420 INFO        GST_ELEMENT_PADS gstpad.c:1795:gst_pad_unlink: unlinked sink:proxypad0 and tempsink:sink
890:00:00.126548210 12228  0x8c55420 INFO           GST_PARENTAGE gstbin.c:1465:gst_bin_remove_func:<autoaudiosink0> removed child "tempsink"
900:00:00.126571436 12228  0x8c55420 INFO         GST_REFCOUNTING gstelement.c:3064:gst_element_dispose:<tempsink> dispose
910:00:00.126586216 12228  0x8c55420 INFO        GST_ELEMENT_PADS gstelement.c:847:gst_element_remove_pad:<tempsink> removing pad 'sink'
920:00:00.126607994 12228  0x8c55420 INFO         GST_REFCOUNTING gstelement.c:3088:gst_element_dispose:<tempsink> parent class dispose
930:00:00.126625063 12228  0x8c55420 INFO         GST_REFCOUNTING gstelement.c:3119:gst_element_finalize:<tempsink> finalize
940:00:00.126633335 12228  0x8c55420 INFO         GST_REFCOUNTING gstelement.c:3130:gst_element_finalize:<tempsink> finalize parent
950:00:00.229353789 12228  0x8c55420 INFO      GST_PLUGIN_LOADING gstplugin.c:859:gst_plugin_load_file: plugin "/usr/lib/i386-linux-gnu/gstreamer-0.10/libgstpulse.so" loaded
960:00:00.229378418 12228  0x8c55420 INFO     GST_ELEMENT_FACTORY gstelementfactory.c:374:gst_element_factory_create: creating element "pulsesink" named "autoaudiosink0-actual-sink-pulse"
970:00:00.229647345 12228  0x8c55420 INFO        GST_ELEMENT_PADS gstelement.c:728:gst_element_add_pad:<GstBaseSink@0x93116f0> adding pad 'sink'
980:00:00.229758447 12228  0x8c55420 INFO        GST_ELEMENT_PADS gstelement.c:975:gst_element_get_static_pad: found pad autoaudiosink0-actual-sink-pulse:sink
990:00:00.229803425 12228  0x8c55420 INFO                   pulse pulsesink.c:2955:gst_pulsesink_change_state:<autoaudiosink0-actual-sink-pulse> new pa main loop thread
1000:00:00.229937997 12228  0x8c55420 INFO                   pulse pulsesink.c:493:gst_pulseringbuffer_open_device:<autoaudiosink0-actual-sink-pulse> new context with name xpra, pbuf=0x9314068, pctx=0x930fea8
1010:00:00.231651613 12228  0x8c55420 WARN                   pulse pulsesink.c:570:gst_pulseringbuffer_open_device:<autoaudiosink0-actual-sink-pulse> error: Failed to connect: Connection refused
1020:00:00.231733746 12228  0x8c55420 INFO        GST_ERROR_SYSTEM gstelement.c:1964:gst_element_message_full:<autoaudiosink0-actual-sink-pulse> posting message: Failed to connect: Connection refused
1030:00:00.231758605 12228  0x8c55420 INFO        GST_ERROR_SYSTEM gstelement.c:1987:gst_element_message_full:<autoaudiosink0-actual-sink-pulse> posted error message: Failed to connect: Connection refused
1040:00:00.231887310 12228  0x8c55420 INFO                   pulse pulsesink.c:2937:gst_pulsesink_release_mainloop:<autoaudiosink0-actual-sink-pulse> terminating pa main loop thread
1050:00:00.232028027 12228  0x8c55420 INFO              GST_STATES gstelement.c:2768:gst_element_change_state:<autoaudiosink0-actual-sink-pulse> have FAILURE change_state return
1060:00:00.232116651 12228  0x8c55420 INFO              GST_STATES gstelement.c:2335:gst_element_abort_state:<autoaudiosink0-actual-sink-pulse> aborting state from NULL to READY
1070:00:00.232191788 12228  0x8c55420 INFO              GST_STATES gstelement.c:2460:gst_element_continue_state:<autoaudiosink0-actual-sink-pulse> completed state change to NULL
1080:00:00.265614803 12228  0x8c55420 INFO      GST_PLUGIN_LOADING gstplugin.c:859:gst_plugin_load_file: plugin "/usr/lib/i386-linux-gnu/gstreamer-0.10/libgstjack.so" loaded
1090:00:00.265689419 12228  0x8c55420 INFO     GST_ELEMENT_FACTORY gstelementfactory.c:374:gst_element_factory_create: creating element "jackaudiosink" named "autoaudiosink0-actual-sink-jackaudio"
1100:00:00.265993168 12228  0x8c55420 INFO        GST_ELEMENT_PADS gstelement.c:728:gst_element_add_pad:<GstBaseSink@0x93180b0> adding pad 'sink'
1110:00:00.266120504 12228  0x8c55420 INFO        GST_ELEMENT_PADS gstelement.c:975:gst_element_get_static_pad: found pad autoaudiosink0-actual-sink-jackaudio:sink
112Cannot connect to server socket err = No such file or directory
113Cannot connect to server request channel
114jack server is not running or cannot be started
1150:00:00.278501667 12228  0x8c55420 WARN              jackclient gstjackaudioclient.c:292:gst_jack_audio_get_connection: could not create connection
1160:00:00.278835028 12228  0x8c55420 WARN                jacksink gstjackaudiosink.c:358:gst_jack_ring_buffer_open_device:<autoaudiosink0-actual-sink-jackaudio> error: Jack server not found
1170:00:00.278866521 12228  0x8c55420 WARN                jacksink gstjackaudiosink.c:358:gst_jack_ring_buffer_open_device:<autoaudiosink0-actual-sink-jackaudio> error: Cannot connect to the Jack server (status 17)
1180:00:00.278908949 12228  0x8c55420 INFO        GST_ERROR_SYSTEM gstelement.c:1964:gst_element_message_full:<autoaudiosink0-actual-sink-jackaudio> posting message: Jack server not found
1190:00:00.278966809 12228  0x8c55420 INFO        GST_ERROR_SYSTEM gstelement.c:1987:gst_element_message_full:<autoaudiosink0-actual-sink-jackaudio> posted error message: Jack server not found
1200:00:00.278996103 12228  0x8c55420 INFO              GST_STATES gstelement.c:2768:gst_element_change_state:<autoaudiosink0-actual-sink-jackaudio> have FAILURE change_state return
1210:00:00.279018229 12228  0x8c55420 INFO              GST_STATES gstelement.c:2335:gst_element_abort_state:<autoaudiosink0-actual-sink-jackaudio> aborting state from NULL to READY
1220:00:00.279050130 12228  0x8c55420 INFO              GST_STATES gstelement.c:2460:gst_element_continue_state:<autoaudiosink0-actual-sink-jackaudio> completed state change to NULL
1230:00:00.282231764 12228  0x8c55420 INFO      GST_PLUGIN_LOADING gstplugin.c:859:gst_plugin_load_file: plugin "/usr/lib/i386-linux-gnu/gstreamer-0.10/libgstalsa.so" loaded
1240:00:00.282355690 12228  0x8c55420 INFO     GST_ELEMENT_FACTORY gstelementfactory.c:374:gst_element_factory_create: creating element "alsasink" named "autoaudiosink0-actual-sink-alsa"
1250:00:00.282826532 12228  0x8c55420 INFO        GST_ELEMENT_PADS gstelement.c:728:gst_element_add_pad:<GstBaseSink@0x931c200> adding pad 'sink'
1260:00:00.283004682 12228  0x8c55420 INFO        GST_ELEMENT_PADS gstelement.c:975:gst_element_get_static_pad: found pad autoaudiosink0-actual-sink-alsa:sink
1270:00:00.298384097 12228  0x8c55420 INFO              GST_STATES gstelement.c:2460:gst_element_continue_state:<autoaudiosink0-actual-sink-alsa> completed state change to READY
1280:00:00.304229492 12228  0x8c55420 INFO              GST_STATES gstelement.c:2365:_priv_gst_element_state_changed:<autoaudiosink0-actual-sink-alsa> notifying about state-changed NULL to READY (VOID_PENDING pending)
1290:00:00.304308525 12228  0x8c55420 INFO         GST_REFCOUNTING gstelement.c:3064:gst_element_dispose:<autoaudiosink0-actual-sink-pulse> dispose
1300:00:00.304324905 12228  0x8c55420 INFO        GST_ELEMENT_PADS gstelement.c:847:gst_element_remove_pad:<autoaudiosink0-actual-sink-pulse> removing pad 'sink'
1310:00:00.304340808 12228  0x8c55420 INFO         GST_REFCOUNTING gstelement.c:3088:gst_element_dispose:<autoaudiosink0-actual-sink-pulse> parent class dispose
1320:00:00.304355642 12228  0x8c55420 INFO         GST_REFCOUNTING gstelement.c:3119:gst_element_finalize:<autoaudiosink0-actual-sink-pulse> finalize
1330:00:00.304366458 12228  0x8c55420 INFO         GST_REFCOUNTING gstelement.c:3130:gst_element_finalize:<autoaudiosink0-actual-sink-pulse> finalize parent
1340:00:00.304391799 12228  0x8c55420 INFO         GST_REFCOUNTING gstelement.c:3064:gst_element_dispose:<autoaudiosink0-actual-sink-jackaudio> dispose
1350:00:00.304403046 12228  0x8c55420 INFO        GST_ELEMENT_PADS gstelement.c:847:gst_element_remove_pad:<autoaudiosink0-actual-sink-jackaudio> removing pad 'sink'
1360:00:00.304415551 12228  0x8c55420 INFO         GST_REFCOUNTING gstelement.c:3088:gst_element_dispose:<autoaudiosink0-actual-sink-jackaudio> parent class dispose
1370:00:00.304426521 12228  0x8c55420 INFO         GST_REFCOUNTING gstelement.c:3119:gst_element_finalize:<autoaudiosink0-actual-sink-jackaudio> finalize
1380:00:00.304436660 12228  0x8c55420 INFO         GST_REFCOUNTING gstelement.c:3130:gst_element_finalize:<autoaudiosink0-actual-sink-jackaudio> finalize parent
1390:00:00.304474915 12228  0x8c55420 INFO                 default gstchildproxy.c:209:gst_child_proxy_lookup: no param spec named async
1400:00:00.304489540 12228  0x8c55420 INFO                 default gstchildproxy.c:209:gst_child_proxy_lookup: no param spec named qos
1410:00:00.304499811 12228  0x8c55420 INFO                 default gstchildproxy.c:209:gst_child_proxy_lookup: no param spec named sync
1420:00:00.304509996 12228  0x8c55420 INFO        GST_ELEMENT_PADS gstelement.c:975:gst_element_get_static_pad: found pad autoaudiosink0-actual-sink-alsa:sink
1430:00:00.304522699 12228  0x8c55420 INFO                GST_PADS gstpad.c:1978:gst_pad_link_prepare: trying to link sink:proxypad0 and autoaudiosink0-actual-sink-alsa:sink
1440:00:00.304543328 12228  0x8c55420 INFO                GST_PADS gstpad.c:2161:gst_pad_link_full: linked sink:proxypad0 and autoaudiosink0-actual-sink-alsa:sink, successful
1450:00:00.304561816 12228  0x8c55420 INFO              GST_STATES gstbin.c:2237:gst_bin_element_set_state:<autoaudiosink0-actual-sink-alsa> skipping transition from READY to  READY, since bin pending is READY : last change state return follows
1460:00:00.304580033 12228  0x8c55420 INFO              GST_STATES gstbin.c:2526:gst_bin_change_state_func:<autoaudiosink0> child 'autoaudiosink0-actual-sink-alsa' changed state to 2(READY) successfully
1470:00:00.304595887 12228  0x8c55420 INFO              GST_STATES gstelement.c:2460:gst_element_continue_state:<autoaudiosink0> completed state change to READY
1480:00:00.304606433 12228  0x8c55420 INFO              GST_STATES gstelement.c:2365:_priv_gst_element_state_changed:<autoaudiosink0> notifying about state-changed NULL to READY (VOID_PENDING pending)
1490:00:00.304624431 12228  0x8c55420 INFO              GST_STATES gstbin.c:2526:gst_bin_change_state_func:<pipeline0> child 'autoaudiosink0' changed state to 2(READY) successfully
1500:00:00.309533018 12228  0x8c55420 INFO              GST_STATES gstelement.c:2460:gst_element_continue_state:<queue> completed state change to READY
1510:00:00.309562366 12228  0x8c55420 INFO              GST_STATES gstelement.c:2365:_priv_gst_element_state_changed:<queue> notifying about state-changed NULL to READY (VOID_PENDING pending)
1520:00:00.309588361 12228  0x8c55420 INFO              GST_STATES gstbin.c:2526:gst_bin_change_state_func:<pipeline0> child 'queue' changed state to 2(READY) successfully
1530:00:00.309603214 12228  0x8c55420 INFO              GST_STATES gstelement.c:2460:gst_element_continue_state:<volume> completed state change to READY
1540:00:00.309612363 12228  0x8c55420 INFO              GST_STATES gstelement.c:2365:_priv_gst_element_state_changed:<volume> notifying about state-changed NULL to READY (VOID_PENDING pending)
1550:00:00.309624054 12228  0x8c55420 INFO              GST_STATES gstbin.c:2526:gst_bin_change_state_func:<pipeline0> child 'volume' changed state to 2(READY) successfully
1560:00:00.309635832 12228  0x8c55420 INFO              GST_STATES gstelement.c:2460:gst_element_continue_state:<audioresample0> completed state change to READY
1570:00:00.309644602 12228  0x8c55420 INFO              GST_STATES gstelement.c:2365:_priv_gst_element_state_changed:<audioresample0> notifying about state-changed NULL to READY (VOID_PENDING pending)
1580:00:00.309656038 12228  0x8c55420 INFO              GST_STATES gstbin.c:2526:gst_bin_change_state_func:<pipeline0> child 'audioresample0' changed state to 2(READY) successfully
1590:00:00.309666609 12228  0x8c55420 INFO              GST_STATES gstelement.c:2460:gst_element_continue_state:<audioconvert0> completed state change to READY
1600:00:00.309675112 12228  0x8c55420 INFO              GST_STATES gstelement.c:2365:_priv_gst_element_state_changed:<audioconvert0> notifying about state-changed NULL to READY (VOID_PENDING pending)
1610:00:00.309686488 12228  0x8c55420 INFO              GST_STATES gstbin.c:2526:gst_bin_change_state_func:<pipeline0> child 'audioconvert0' changed state to 2(READY) successfully
1620:00:00.309699781 12228  0x8c55420 INFO              GST_STATES gstelement.c:2460:gst_element_continue_state:<wavparse0> completed state change to READY
1630:00:00.309708453 12228  0x8c55420 INFO              GST_STATES gstelement.c:2365:_priv_gst_element_state_changed:<wavparse0> notifying about state-changed NULL to READY (VOID_PENDING pending)
1640:00:00.309719527 12228  0x8c55420 INFO              GST_STATES gstbin.c:2526:gst_bin_change_state_func:<pipeline0> child 'wavparse0' changed state to 2(READY) successfully
1650:00:00.309730047 12228  0x8c55420 INFO              GST_STATES gstelement.c:2460:gst_element_continue_state:<src> completed state change to READY
1660:00:00.309738534 12228  0x8c55420 INFO              GST_STATES gstelement.c:2365:_priv_gst_element_state_changed:<src> notifying about state-changed NULL to READY (VOID_PENDING pending)
1670:00:00.309749421 12228  0x8c55420 INFO              GST_STATES gstbin.c:2526:gst_bin_change_state_func:<pipeline0> child 'src' changed state to 2(READY) successfully
1680:00:00.309760379 12228  0x8c55420 INFO              GST_STATES gstelement.c:2435:gst_element_continue_state:<pipeline0> committing state from NULL to READY, pending PLAYING, next PAUSED
1690:00:00.309769604 12228  0x8c55420 INFO              GST_STATES gstelement.c:2365:_priv_gst_element_state_changed:<pipeline0> notifying about state-changed NULL to READY (PLAYING pending)
1700:00:00.309780915 12228  0x8c55420 INFO              GST_STATES gstelement.c:2442:gst_element_continue_state:<pipeline0> continue state change READY to PAUSED, final PLAYING
1710:00:00.309836621 12228  0x8c55420 INFO              GST_STATES gstbin.c:2532:gst_bin_change_state_func:<autoaudiosink0> child 'autoaudiosink0-actual-sink-alsa' is changing state asynchronously to PAUSED
1720:00:00.309851341 12228  0x8c55420 INFO              GST_STATES gstbin.c:2532:gst_bin_change_state_func:<pipeline0> child 'autoaudiosink0' is changing state asynchronously to PAUSED
1730:00:00.309933424 12228  0x8c55420 INFO              GST_STATES gstelement.c:2460:gst_element_continue_state:<queue> completed state change to PAUSED
1740:00:00.309945877 12228  0x8c55420 INFO              GST_STATES gstelement.c:2365:_priv_gst_element_state_changed:<queue> notifying about state-changed READY to PAUSED (VOID_PENDING pending)
1750:00:00.309958154 12228  0x8c55420 INFO              GST_STATES gstbin.c:2526:gst_bin_change_state_func:<pipeline0> child 'queue' changed state to 3(PAUSED) successfully
1760:00:00.309984421 12228  0x8c55420 INFO              GST_STATES gstelement.c:2460:gst_element_continue_state:<volume> completed state change to PAUSED
1770:00:00.309994015 12228  0x8c55420 INFO              GST_STATES gstelement.c:2365:_priv_gst_element_state_changed:<volume> notifying about state-changed READY to PAUSED (VOID_PENDING pending)
1780:00:00.310005144 12228  0x8c55420 INFO              GST_STATES gstbin.c:2526:gst_bin_change_state_func:<pipeline0> child 'volume' changed state to 3(PAUSED) successfully
1790:00:00.310028267 12228  0x8c55420 INFO              GST_STATES gstelement.c:2460:gst_element_continue_state:<audioresample0> completed state change to PAUSED
1800:00:00.310037351 12228  0x8c55420 INFO              GST_STATES gstelement.c:2365:_priv_gst_element_state_changed:<audioresample0> notifying about state-changed READY to PAUSED (VOID_PENDING pending)
1810:00:00.310048464 12228  0x8c55420 INFO              GST_STATES gstbin.c:2526:gst_bin_change_state_func:<pipeline0> child 'audioresample0' changed state to 3(PAUSED) successfully
1820:00:00.310071529 12228  0x8c55420 INFO              GST_STATES gstelement.c:2460:gst_element_continue_state:<audioconvert0> completed state change to PAUSED
1830:00:00.310080423 12228  0x8c55420 INFO              GST_STATES gstelement.c:2365:_priv_gst_element_state_changed:<audioconvert0> notifying about state-changed READY to PAUSED (VOID_PENDING pending)
1840:00:00.310091637 12228  0x8c55420 INFO              GST_STATES gstbin.c:2526:gst_bin_change_state_func:<pipeline0> child 'audioconvert0' changed state to 3(PAUSED) successfully
1850:00:00.310117145 12228  0x8c55420 INFO              GST_STATES gstelement.c:2460:gst_element_continue_state:<wavparse0> completed state change to PAUSED
1860:00:00.310126937 12228  0x8c55420 INFO              GST_STATES gstelement.c:2365:_priv_gst_element_state_changed:<wavparse0> notifying about state-changed READY to PAUSED (VOID_PENDING pending)
1870:00:00.310138149 12228  0x8c55420 INFO              GST_STATES gstbin.c:2526:gst_bin_change_state_func:<pipeline0> child 'wavparse0' changed state to 3(PAUSED) successfully
1880:00:00.310164292 12228  0x8c55420 INFO               GST_EVENT gstevent.c:606:gst_event_new_new_segment_full: creating newsegment update 0, rate 1.000000, format buffers, start 0, stop -1, position 0
1890:00:00.310227371 12228  0x8c55420 INFO              GST_STATES gstelement.c:2460:gst_element_continue_state:<src> completed state change to PAUSED
1900:00:00.310237450 12228  0x8c55420 INFO              GST_STATES gstelement.c:2365:_priv_gst_element_state_changed:<src> notifying about state-changed READY to PAUSED (VOID_PENDING pending)
1910:00:00.310252172 12228  0x8c55420 INFO              GST_STATES gstbin.c:2526:gst_bin_change_state_func:<pipeline0> child 'src' changed state to 3(PAUSED) successfully
1922016-08-06 08:17:05,957 sound output SoundPipeline.start() done
1932016-08-06 08:17:05,959 the wav sound sink has stopped
1942016-08-06 08:17:05,959 stop_receiving_sound(True) sound sink=sink_subprocess_wrapper(12228)
1952016-08-06 08:17:05,960 stop_receiving_sound(True) calling <bound method sink_subprocess_wrapper.cleanup of sink_subprocess_wrapper(12228)>
1962016-08-06 08:17:05,960 cleanup() sending cleanup request to sound output
1972016-08-06 08:17:05,961 stop_receiving_sound(True) done
1982016-08-06 08:17:05,961 sound_sink_exit() not the current sink, ignoring it
1992016-08-06 08:17:05,961 sound_process_stopped(sink_subprocess_wrapper(12228), ()) not the current sink, ignoring it
2002016-08-06 08:17:08,458 verify_started() process=<subprocess.Popen object at 0xab9768c>, info={}, codec=