After an evaluation, GNOME has moved from Bugzilla to GitLab. Learn more about GitLab.
No new issues can be reported in GNOME Bugzilla anymore.
To report an issue in a GNOME project, go to GNOME GitLab.
Do not go to GNOME Gitlab for: Bluefish, Doxygen, GnuCash, GStreamer, java-gnome, LDTP, NetworkManager, Tomboy.
Bug 582528 - playbin2 Audio CD playback broken since
playbin2 Audio CD playback broken since
Status: RESOLVED FIXED
Product: GStreamer
Classification: Platform
Component: gst-plugins-base
git master
Other All
: Normal major
: 0.10.24
Assigned To: Wim Taymans
GStreamer Maintainers
: 583721 593021 (view as bug list)
Depends on:
Blocks:
 
 
Reported: 2009-05-13 20:20 UTC by Andreas Frisch
Modified: 2009-09-17 16:59 UTC
See Also:
GNOME target: ---
GNOME version: ---


Attachments
full debug log of this case (130.18 KB, application/x-bzip2)
2009-05-14 07:41 UTC, Andreas Frisch
Details

Description Andreas Frisch 2009-05-13 20:20:02 UTC
Please describe the problem:
when trying to play an audio cd using playbin2, the pipeline doesn't reach playing anymore.

Steps to reproduce:
with gstreamer core 0.10.23 and gst-plugins-base git checkout from 2009-05-13

root@dm8000:/media/hdd/movie/mkv# GST_DEBUG=*:3,*playbin2*:5,*cd*:5 gst-launch playbin2 uri=cdda://1


Actual results:
0:00:00.003025000  4966 0x10001050 INFO              GST_INIT gst.c:611:init_pre: Initializing GStreamer Core Library version 0.10.23
0:00:00.052300000  4966 0x10001050 INFO              GST_INIT gst.c:612:init_pre: Using library installed in /usr/lib                
0:00:00.053964000  4966 0x10001050 INFO              GST_INIT gst.c:622:init_pre: Linux dm8000 2.6.12-5.1-brcmstb-dm8000 #1 Tue Nov 18 16:55:19 CET 2008 7400b0
0:00:00.057800000  4966 0x10001050 INFO              GST_INIT gstquery.c:105:_gst_query_initialize: init queries                                               
0:00:00.094377000  4966 0x10001050 INFO              GST_INIT gstmessage.c:73:_gst_message_initialize: init messages                                           
0:00:00.100766000  4966 0x10001050 INFO    GST_PLUGIN_LOADING gstplugin.c:261:_gst_plugin_initialize: registering 0 static plugins                             
0:00:00.108502000  4966 0x10001050 INFO    GST_PLUGIN_LOADING gstplugin.c:246:gst_plugin_register_static: registered static plugin "staticelements"            
0:00:00.110194000  4966 0x10001050 INFO    GST_PLUGIN_LOADING gstplugin.c:248:gst_plugin_register_static: added static plugin "staticelements", result: 1      
0:00:00.126318000  4966 0x10001050 INFO              GST_INIT gst.c:923:ensure_current_registry: reading registry cache: /home/root/.gstreamer-0.10/registry.mipsel.bin
0:00:00.377853000  4966 0x10001050 INFO          GST_REGISTRY gstregistrybinary.c:1285:gst_registry_binary_read_cache: loaded /home/root/.gstreamer-0.10/registry.mipsel.bin in 0.249687 seconds
0:00:00.383469000  4967 0x10001050 INFO              GST_INIT gst.c:674:scan_and_update_registry: Validating registry cache: /home/root/.gstreamer-0.10/registry.mipsel.bin                     
0:00:00.423493000  4967 0x10001050 INFO              GST_INIT gst.c:759:scan_and_update_registry: Registry cache has not changed                                                                
0:00:00.426384000  4966 0x10001050 INFO              GST_INIT gst.c:970:ensure_current_registry: registry reading and updating done, result = 1                                                 
0:00:00.429988000  4966 0x10001050 INFO          GST_PIPELINE gstparse.c:291:gst_parse_launch_full: parsing pipeline description 'playbin2 uri=cdda://1 '                                       
0:00:00.468341000  4966 0x10001050 INFO    GST_PLUGIN_LOADING gstplugin.c:567:gst_plugin_load_file: plugin "/usr/lib/gstreamer-0.10/libgstplaybin.so" loaded                                    
0:00:00.470322000  4966 0x10001050 INFO   GST_ELEMENT_FACTORY gstelementfactory.c:379:gst_element_factory_create: creating element "playbin2"                                                   
0:00:00.490462000  4966 0x10001050 DEBUG             playbin2 gstplaybin2.c:1081:gst_play_bin_set_uri: set new uri to cdda://1                                                                  
Setting pipeline to PAUSED ...                                                                                                                                                                  
0:00:00.494588000  4966 0x10001050 INFO            GST_STATES gstelement.c:2152:gst_element_continue_state:<playsink0> completed state change to READY                                          
0:00:00.496061000  4966 0x10001050 INFO            GST_STATES gstelement.c:2165:gst_element_continue_state:<playsink0> posting state-changed NULL to READY                                      
0:00:00.498416000  4966 0x10001050 INFO            GST_STATES gstbin.c:2328:gst_bin_change_state_func:<playbin20> child 'playsink0' changed state to 2(READY) successfully                      
0:00:00.501264000  4966 0x10001050 INFO            GST_STATES gstelement.c:2125:gst_element_continue_state:<playbin20> committing state from NULL to READY, pending PAUSED                      
0:00:00.503179000  4966 0x10001050 INFO            GST_STATES gstelement.c:2134:gst_element_continue_state:<playbin20> continue state change READY to PAUSED, final PAUSED                      
0:00:00.504644000  4966 0x10001050 LOG               playbin2 gstplaybin2.c:2583:gst_play_bin_change_state:<playbin20> clearing shutdown flag                                                   
0:00:00.505955000  4966 0x10001050 DEBUG             playbin2 gstplaybin2.c:2486:setup_next_source:<playbin20> setup sources                                                                    
0:00:00.507288000  4966 0x10001050 DEBUG             playbin2 gstplaybin2.c:2282:activate_group:<playbin20> activating group 0x1006c400                                                         
0:00:00.508626000  4966 0x10001050 DEBUG             playbin2 gstplaybin2.c:2297:activate_group:<playbin20> making new uridecodebin                                                             
0:00:00.528402000  4966 0x10001050 INFO    GST_PLUGIN_LOADING gstplugin.c:567:gst_plugin_load_file: plugin "/usr/lib/gstreamer-0.10/libgstdecodebin2.so" loaded                                 
0:00:00.530543000  4966 0x10001050 INFO   GST_ELEMENT_FACTORY gstelementfactory.c:379:gst_element_factory_create: creating element "uridecodebin"                                               
0:00:00.542768000  4966 0x10001050 INFO            GST_STATES gstelement.c:2125:gst_element_continue_state:<uridecodebin0> committing state from NULL to READY, pending PAUSED                  
0:00:00.544662000  4966 0x10001050 INFO            GST_STATES gstelement.c:2134:gst_element_continue_state:<uridecodebin0> continue state change READY to PAUSED, final PAUSED                  
0:00:00.591906000  4966 0x10001050 INFO    GST_PLUGIN_LOADING gstplugin.c:567:gst_plugin_load_file: plugin "/usr/lib/gstreamer-0.10/libgstcdio.so" loaded                                       
0:00:00.593889000  4966 0x10001050 INFO   GST_ELEMENT_FACTORY gstelementfactory.c:377:gst_element_factory_create: creating element "cdiocddasrc" named "source"                                 
0:00:00.597177000  4966 0x10001050 INFO      GST_ELEMENT_PADS gstelement.c:641:gst_element_add_pad:<GstBaseSrc@0x10076068> adding pad 'src'                                                     
0:00:00.600944000  4966 0x10001050 LOG            cddabasesrc gstcddabasesrc.c:965:gst_cdda_base_src_uri_set_uri:<source> successfully handled uri 'cdda://1'                                   
0:00:00.610513000  4966 0x10001050 INFO              GST_PADS gstpad.c:1849:gst_pad_link_prepare: trying to link source:src and src0:proxypad0                                                  
0:00:00.613382000  4966 0x10001050 INFO              GST_PADS gstpad.c:2022:gst_pad_link: linked source:src and src0:proxypad0, successful                                                      
0:00:00.615748000  4966 0x10001050 INFO      GST_ELEMENT_PADS gstelement.c:641:gst_element_add_pad:<uridecodebin0> adding pad 'src0'                                                            
0:00:00.617913000  4966 0x10001050 DEBUG             playbin2 gstplaybin2.c:1755:pad_added_cb:<playbin20> (null)                                                                                
0:00:00.620396000  4966 0x10001050 DEBUG             playbin2 gstplaybin2.c:1772:pad_added_cb:<playbin20> creating new selector                                                                 
0:00:00.635197000  4966 0x10001050 INFO    GST_PLUGIN_LOADING gstplugin.c:567:gst_plugin_load_file: plugin "/usr/lib/gstreamer-0.10/libgstselector.so" loaded                                   
0:00:00.637217000  4966 0x10001050 INFO   GST_ELEMENT_FACTORY gstelementfactory.c:379:gst_element_factory_create: creating element "input-selector"                                             
0:00:00.640688000  4966 0x10001050 INFO      GST_ELEMENT_PADS gstelement.c:641:gst_element_add_pad:<GstInputSelector@0x1007c038> adding pad 'src'                                               
0:00:00.643189000  4966 0x10001050 DEBUG             playbin2 gstplaybin2.c:1787:pad_added_cb:<playbin20> adding new selector 0x1007c038                                                        
0:00:00.645017000  4966 0x10001050 INFO            GST_STATES gstelement.c:2125:gst_element_continue_state:<inputselector0> committing state from NULL to READY, pending PAUSED                 
0:00:00.647608000  4966 0x10001050 INFO            GST_STATES gstelement.c:2134:gst_element_continue_state:<inputselector0> continue state change READY to PAUSED, final PAUSED                 
0:00:00.649577000  4966 0x10001050 INFO            GST_STATES gstelement.c:2152:gst_element_continue_state:<inputselector0> completed state change to PAUSED                                    
0:00:00.651186000  4966 0x10001050 INFO            GST_STATES gstelement.c:2165:gst_element_continue_state:<inputselector0> posting state-changed READY to PAUSED                               
0:00:00.653405000  4966 0x10001050 INFO      GST_ELEMENT_PADS gstelement.c:887:gst_element_get_static_pad: found pad inputselector0:src                                                         
0:00:00.656875000  4966 0x10001050 INFO      GST_ELEMENT_PADS gstelement.c:641:gst_element_add_pad:<inputselector0> adding pad 'sink0'                                                          
0:00:00.658429000  4966 0x10001050 DEBUG             playbin2 gstplaybin2.c:1812:pad_added_cb:<playbin20> got pad inputselector0:sink0 from selector                                            
0:00:00.661169000  4966 0x10001050 DEBUG             playbin2 gstplaybin2.c:1818:pad_added_cb:<playbin20> pad 0x1007d060 added to array                                                         
0:00:00.662943000  4966 0x10001050 INFO              GST_PADS gstpad.c:1849:gst_pad_link_prepare: trying to link uridecodebin0:src0 and inputselector0:sink0                                    
0:00:00.665164000  4966 0x10001050 INFO              GST_PADS gstpad.c:2022:gst_pad_link: linked uridecodebin0:src0 and inputselector0:sink0, successful                                        
0:00:00.667259000  4966 0x10001050 DEBUG             playbin2 gstplaybin2.c:1830:pad_added_cb:<playbin20> linked pad uridecodebin0:src0 to selector 0x1007c038                                  
0:00:00.669261000  4966 0x10001050 DEBUG             playbin2 gstplaybin2.c:1969:no_more_pads_cb:<playbin20> no more pads in group 0x1006c400                                                   
0:00:00.670652000  4966 0x10001050 DEBUG             playbin2 gstplaybin2.c:1982:no_more_pads_cb:<playbin20> requesting new sink pad 1                                                          
0:00:00.734811000  4966 0x10001050 INFO    GST_PLUGIN_LOADING gstplugin.c:567:gst_plugin_load_file: plugin "/usr/lib/gstreamer-0.10/libgstcoreelements.so" loaded                               
0:00:00.736849000  4966 0x10001050 INFO   GST_ELEMENT_FACTORY gstelementfactory.c:377:gst_element_factory_create: creating element "tee" named "audiotee"                                       
0:00:00.741427000  4966 0x10001050 INFO      GST_ELEMENT_PADS gstelement.c:641:gst_element_add_pad:<GstTee@0x10078190> adding pad 'sink'                                                        
0:00:00.743927000  4966 0x10001050 INFO      GST_ELEMENT_PADS gstelement.c:887:gst_element_get_static_pad: found pad audiotee:sink                                                              
0:00:00.745738000  4966 0x10001050 INFO            GST_STATES gstelement.c:2125:gst_element_continue_state:<audiotee> committing state from NULL to READY, pending PAUSED                       
0:00:00.747618000  4966 0x10001050 INFO            GST_STATES gstelement.c:2134:gst_element_continue_state:<audiotee> continue state change READY to PAUSED, final PAUSED                       
0:00:00.749344000  4966 0x10001050 INFO            GST_STATES gstelement.c:2152:gst_element_continue_state:<audiotee> completed state change to PAUSED                                          
0:00:00.750699000  4966 0x10001050 INFO            GST_STATES gstelement.c:2165:gst_element_continue_state:<audiotee> posting state-changed READY to PAUSED                                     
0:00:00.755395000  4966 0x10001050 INFO              GST_PADS gstpad.c:1849:gst_pad_link_prepare: trying to link audio_sink:proxypad1 and audiotee:sink                                         
0:00:00.757456000  4966 0x10001050 INFO              GST_PADS gstpad.c:2022:gst_pad_link: linked audio_sink:proxypad1 and audiotee:sink, successful                                             
0:00:00.760026000  4966 0x10001050 INFO      GST_ELEMENT_PADS gstelement.c:641:gst_element_add_pad:<playsink0> adding pad 'audio_sink'                                                          
0:00:00.762067000  4966 0x10001050 INFO              GST_PADS gstpad.c:1849:gst_pad_link_prepare: trying to link inputselector0:src and playsink0:audio_sink                                    
0:00:00.764019000  4966 0x10001050 INFO              GST_PADS gstpad.c:2022:gst_pad_link: linked inputselector0:src and playsink0:audio_sink, successful                                        
0:00:00.766257000  4966 0x10001050 DEBUG             playbin2 gstplaybin2.c:1987:no_more_pads_cb:<playbin20> linked type audio/x-raw-, result: 0                                                
0:00:00.767649000  4966 0x10001050 DEBUG             playbin2 gstplaybin2.c:1996:no_more_pads_cb:<playbin20> pending 1 > 0                                                                      
0:00:00.769616000  4966 0x10001050 LOG               playbin2 gstplaybin2.c:2004:no_more_pads_cb:<playbin20> last group complete                                                                
0:00:00.771197000  4966 0x10001050 LOG               playbin2 gstplaybin2.c:2015:no_more_pads_cb:<playbin20> setting custom audio sink (nil)                                                    
0:00:00.772959000  4966 0x10001050 LOG               playbin2 gstplaybin2.c:2018:no_more_pads_cb:<playbin20> setting custom video sink (nil)                                                    
0:00:00.774511000  4966 0x10001050 LOG               playbin2 gstplaybin2.c:2023:no_more_pads_cb:<playbin20> reconfigure sink                                                                   
0:00:00.776738000  4966 0x10001050 INFO   GST_ELEMENT_FACTORY gstelementfactory.c:464:gst_element_factory_make: no such element factory "autoaudiosink"!                                        
0:00:00.894260000  4966 0x10001050 INFO    GST_PLUGIN_LOADING gstplugin.c:567:gst_plugin_load_file: plugin "/usr/lib/gstreamer-0.10/libgstalsa.so" loaded                                       
0:00:00.896432000  4966 0x10001050 INFO   GST_ELEMENT_FACTORY gstelementfactory.c:377:gst_element_factory_create: creating element "alsasink" named "audiosink"                                 
0:00:00.900814000  4966 0x10001050 INFO      GST_ELEMENT_PADS gstelement.c:641:gst_element_add_pad:<GstBaseSink@0x1008c020> adding pad 'sink'                                                   
0:00:00.944654000  4966 0x10001050 INFO            GST_STATES gstelement.c:2152:gst_element_continue_state:<audiosink> completed state change to READY                                          
0:00:00.946459000  4966 0x10001050 INFO            GST_STATES gstelement.c:2165:gst_element_continue_state:<audiosink> posting state-changed NULL to READY                                      
0:00:00.949193000  4966 0x10001050 INFO   GST_ELEMENT_FACTORY gstelementfactory.c:377:gst_element_factory_create: creating element "bin" named "abin"                                           
0:00:00.980939000  4966 0x10001050 INFO    GST_PLUGIN_LOADING gstplugin.c:567:gst_plugin_load_file: plugin "/usr/lib/gstreamer-0.10/libgstaudioconvert.so" loaded                               
0:00:00.982829000  4966 0x10001050 INFO   GST_ELEMENT_FACTORY gstelementfactory.c:377:gst_element_factory_create: creating element "audioconvert" named "aconv"                                 
0:00:00.985762000  4966 0x10001050 INFO      GST_ELEMENT_PADS gstelement.c:641:gst_element_add_pad:<GstBaseTransform@0x1009c0f0> adding pad 'sink'                                              
0:00:00.988385000  4966 0x10001050 INFO      GST_ELEMENT_PADS gstelement.c:641:gst_element_add_pad:<GstBaseTransform@0x1009c0f0> adding pad 'src'                                               
0:00:01.011269000  4966 0x10001050 INFO    GST_PLUGIN_LOADING gstplugin.c:567:gst_plugin_load_file: plugin "/usr/lib/gstreamer-0.10/libgstaudioresample.so" loaded                              
0:00:01.013090000  4966 0x10001050 INFO   GST_ELEMENT_FACTORY gstelementfactory.c:377:gst_element_factory_create: creating element "audioresample" named "aresample"                            
0:00:01.016363000  4966 0x10001050 INFO      GST_ELEMENT_PADS gstelement.c:641:gst_element_add_pad:<GstBaseTransform@0x100a00e0> adding pad 'sink'                                              
0:00:01.020790000  4966 0x10001050 INFO      GST_ELEMENT_PADS gstelement.c:641:gst_element_add_pad:<GstBaseTransform@0x100a00e0> adding pad 'src'                                               
0:00:01.024527000  4966 0x10001050 INFO      GST_ELEMENT_PADS gstutils.c:1338:gst_element_link_pads: trying to link element aconv:src to element aresample:sink                                 
0:00:01.026090000  4966 0x10001050 INFO      GST_ELEMENT_PADS gstelement.c:887:gst_element_get_static_pad: found pad aconv:src                                                                  
0:00:01.027548000  4966 0x10001050 INFO      GST_ELEMENT_PADS gstelement.c:887:gst_element_get_static_pad: found pad aresample:sink                                                             
0:00:01.029007000  4966 0x10001050 INFO              GST_PADS gstutils.c:1243:prepare_link_maybe_ghosting: aconv and aresample in same bin, no need for ghost pads                              
0:00:01.030866000  4966 0x10001050 INFO              GST_PADS gstpad.c:1849:gst_pad_link_prepare: trying to link aconv:src and aresample:sink                                                   
0:00:01.041815000  4966 0x10001050 INFO              GST_PADS gstpad.c:2022:gst_pad_link: linked aconv:src and aresample:sink, successful                                                       
0:00:09.789554000  4966 0x10001050 INFO    GST_PLUGIN_LOADING gstplugin.c:567:gst_plugin_load_file: plugin "/usr/lib/gstreamer-0.10/libgstvolume.so" loaded                                     
0:00:09.791768000  4966 0x10001050 INFO   GST_ELEMENT_FACTORY gstelementfactory.c:377:gst_element_factory_create: creating element "volume" named "volume"                                      
0:00:09.794708000  4966 0x10001050 INFO      GST_ELEMENT_PADS gstelement.c:641:gst_element_add_pad:<GstBaseTransform@0x100a8068> adding pad 'sink'                                              
0:00:09.798646000  4966 0x10001050 INFO      GST_ELEMENT_PADS gstelement.c:641:gst_element_add_pad:<GstBaseTransform@0x100a8068> adding pad 'src'                                               
0:00:09.802293000  4966 0x10001050 INFO      GST_ELEMENT_PADS gstutils.c:1338:gst_element_link_pads: trying to link element aresample:src to element volume:sink                                
0:00:09.803842000  4966 0x10001050 INFO      GST_ELEMENT_PADS gstelement.c:887:gst_element_get_static_pad: found pad aresample:src                                                              
0:00:09.805303000  4966 0x10001050 INFO      GST_ELEMENT_PADS gstelement.c:887:gst_element_get_static_pad: found pad volume:sink                                                                
0:00:09.806743000  4966 0x10001050 INFO              GST_PADS gstutils.c:1243:prepare_link_maybe_ghosting: aresample and volume in same bin, no need for ghost pads                             
0:00:09.808634000  4966 0x10001050 INFO              GST_PADS gstpad.c:1849:gst_pad_link_prepare: trying to link aresample:src and volume:sink                                                  
0:00:09.827092000  4966 0x10001050 INFO              GST_PADS gstpad.c:2022:gst_pad_link: linked aresample:src and volume:sink, successful                                                      
0:00:09.829654000  4966 0x10001050 INFO      GST_ELEMENT_PADS gstutils.c:1338:gst_element_link_pads: trying to link element volume:src to element audiosink:(any)                               
0:00:09.831664000  4966 0x10001050 INFO      GST_ELEMENT_PADS gstelement.c:887:gst_element_get_static_pad: found pad volume:src                                                                 
0:00:09.833541000  4966 0x10001050 INFO              GST_PADS gstutils.c:792:gst_pad_check_link: trying to link volume:src and audiosink:sink                                                   
0:00:09.856012000  4966 0x10001050 WARN                  alsa gstalsa.c:124:gst_alsa_detect_formats:<audiosink> skipping non-int format                                                         
0:00:09.888830000  4966 0x10001050 WARN                  alsa pcm.c:2017:snd_pcm_open_conf: alsalib error: Invalid type for PCM iec958:{AES0 0x02 AES1 0x82 AES2 0x00 AES3 0x02} definition (id: iec958, value: cards.pcm.iec958)                                                                                                                                                                             
0:00:09.890711000  4966 0x10001050 INFO                  alsa gstalsasink.c:321:gst_alsasink_getcaps:<audiosink> (null)                                                                                
0:00:09.895431000  4966 0x10001050 INFO              GST_PADS gstutils.c:1243:prepare_link_maybe_ghosting: volume and audiosink in same bin, no need for ghost pads                                    
0:00:09.898350000  4966 0x10001050 INFO              GST_PADS gstpad.c:1849:gst_pad_link_prepare: trying to link volume:src and audiosink:sink                                                         
0:00:09.929887000  4966 0x10001050 INFO              GST_PADS gstpad.c:2022:gst_pad_link: linked volume:src and audiosink:sink, successful                                                             
0:00:09.932297000  4966 0x10001050 INFO      GST_ELEMENT_PADS gstelement.c:887:gst_element_get_static_pad: found pad aconv:sink                                                                        
0:00:09.936372000  4966 0x10001050 INFO              GST_PADS gstpad.c:1849:gst_pad_link_prepare: trying to link sink:proxypad2 and aconv:sink                                                         
0:00:09.973586000  4966 0x10001050 INFO              GST_PADS gstpad.c:2022:gst_pad_link: linked sink:proxypad2 and aconv:sink, successful                                                             
0:00:09.975293000  4966 0x10001050 INFO      GST_ELEMENT_PADS gstelement.c:641:gst_element_add_pad:<abin> adding pad 'sink'                                                                            
0:00:09.978998000  4966 0x10001050 INFO      GST_ELEMENT_PADS gstelement.c:641:gst_element_add_pad:<audiotee> adding pad 'src0'                                                                        
0:00:09.982150000  4966 0x10001050 INFO            GST_STATES gstelement.c:2152:gst_element_continue_state:<audiosink> completed state change to READY                                                 
0:00:09.983771000  4966 0x10001050 INFO            GST_STATES gstbin.c:2328:gst_bin_change_state_func:<abin> child 'audiosink' changed state to 2(READY) successfully                                  
0:00:09.985601000  4966 0x10001050 INFO            GST_STATES gstelement.c:2152:gst_element_continue_state:<volume> completed state change to READY                                                    
0:00:09.987073000  4966 0x10001050 INFO            GST_STATES gstelement.c:2165:gst_element_continue_state:<volume> posting state-changed NULL to READY                                                
0:00:09.988990000  4966 0x10001050 INFO            GST_STATES gstbin.c:2328:gst_bin_change_state_func:<abin> child 'volume' changed state to 2(READY) successfully                                     
0:00:09.990804000  4966 0x10001050 INFO            GST_STATES gstelement.c:2152:gst_element_continue_state:<aresample> completed state change to READY                                                 
0:00:09.992247000  4966 0x10001050 INFO            GST_STATES gstelement.c:2165:gst_element_continue_state:<aresample> posting state-changed NULL to READY                                             
0:00:09.994647000  4966 0x10001050 INFO            GST_STATES gstbin.c:2328:gst_bin_change_state_func:<abin> child 'aresample' changed state to 2(READY) successfully                                  
0:00:09.996668000  4966 0x10001050 INFO            GST_STATES gstelement.c:2152:gst_element_continue_state:<aconv> completed state change to READY                                                     
0:00:09.999774000  4966 0x10001050 INFO            GST_STATES gstelement.c:2165:gst_element_continue_state:<aconv> posting state-changed NULL to READY                                                 
0:00:10.001996000  4966 0x10001050 INFO            GST_STATES gstbin.c:2328:gst_bin_change_state_func:<abin> child 'aconv' changed state to 2(READY) successfully                                      
0:00:10.003694000  4966 0x10001050 INFO            GST_STATES gstelement.c:2152:gst_element_continue_state:<abin> completed state change to READY                                                      
0:00:10.005160000  4966 0x10001050 INFO            GST_STATES gstelement.c:2165:gst_element_continue_state:<abin> posting state-changed NULL to READY                                                  
0:00:10.007349000  4966 0x10001050 INFO              GST_PADS gstpad.c:1849:gst_pad_link_prepare: trying to link audiotee:src0 and abin:sink                                                           
0:00:10.044300000  4966 0x10001050 INFO              GST_PADS gstpad.c:2022:gst_pad_link: linked audiotee:src0 and abin:sink, successful                                                               
0:00:10.046481000  4966 0x10001050 DEBUG             playbin2 gstplaybin2.c:2035:no_more_pads_cb:<playbin20> (null)                                                                                    
0:00:10.048342000  4966 0x10001050 INFO            GST_STATES gstelement.c:2125:gst_element_continue_state:<source> committing state from NULL to READY, pending PAUSED                                
0:00:10.050259000  4966 0x10001050 INFO            GST_STATES gstelement.c:2134:gst_element_continue_state:<source> continue state change READY to PAUSED, final PAUSED                                
0:00:10.062950000  4966 0x10001050 LOG                   cdio gstcdiocddasrc.c:141:gst_cdio_cdda_src_get_default_device:<source> returning default device: /dev/sr0                                    
0:00:10.064586000  4966 0x10001050 LOG            cddabasesrc gstcddabasesrc.c:1379:gst_cdda_base_src_start:<source> opening device /dev/sr0                                                           
0:00:10.065911000  4966 0x10001050 LOG                   cdio gstcdiocddasrc.c:231:gst_cdio_cdda_src_open:<source> trying to open device /dev/sr0                                                      
0:00:10.126982000  4966 0x10001050 LOG                   cdio gstcdiocddasrc.c:237:gst_cdio_cdda_src_open:<source> discmode: 0                                                                         
0:00:10.280987000  4966 0x10001050 DEBUG                 cdio gstcdio.c:56:gst_cdio_add_cdtext_field:<source> CD-TEXT: album = One Voice                                                               
0:00:10.282795000  4966 0x10001050 DEBUG                 cdio gstcdio.c:40:gst_cdio_add_cdtext_field:<source> empty CD-TEXT field 3 (genre)                                                            
0:00:10.284439000  4966 0x10001050 DEBUG                 cdio gstcdio.c:92:gst_cdio_add_cdtext_album_tags: (null)                                                                                      
0:00:10.287330000  4966 0x10001050 LOG                   cdio gstcdiocddasrc.c:254:gst_cdio_cdda_src_open:<source> 11 tracks, first track: 1                                                           
0:00:10.291450000  4966 0x10001050 DEBUG                 cdio gstcdio.c:56:gst_cdio_add_cdtext_field:<source> CD-TEXT: artist = Billy Gilman                                                           
0:00:10.294569000  4966 0x10001050 DEBUG                 cdio gstcdio.c:56:gst_cdio_add_cdtext_field:<source> CD-TEXT: title = Little Things                                                           
0:00:10.299254000  4966 0x10001050 DEBUG          cddabasesrc gstcddabasesrc.c:1022:gst_cdda_base_src_add_track:<source> (null)                                                                        
0:00:10.301769000  4966 0x10001050 DEBUG                 cdio gstcdio.c:56:gst_cdio_add_cdtext_field:<source> CD-TEXT: artist = Billy Gilman                                                           
0:00:10.303663000  4966 0x10001050 DEBUG                 cdio gstcdio.c:56:gst_cdio_add_cdtext_field:<source> CD-TEXT: title = I Think She Likes Me                                                    
0:00:10.305090000  4966 0x10001050 DEBUG          cddabasesrc gstcddabasesrc.c:1022:gst_cdda_base_src_add_track:<source> (null)                                                                        
0:00:10.306706000  4966 0x10001050 DEBUG                 cdio gstcdio.c:56:gst_cdio_add_cdtext_field:<source> CD-TEXT: artist = Billy Gilman                                                           
0:00:10.308237000  4966 0x10001050 DEBUG                 cdio gstcdio.c:56:gst_cdio_add_cdtext_field:<source> CD-TEXT: title = What's Forever For                                                      
0:00:10.309538000  4966 0x10001050 DEBUG          cddabasesrc gstcddabasesrc.c:1022:gst_cdda_base_src_add_track:<source> (null)                                                                        
0:00:10.311229000  4966 0x10001050 DEBUG                 cdio gstcdio.c:56:gst_cdio_add_cdtext_field:<source> CD-TEXT: artist = Billy Gilman                                                           
0:00:10.312702000  4966 0x10001050 DEBUG                 cdio gstcdio.c:56:gst_cdio_add_cdtext_field:<source> CD-TEXT: title = One Voice                                                               
0:00:10.314076000  4966 0x10001050 DEBUG          cddabasesrc gstcddabasesrc.c:1022:gst_cdda_base_src_add_track:<source> (null)                                                                        
0:00:10.315622000  4966 0x10001050 DEBUG                 cdio gstcdio.c:56:gst_cdio_add_cdtext_field:<source> CD-TEXT: artist = Billy Gilman                                                           
0:00:10.318193000  4966 0x10001050 DEBUG                 cdio gstcdio.c:56:gst_cdio_add_cdtext_field:<source> CD-TEXT: title = Spend Another Night                                                     
0:00:10.319641000  4966 0x10001050 DEBUG          cddabasesrc gstcddabasesrc.c:1022:gst_cdda_base_src_add_track:<source> (null)                                                                        
0:00:10.321653000  4966 0x10001050 DEBUG                 cdio gstcdio.c:56:gst_cdio_add_cdtext_field:<source> CD-TEXT: artist = Billy Gilman                                                           
0:00:10.323368000  4966 0x10001050 DEBUG                 cdio gstcdio.c:56:gst_cdio_add_cdtext_field:<source> CD-TEXT: title = Little Bitty Pretty One                                                 
0:00:10.325211000  4966 0x10001050 DEBUG          cddabasesrc gstcddabasesrc.c:1022:gst_cdda_base_src_add_track:<source> (null)                                                                        
0:00:10.326944000  4966 0x10001050 DEBUG                 cdio gstcdio.c:56:gst_cdio_add_cdtext_field:<source> CD-TEXT: artist = Billy Gilman                                                           
0:00:10.328664000  4966 0x10001050 DEBUG                 cdio gstcdio.c:56:gst_cdio_add_cdtext_field:<source> CD-TEXT: title = The Snake Song                                                          
0:00:10.330282000  4966 0x10001050 DEBUG          cddabasesrc gstcddabasesrc.c:1022:gst_cdda_base_src_add_track:<source> (null)                                                                        
0:00:10.331805000  4966 0x10001050 DEBUG                 cdio gstcdio.c:56:gst_cdio_add_cdtext_field:<source> CD-TEXT: artist = Billy Gilman                                                           
0:00:10.333300000  4966 0x10001050 DEBUG                 cdio gstcdio.c:56:gst_cdio_add_cdtext_field:<source> CD-TEXT: title = I Wanna Get To Ya                                                       
0:00:10.334665000  4966 0x10001050 DEBUG          cddabasesrc gstcddabasesrc.c:1022:gst_cdda_base_src_add_track:<source> (null)                                                                        
0:00:10.336204000  4966 0x10001050 DEBUG                 cdio gstcdio.c:56:gst_cdio_add_cdtext_field:<source> CD-TEXT: artist = Billy Gilman                                                           
0:00:10.338877000  4966 0x10001050 DEBUG                 cdio gstcdio.c:56:gst_cdio_add_cdtext_field:<source> CD-TEXT: title = Oklahoma                                                                
0:00:10.340325000  4966 0x10001050 DEBUG          cddabasesrc gstcddabasesrc.c:1022:gst_cdda_base_src_add_track:<source> (null)                                                                        
0:00:10.341852000  4966 0x10001050 DEBUG                 cdio gstcdio.c:56:gst_cdio_add_cdtext_field:<source> CD-TEXT: artist = Billy Gilman                                                           
0:00:10.343370000  4966 0x10001050 DEBUG                 cdio gstcdio.c:56:gst_cdio_add_cdtext_field:<source> CD-TEXT: title = There's A Hero                                                          
0:00:10.344778000  4966 0x10001050 DEBUG          cddabasesrc gstcddabasesrc.c:1022:gst_cdda_base_src_add_track:<source> (null)                                                                        
0:00:10.346343000  4966 0x10001050 DEBUG                 cdio gstcdio.c:56:gst_cdio_add_cdtext_field:<source> CD-TEXT: artist = Billy Gilman                                                           
0:00:10.347824000  4966 0x10001050 DEBUG                 cdio gstcdio.c:56:gst_cdio_add_cdtext_field:<source> CD-TEXT: title = (Bonus) 'Til I Can Make It On My Own                                    
0:00:10.349336000  4966 0x10001050 DEBUG          cddabasesrc gstcddabasesrc.c:1022:gst_cdda_base_src_add_track:<source> (null)                                                                        
0:00:10.350589000  4966 0x10001050 DEBUG          cddabasesrc gstcddabasesrc.c:1210:gst_cdda_base_src_calculate_cddb_id:<source> track 01: lsn    150 (00:02), length: 145 seconds (02:25)             
0:00:10.352236000  4966 0x10001050 DEBUG          cddabasesrc gstcddabasesrc.c:1210:gst_cdda_base_src_calculate_cddb_id:<source> track 02: lsn  11060 (02:27), length: 187 seconds (03:07)             
0:00:10.353710000  4966 0x10001050 DEBUG          cddabasesrc gstcddabasesrc.c:1210:gst_cdda_base_src_calculate_cddb_id:<source> track 03: lsn  25120 (05:34), length: 207 seconds (03:27)             
0:00:10.355369000  4966 0x10001050 DEBUG          cddabasesrc gstcddabasesrc.c:1210:gst_cdda_base_src_calculate_cddb_id:<source> track 04: lsn  40687 (09:02), length: 250 seconds (04:10)             
0:00:10.357821000  4966 0x10001050 DEBUG          cddabasesrc gstcddabasesrc.c:1210:gst_cdda_base_src_calculate_cddb_id:<source> track 05: lsn  59470 (13:12), length: 226 seconds (03:46)             
0:00:10.359363000  4966 0x10001050 DEBUG          cddabasesrc gstcddabasesrc.c:1210:gst_cdda_base_src_calculate_cddb_id:<source> track 06: lsn  76430 (16:59), length: 152 seconds (02:32)             
0:00:10.361018000  4966 0x10001050 DEBUG          cddabasesrc gstcddabasesrc.c:1210:gst_cdda_base_src_calculate_cddb_id:<source> track 07: lsn  87835 (19:31), length: 192 seconds (03:12)             
0:00:10.362965000  4966 0x10001050 DEBUG          cddabasesrc gstcddabasesrc.c:1210:gst_cdda_base_src_calculate_cddb_id:<source> track 08: lsn 102250 (22:43), length: 217 seconds (03:37)             
0:00:10.364795000  4966 0x10001050 DEBUG          cddabasesrc gstcddabasesrc.c:1210:gst_cdda_base_src_calculate_cddb_id:<source> track 09: lsn 118585 (26:21), length: 244 seconds (04:04)             
0:00:10.366554000  4966 0x10001050 DEBUG          cddabasesrc gstcddabasesrc.c:1210:gst_cdda_base_src_calculate_cddb_id:<source> track 10: lsn 136920 (30:25), length: 206 seconds (03:26)             
0:00:10.368271000  4966 0x10001050 DEBUG          cddabasesrc gstcddabasesrc.c:1210:gst_cdda_base_src_calculate_cddb_id:<source> track 11: lsn 152430 (33:52), length: 190 seconds (03:10)             
0:00:10.370015000  4966 0x10001050 DEBUG          cddabasesrc gstcddabasesrc.c:1224:gst_cdda_base_src_calculate_cddb_id:<source> first_sector = 150 = 2 secs (00:02)                                   
0:00:10.371609000  4966 0x10001050 DEBUG          cddabasesrc gstcddabasesrc.c:1226:gst_cdda_base_src_calculate_cddb_id:<source> last_sector  = 166747 = 2223 secs (37:03)                             
0:00:10.373213000  4966 0x10001050 DEBUG          cddabasesrc gstcddabasesrc.c:1232:gst_cdda_base_src_calculate_cddb_id:<source> total length = 2221 secs (37:01), added title lengths = 2216 seconds (36:56)                                                                                                                                                                                                 
0:00:10.375682000  4966 0x10001050 DEBUG          cddabasesrc gstcddabasesrc.c:1251:gst_cdda_base_src_calculate_cddb_id:<source> cddb discid = 7d08ad0b 11 150 11060 25120 40687 59470 76430 87835 102250 118585 136920 152430 2221                                                                                                                                                                           
0:00:10.379954000  4966 0x10001050 DEBUG          cddabasesrc gstcddabasesrc.c:1149:gst_cddabasesrc_calculate_musicbrainz_discid:<source> musicbrainz-discid      = azVBzLSg8fBbVCaufDvqbpO64pE-       
0:00:10.381432000  4966 0x10001050 DEBUG          cddabasesrc gstcddabasesrc.c:1150:gst_cddabasesrc_calculate_musicbrainz_discid:<source> musicbrainz-discid-full = 01 0B 00028B5B 00000096 00002B34 00006220 00009EEF 0000E84E 00012A8E 0001571B 00018F6A 0001CF39 000216D8 0002536E                                                                                                                         
0:00:10.383202000  4966 0x10001050 LOG            cddabasesrc gstcddabasesrc.c:429:gst_cdda_base_src_convert:<source> converting value 10910 from sector into time                                     
0:00:10.384688000  4966 0x10001050 LOG            cddabasesrc gstcddabasesrc.c:535:gst_cdda_base_src_convert:<source> returning 145466666666                                                           
0:00:10.386302000  4966 0x10001050 LOG            cddabasesrc gstcddabasesrc.c:429:gst_cdda_base_src_convert:<source> converting value 14060 from sector into time                                     
0:00:10.387847000  4966 0x10001050 LOG            cddabasesrc gstcddabasesrc.c:535:gst_cdda_base_src_convert:<source> returning 187466666666                                                           
0:00:10.389463000  4966 0x10001050 LOG            cddabasesrc gstcddabasesrc.c:429:gst_cdda_base_src_convert:<source> converting value 15567 from sector into time                                     
0:00:10.390905000  4966 0x10001050 LOG            cddabasesrc gstcddabasesrc.c:535:gst_cdda_base_src_convert:<source> returning 207560000000                                                           
0:00:10.392504000  4966 0x10001050 LOG            cddabasesrc gstcddabasesrc.c:429:gst_cdda_base_src_convert:<source> converting value 18783 from sector into time                                     
0:00:10.393935000  4966 0x10001050 LOG            cddabasesrc gstcddabasesrc.c:535:gst_cdda_base_src_convert:<source> returning 250440000000                                                           
0:00:10.395534000  4966 0x10001050 LOG            cddabasesrc gstcddabasesrc.c:429:gst_cdda_base_src_convert:<source> converting value 16960 from sector into time                                     
0:00:10.397978000  4966 0x10001050 LOG            cddabasesrc gstcddabasesrc.c:535:gst_cdda_base_src_convert:<source> returning 226133333333                                                           
0:00:10.399686000  4966 0x10001050 LOG            cddabasesrc gstcddabasesrc.c:429:gst_cdda_base_src_convert:<source> converting value 11405 from sector into time                                     
0:00:10.401160000  4966 0x10001050 LOG            cddabasesrc gstcddabasesrc.c:535:gst_cdda_base_src_convert:<source> returning 152066666666                                                           
0:00:10.402721000  4966 0x10001050 LOG            cddabasesrc gstcddabasesrc.c:429:gst_cdda_base_src_convert:<source> converting value 14415 from sector into time                                     
0:00:10.404901000  4966 0x10001050 LOG            cddabasesrc gstcddabasesrc.c:535:gst_cdda_base_src_convert:<source> returning 192200000000                                                           
0:00:10.406775000  4966 0x10001050 LOG            cddabasesrc gstcddabasesrc.c:429:gst_cdda_base_src_convert:<source> converting value 16335 from sector into time                                     
0:00:10.408471000  4966 0x10001050 LOG            cddabasesrc gstcddabasesrc.c:535:gst_cdda_base_src_convert:<source> returning 217800000000                                                           
0:00:10.410277000  4966 0x10001050 LOG            cddabasesrc gstcddabasesrc.c:429:gst_cdda_base_src_convert:<source> converting value 18335 from sector into time                                     
0:00:10.411746000  4966 0x10001050 LOG            cddabasesrc gstcddabasesrc.c:535:gst_cdda_base_src_convert:<source> returning 244466666666                                                           
0:00:10.413462000  4966 0x10001050 LOG            cddabasesrc gstcddabasesrc.c:429:gst_cdda_base_src_convert:<source> converting value 15510 from sector into time                                     
0:00:10.414901000  4966 0x10001050 LOG            cddabasesrc gstcddabasesrc.c:535:gst_cdda_base_src_convert:<source> returning 206800000000                                                           
0:00:10.416536000  4966 0x10001050 LOG            cddabasesrc gstcddabasesrc.c:429:gst_cdda_base_src_convert:<source> converting value 14317 from sector into time                                     
0:00:10.419162000  4966 0x10001050 LOG            cddabasesrc gstcddabasesrc.c:535:gst_cdda_base_src_convert:<source> returning 190893333333                                                           
0:00:10.420771000  4966 0x10001050 DEBUG          cddabasesrc gstcddabasesrc.c:1297:gst_cdda_base_src_add_tags: (null)                                                                                 
0:00:10.422173000  4966 0x10001050 LOG            cddabasesrc gstcddabasesrc.c:1444:gst_cdda_base_src_start:<source> seek to track 1                                                                   
0:00:10.423531000  4966 0x10001050 LOG            cddabasesrc gstcddabasesrc.c:1451:gst_cdda_base_src_start:<source> starting at sector 0                                                              
0:00:10.425362000  4966 0x10001050 LOG            cddabasesrc gstcddabasesrc.c:569:gst_cdda_base_src_query:<source> handling duration query                                                            
0:00:10.427517000  4966 0x10001050 LOG            cddabasesrc gstcddabasesrc.c:1065:gst_cdda_base_src_update_duration:<source> duration updated to 99:99:99.999999999                                  
0:00:10.474614000  4966 0x10001050 DEBUG          cddabasesrc gstcddabasesrc.c:688:gst_cdda_base_src_do_seek:<source> segment 0:00:00.000000000-99:99:99.999999999                                     
0:00:10.479240000  4966 0x10001050 LOG            cddabasesrc gstcddabasesrc.c:429:gst_cdda_base_src_convert:<source> converting value 0 from time into sector                                         
0:00:10.481963000  4966 0x10001050 LOG            cddabasesrc gstcddabasesrc.c:535:gst_cdda_base_src_convert:<source> returning 0                                                                      
0:00:10.483443000  4966 0x10001050 DEBUG          cddabasesrc gstcddabasesrc.c:712:gst_cdda_base_src_do_seek:<source> seek'd to sector 0                                                               
0:00:10.484962000  4966 0x10001050 INFO             GST_EVENT gstevent.c:590:gst_event_new_new_segment_full: 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:10.490213000  4966 0x10001050 INFO            GST_STATES gstelement.c:2152:gst_element_continue_state:<source> completed state change to PAUSED                                                   
0:00:10.491949000  4966 0x10001050 INFO            GST_STATES gstelement.c:2165:gst_element_continue_state:<source> posting state-changed READY to PAUSED                                              
0:00:10.494065000  4966 0x10001050 INFO            GST_STATES gstbin.c:2328:gst_bin_change_state_func:<uridecodebin0> child 'source' changed state to 3(PAUSED) successfully                           
0:00:10.495903000  4966 0x10001050 INFO            GST_STATES gstelement.c:2152:gst_element_continue_state:<uridecodebin0> completed state change to PAUSED                                            
0:00:10.498313000  4966 0x10001050 INFO            GST_STATES gstelement.c:2165:gst_element_continue_state:<uridecodebin0> posting state-changed READY to PAUSED                                       
0:00:10.500386000  4966 0x10001050 DEBUG             playbin2 gstplaybin2.c:2256:group_set_locked_state_unlocked:<playbin20> locked_state 0 on group 0x1006c400                                        
0:00:10.505273000  4966 0x10001050 INFO            GST_STATES gstbin.c:2334:gst_bin_change_state_func:<abin> child 'audiosink' is changing state asynchronously to PAUSED                              
0:00:10.507598000  4966 0x10001050 INFO            GST_STATES gstelement.c:2152:gst_element_continue_state:<volume> completed state change to PAUSED                                                   
0:00:10.509046000  4966 0x10001050 INFO            GST_STATES gstelement.c:2165:gst_element_continue_state:<volume> posting state-changed READY to PAUSED                                              
0:00:10.510980000  4966 0x10001050 INFO            GST_STATES gstbin.c:2328:gst_bin_change_state_func:<abin> child 'volume' changed state to 3(PAUSED) successfully                                    
0:00:10.513077000  4966 0x10001050 INFO            GST_STATES gstelement.c:2152:gst_element_continue_state:<aresample> completed state change to PAUSED
0:00:10.514417000  4966 0x10001050 INFO            GST_STATES gstelement.c:2165:gst_element_continue_state:<aresample> posting state-changed READY to PAUSED
0:00:10.516430000  4966 0x10001050 INFO            GST_STATES gstbin.c:2328:gst_bin_change_state_func:<abin> child 'aresample' changed state to 3(PAUSED) successfully
0:00:10.520855000  4966 0x10052120 LOG            cddabasesrc gstcddabasesrc.c:1541:gst_cdda_base_src_create:<source> (null)
0:00:10.523983000  4966 0x10052120 INFO              GST_PADS gstpad.c:3315:gst_pad_event_default_dispatch:<audiotee:sink> Sending event 0x10083260 (tag) to all internally linked pads
0:00:10.525981000  4966 0x10052120 INFO             GST_EVENT gstpad.c:4762:gst_pad_send_event:<abin:sink> Received event on flushing pad. Discarding
0:00:10.529057000  4966 0x10052120 LOG            cddabasesrc gstcddabasesrc.c:569:gst_cdda_base_src_query:<source> handling duration query
0:00:10.530736000  4966 0x10052120 LOG            cddabasesrc gstcddabasesrc.c:429:gst_cdda_base_src_convert:<source> converting value 10910 from sector into time
0:00:10.532262000  4966 0x10052120 LOG            cddabasesrc gstcddabasesrc.c:535:gst_cdda_base_src_convert:<source> returning 145466666666
0:00:10.534049000  4966 0x10052120 LOG            cddabasesrc gstcddabasesrc.c:610:gst_cdda_base_src_query: duration: 10910 sectors, 145466666666 in format time
0:00:10.536150000  4966 0x10052120 LOG            cddabasesrc gstcddabasesrc.c:1065:gst_cdda_base_src_update_duration:<source> duration updated to 0:02:25.466666666
0:00:10.539070000  4966 0x10052120 LOG            cddabasesrc gstcddabasesrc.c:1551:gst_cdda_base_src_create:<source> asking for sector 0
0:00:10.519609000  4966 0x10001050 INFO            GST_STATES gstelement.c:2152:gst_element_continue_state:<aconv> completed state change to PAUSED
0:00:10.542404000  4966 0x10001050 INFO            GST_STATES gstelement.c:2165:gst_element_continue_state:<aconv> posting state-changed READY to PAUSED
0:00:10.544383000  4966 0x10001050 INFO            GST_STATES gstbin.c:2328:gst_bin_change_state_func:<abin> child 'aconv' changed state to 3(PAUSED) successfully
0:00:10.546572000  4966 0x10001050 INFO            GST_STATES gstbin.c:2334:gst_bin_change_state_func:<playsink0> child 'abin' is changing state asynchronously to PAUSED
0:00:10.548506000  4966 0x10001050 INFO            GST_STATES gstelement.c:2152:gst_element_continue_state:<audiotee> completed state change to PAUSED
0:00:10.549986000  4966 0x10001050 INFO            GST_STATES gstbin.c:2328:gst_bin_change_state_func:<playsink0> child 'audiotee' changed state to 3(PAUSED) successfully
0:00:10.551868000  4966 0x10001050 INFO            GST_STATES gstbin.c:2334:gst_bin_change_state_func:<playbin20> child 'playsink0' is changing state asynchronously to PAUSED
0:00:10.553655000  4966 0x10001050 INFO            GST_STATES gstelement.c:2152:gst_element_continue_state:<inputselector0> completed state change to PAUSED
0:00:10.555148000  4966 0x10001050 INFO            GST_STATES gstbin.c:2328:gst_bin_change_state_func:<playbin20> child 'inputselector0' changed state to 3(PAUSED) successfully
0:00:10.558091000  4966 0x10001050 INFO            GST_STATES gstelement.c:2152:gst_element_continue_state:<source> completed state change to PAUSED
0:00:10.559681000  4966 0x10001050 INFO            GST_STATES gstbin.c:2328:gst_bin_change_state_func:<uridecodebin0> child 'source' changed state to 3(PAUSED) successfully
0:00:10.561358000  4966 0x10001050 INFO            GST_STATES gstelement.c:2152:gst_element_continue_state:<uridecodebin0> completed state change to PAUSED
0:00:10.562700000  4966 0x10001050 INFO            GST_STATES gstbin.c:2328:gst_bin_change_state_func:<playbin20> child 'uridecodebin0' changed state to 3(PAUSED) successfully
Pipeline is PREROLLING ...
0:00:10.587486000  4966 0x10052120 LOG            cddabasesrc gstcddabasesrc.c:569:gst_cdda_base_src_query:<source> handling position query
0:00:10.588869000  4966 0x10052120 LOG            cddabasesrc gstcddabasesrc.c:429:gst_cdda_base_src_convert:<source> converting value 0 from sector into time
0:00:10.590664000  4966 0x10052120 LOG            cddabasesrc gstcddabasesrc.c:535:gst_cdda_base_src_convert:<source> returning 0
0:00:10.592107000  4966 0x10052120 LOG            cddabasesrc gstcddabasesrc.c:648:gst_cdda_base_src_query: position: sector 0, 0 in format time
0:00:10.593794000  4966 0x10052120 LOG            cddabasesrc gstcddabasesrc.c:569:gst_cdda_base_src_query:<source> handling position query
0:00:10.595302000  4966 0x10052120 LOG            cddabasesrc gstcddabasesrc.c:429:gst_cdda_base_src_convert:<source> converting value 1 from sector into time
0:00:10.597765000  4966 0x10052120 LOG            cddabasesrc gstcddabasesrc.c:535:gst_cdda_base_src_convert:<source> returning 13333333
0:00:10.599319000  4966 0x10052120 LOG            cddabasesrc gstcddabasesrc.c:648:gst_cdda_base_src_query: position: sector 1, 13333333 in format time
0:00:10.600852000  4966 0x10052120 LOG            cddabasesrc gstcddabasesrc.c:1587:gst_cdda_base_src_create:<source> pushing sector 0 with timestamp 0:00:00.000000000
0:00:10.642919000  4966 0x10052120 INFO             GST_EVENT gstevent.c:590:gst_event_new_new_segment_full: 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:10.645192000  4966 0x10052120 INFO              GST_PADS gstpad.c:3315:gst_pad_event_default_dispatch:<audiotee:sink> Sending event 0x100832f0 (newsegment) to all internally linked pads
0:00:10.747418000  4966 0x10052120 INFO          audioconvert audioconvert.c:459:audio_convert_prepare_context: use int mixing
0:00:10.748727000  4966 0x10052120 INFO          audioconvert audioconvert.c:465:audio_convert_prepare_context: unitsizes: 4 -> 4
0:00:10.750049000  4966 0x10052120 INFO          audioconvert audioconvert.c:475:audio_convert_prepare_context: in default 0, mix passthrough 1, out default 0
0:00:10.815787000  4966 0x10052120 INFO            GST_STATES gstbin.c:2712:bin_handle_async_done:<abin> committing state from READY to PAUSED, old pending PAUSED
0:00:10.817812000  4966 0x10052120 INFO            GST_STATES gstbin.c:2727:bin_handle_async_done:<abin> completed state change, pending VOID



Expected results:
audio cd playback to start

Does this happen every time?
yes.

Other information:
it still works with gst-launch cdiocddasrc ! alsasink
Comment 1 Tim-Philipp Müller 2009-05-14 00:14:54 UTC
Could you make a full GST_DEBUG=*:5 log of the failure please (and attach it)?

The bug title says 'broken since' - so: since when?
Comment 2 Andreas Frisch 2009-05-14 07:31:38 UTC
good point! i forgot to put that. it's broken since release 0.10.23 (also without the latest git changes)
0.10.22.3 used to work
Comment 3 Andreas Frisch 2009-05-14 07:41:41 UTC
Created attachment 134629 [details]
full debug log of this case

GST_DEBUG=*:5 gst-launch playbin2 uri=cdda://1 --gst-debug-no-color >playbin2_cdda_broken.log 2>&1
Comment 4 Sebastian Dröge (slomo) 2009-05-15 05:07:09 UTC
This was probably fixed by http://cgit.freedesktop.org/gstreamer/gst-plugins-base/commit/?id=768cadf0935f892b8e6aa4696f0f760bbf19fc2a

Can you confirm and close this bug then? :)
Comment 5 Andreas Frisch 2009-05-15 09:06:44 UTC
aye! works with thaytan's patch - thx a lot!
Comment 6 Andreas Frisch 2009-05-15 10:04:17 UTC
playback's choppy though :/ 
Comment 7 Wim Taymans 2009-05-19 11:13:01 UTC
We need to add a queue somewhere because cdparanoia can stall quite a bit.
Comment 8 Wim Taymans 2009-05-19 13:24:01 UTC
Can people please test and see if this is fine. There is no tuning yet, if this does not work quite right, please experiment with:

  gst-launch cdparanoiasrc ! queue2 ! pulsesink

And the queue properties until you find something that works for you and then post the values here.


commit f11edb626f9da2a92e0a4dedb6636ac723e7a561
Author: Wim Taymans <wim.taymans@collabora.co.uk>
Date:   Tue May 19 15:20:27 2009 +0200

    uridecodebin: add queue after cdda://
    
    Add a queue2 after the raw output pads of certain sources such as those for uris
    like cdda://
    
    No tuning of the queue is done yet as the defaults seem to work fine for me.
    
    Fixes #582528
Comment 9 Andreas Frisch 2009-05-19 15:32:19 UTC
great! works on our dreambox architecture also without chaning the defaults.
thanks a lot once again!
Comment 10 Wim Taymans 2009-05-25 09:08:18 UTC
*** Bug 583721 has been marked as a duplicate of this bug. ***
Comment 11 Jan Schmidt 2009-05-25 09:30:27 UTC
It occurs to me to wonder, maybe we could make cdparanoiasrc respond to QoS messages by dropping the paranoia level, if it can do so on the fly.
Comment 12 Jonathan Matthew 2009-06-18 05:54:50 UTC
I'm still seeing this, and I can't seem to find any queue parameters that work, even setting paranoia-mode to 0.

I can't remember when cdparanoia last worked properly, but since the cdparanoia library hasn't been changed significantly in about a year (according to the package changelog) and the gst plugin hasn't changed much in over two years, I'm pretty sure something else broke it.
Comment 13 Jonathan Matthew 2009-06-18 08:16:58 UTC
Or maybe not.  Lowering cdparanoia's sector cache size from the current default of 1200 to the previous 150 results in correct playback.
Comment 14 Jonathan Matthew 2009-06-18 09:11:45 UTC
and now I can get it to work just with queue2 parameters: max-size-buffers=0 max-size-time=8000000000.  The default max-size-time value also works, but 6 seconds is about as low as it can go (probably higher with lower read speeds?).  Should have realised sooner that max-size-buffers=100 was the problem.
Comment 15 Sebastian Dröge (slomo) 2009-09-09 13:06:15 UTC
*** Bug 593021 has been marked as a duplicate of this bug. ***
Comment 16 williamnorfleet2000 2009-09-17 16:59:52 UTC
In case the information is helpful, I have not hit upon a combination of queue2 properties that fixes grossly choppy audio CD playback on a Thinkpad 600E (described in more detail in Bug 593021 which has been closed as a duplicate of this Bug).