Lo?c Minier wrote: > Hi, > > On lun, avr 11, 2005, Kevin Brown wrote: > > Running rhythmbox with the '-d' option produces no output once the UI > > has hung. Running it with the 'gst-debug-level=5' option produces the > > following debug statements continuously, once the UI has hung: > > > > DEBUG (0x80d84c8 - 309174:09:41.606180000) GST_THREAD(22151) > > gstthread.c(406):gst_thread_sync:<pipeline> wait > > LOG (0x80d84c8 - 309174:09:41.608127000) GST_THREAD(22151) > > gstthread.c(400):gst_thread_sync:<pipeline> syncing thread... > > DEBUG (0x80d84c8 - 309174:09:41.608249000) GST_THREAD(22151) > > gstthread.c(332):gst_thread_release_children_locks:<pipeline> waking > > element "src" > > I just read the bug log again, and this seemed like an interesting > trail after all. This looks like a dead lock in releasing the playing > pipeline. > > Could you get more of those? Is this happening in a loop? Could you > paste the first lines before entering this loop?
Yeah, it's happening in a loop, it seems. But note that the loop in question only happens *after* the sound is messed up. At that point, rhythmbox thinks it's playing the song but only a once-per-second "pop" comes out of the speakers. There are some 7000 lines of debugging info between the time I push the "play" button and the time I push the "pause" button. However, the debug output itself has at that point stopped for some time. Here are the last few (well, okay, a little more than a few) lines right before I push the "pause" button (at this point, the periodic "popping" sound has been going on for some time without generating any debug output at all): LOG (0x8331e10 - 309872:04:09.890771000) GST_SCHEDULING(19621) gstpad.c(3297):gst_pad_push:<audioconvert:src> calling chainhandler &gst_pad_call_chain_function of peer pad audioscale:sink LOG (0x8331e10 - 309872:04:09.890886000) GST_DATAFLOW(19621) gstpad.c(4496):gst_pad_call_chain_function:<audioscale:sink> calling chain function with buffer 0x8109104 (size 2048, refcount 1) DEBUG (0x8331e10 - 309872:04:09.891037000) audioscale(19621) gstaudioscale.c(617):gst_audioscale_chain: gst_audioscale_chain: got buffer of 2048 bytes in 'audioscale' DEBUG (0x8331e10 - 309872:04:09.891163000) audioscale(19621) gstaudioscale.c(622):gst_audioscale_chain: doing gstresample DEBUG (0x8331e10 - 309872:04:09.891538000) audioscale(19621) gstaudioscale.c(394):gst_audioscale_get_buffer: size requested: 3970 irate: 1.000000 orate: 1.953125 LOG (0x8331e10 - 309872:04:09.891766000) GST_BUFFER(19621) gstbuffer.c(211):gst_buffer_new: new 0x8109178 LOG (0x8331e10 - 309872:04:09.894545000) GST_BUFFER(19621) gstdata.c(239):gst_data_unref: 0x8109104 1->0 DEBUG (0x8331e10 - 309872:04:09.894743000) audioscale(19621) gstaudioscale.c(633):gst_audioscale_chain: doing gst_audioscale_increase_rate LOG (0x8331e10 - 309872:04:09.894920000) GST_BUFFER(19621) gstbuffer.c(211):gst_buffer_new: new 0x8109104 DEBUG (0x8331e10 - 309872:04:09.895049000) audioscale(19621) gstaudioscale.c(462):gst_audioscale_increase_rate: iteration = 0 channels = 1 in size = 3970 out size = 7940 out rate = 3.906250 LOG (0x8331e10 - 309872:04:09.895191000) GST_BUFFER(19621) gstdata.c(239):gst_data_unref: 0x8109178 1->0 DEBUG (0x8331e10 - 309872:04:09.895288000) audioscale(19621) gstaudioscale.c(633):gst_audioscale_chain: doing gst_audioscale_increase_rate LOG (0x8331e10 - 309872:04:09.895611000) GST_BUFFER(19621) gstbuffer.c(211):gst_buffer_new: new 0x8109178 DEBUG (0x8331e10 - 309872:04:09.895711000) audioscale(19621) gstaudioscale.c(462):gst_audioscale_increase_rate: iteration = 1 channels = 1 in size = 7940 out size = 15880 out rate = 7.812500 LOG (0x8331e10 - 309872:04:09.895875000) GST_BUFFER(19621) gstdata.c(239):gst_data_unref: 0x8109104 1->0 DEBUG (0x8331e10 - 309872:04:09.895976000) audioscale(19621) gstaudioscale.c(633):gst_audioscale_chain: doing gst_audioscale_increase_rate LOG (0x8331e10 - 309872:04:09.896072000) GST_BUFFER(19621) gstbuffer.c(211):gst_buffer_new: new 0x8109104 DEBUG (0x8331e10 - 309872:04:09.896166000) audioscale(19621) gstaudioscale.c(462):gst_audioscale_increase_rate: iteration = 2 channels = 1 in size = 15880 out size = 31760 out rate = 15.625000 LOG (0x8331e10 - 309872:04:09.896583000) GST_BUFFER(19621) gstdata.c(239):gst_data_unref: 0x8109178 1->0 DEBUG (0x8331e10 - 309872:04:09.896737000) audioscale(19621) gstaudioscale.c(633):gst_audioscale_chain: doing gst_audioscale_increase_rate LOG (0x8331e10 - 309872:04:09.896844000) GST_BUFFER(19621) gstbuffer.c(211):gst_buffer_new: new 0x8109178 DEBUG (0x8331e10 - 309872:04:09.896968000) audioscale(19621) gstaudioscale.c(462):gst_audioscale_increase_rate: iteration = 3 channels = 1 in size = 31760 out size = 63520 out rate = 31.250000 LOG (0x8331e10 - 309872:04:09.897503000) GST_BUFFER(19621) gstdata.c(239):gst_data_unref: 0x8109104 1->0 DEBUG (0x8331e10 - 309872:04:09.897665000) audioscale(19621) gstaudioscale.c(633):gst_audioscale_chain: doing gst_audioscale_increase_rate LOG (0x8331e10 - 309872:04:09.897769000) GST_BUFFER(19621) gstbuffer.c(211):gst_buffer_new: new 0x8109104 DEBUG (0x8331e10 - 309872:04:09.897876000) audioscale(19621) gstaudioscale.c(462):gst_audioscale_increase_rate: iteration = 4 channels = 1 in size = 63520 out size = 127040 out rate = 62.500000 LOG (0x8331e10 - 309872:04:09.899233000) GST_BUFFER(19621) gstdata.c(239):gst_data_unref: 0x8109178 1->0 DEBUG (0x8331e10 - 309872:04:09.899666000) audioscale(19621) gstaudioscale.c(633):gst_audioscale_chain: doing gst_audioscale_increase_rate LOG (0x8331e10 - 309872:04:09.899854000) GST_BUFFER(19621) gstbuffer.c(211):gst_buffer_new: new 0x8109178 DEBUG (0x8331e10 - 309872:04:09.899994000) audioscale(19621) gstaudioscale.c(462):gst_audioscale_increase_rate: iteration = 5 channels = 1 in size = 127040 out size = 254080 out rate = 125.000000 LOG (0x8331e10 - 309872:04:09.902742000) GST_BUFFER(19621) gstdata.c(239):gst_data_unref: 0x8109104 1->0 DEBUG (0x8331e10 - 309872:04:09.902996000) audioscale(19621) gstaudioscale.c(633):gst_audioscale_chain: doing gst_audioscale_increase_rate LOG (0x8331e10 - 309872:04:09.903110000) GST_BUFFER(19621) gstbuffer.c(211):gst_buffer_new: new 0x8109104 DEBUG (0x8331e10 - 309872:04:09.903230000) audioscale(19621) gstaudioscale.c(462):gst_audioscale_increase_rate: iteration = 6 channels = 1 in size = 254080 out size = 508160 out rate = 250.000000 LOG (0x8331e10 - 309872:04:09.906698000) GST_BUFFER(19621) gstdata.c(239):gst_data_unref: 0x8109178 1->0 DEBUG (0x8331e10 - 309872:04:09.906966000) audioscale(19621) gstaudioscale.c(633):gst_audioscale_chain: doing gst_audioscale_increase_rate LOG (0x8331e10 - 309872:04:09.907078000) GST_BUFFER(19621) gstbuffer.c(211):gst_buffer_new: new 0x8109178 DEBUG (0x8331e10 - 309872:04:09.907198000) audioscale(19621) gstaudioscale.c(462):gst_audioscale_increase_rate: iteration = 7 channels = 1 in size = 508160 out size = 1016320 out rate = 500.000000 LOG (0x8331e10 - 309872:04:09.915505000) GST_BUFFER(19621) gstdata.c(239):gst_data_unref: 0x8109104 1->0 DEBUG (0x8331e10 - 309872:04:09.915811000) audioscale(19621) gstaudioscale.c(633):gst_audioscale_chain: doing gst_audioscale_increase_rate LOG (0x8331e10 - 309872:04:09.915930000) GST_BUFFER(19621) gstbuffer.c(211):gst_buffer_new: new 0x8109104 DEBUG (0x8331e10 - 309872:04:09.916049000) audioscale(19621) gstaudioscale.c(462):gst_audioscale_increase_rate: iteration = 8 channels = 1 in size = 1016320 out size = 2032640 out rate = 1000.000000 LOG (0x8331e10 - 309872:04:09.930721000) GST_BUFFER(19621) gstdata.c(239):gst_data_unref: 0x8109178 1->0 LOG (0x8331e10 - 309872:04:09.931163000) GST_DATAFLOW(19621) gstpad.c(3249):gst_pad_push:<audioscale:src> gst_pad_push buffer 0x8109104 (size 2032640, refcount 1) DEBUG (0x8331e10 - 309872:04:09.931495000) GST_PROBE(19621) gstprobe.c(244):gst_probe_dispatcher_dispatch: dispatching data 0x8109104 on dispatcher 0x8499aac LOG (0x8331e10 - 309872:04:09.931635000) GST_SCHEDULING(19621) gstpad.c(3272):gst_pad_push:<audioscale:src> pushing DEBUG (0x8331e10 - 309872:04:09.931728000) GST_PROBE(19621) gstprobe.c(244):gst_probe_dispatcher_dispatch: dispatching data 0x8109104 on dispatcher 0x8496a64 LOG (0x8331e10 - 309872:04:09.931830000) GST_SCHEDULING(19621) gstpad.c(3297):gst_pad_push:<audioscale:src> calling chainhandler &gst_pad_call_chain_function of peer pad osssink0:sink LOG (0x8331e10 - 309872:04:09.931932000) GST_DATAFLOW(19621) gstpad.c(4496):gst_pad_call_chain_function:<osssink0:sink> calling chain function with buffer 0x8109104 (size 2032640, refcount 1) LOG (0x8331e10 - 309872:04:09.932100000) oss(19621) gstosssink.c(445):gst_osssink_chain:<osssink0> time: real 0:00:00.000000000, buffer: 0:00:00.000000000 The UI will hang once I push the "pause" button. Here's the non-repeating portion of the debug output that results from pushing the "pause" button: DEBUG (0x80d84f0 - 309872:04:22.663294000) default(19621) gstelement.c(2790):gst_element_set_state:<pipeline> setting state to PAUSED LOG (0x80d84f0 - 309872:04:22.663379000) GST_REFCOUNTING(19621) gstobject.c(226):gst_object_ref:<pipeline> ref 4->5 LOG (0x80d84f0 - 309872:04:22.663425000) GST_REFCOUNTING(19621) gstobject.c(226):gst_object_ref:<pipeline> ref 5->6 INFO (0x80d84f0 - 309872:04:22.663464000) GST_STATES(19621) gstelement.c(2825):gst_element_set_state_func:<pipeline> setting state from PLAYING to PAUSED DEBUG (0x80d84f0 - 309872:04:22.663506000) GST_STATES(19621) gstelement.c(2848):gst_element_set_state_func:<pipeline> start: setting current state PLAYING again DEBUG (0x80d84f0 - 309872:04:22.663761000) GST_THREAD(19621) gstthread.c(428):gst_thread_change_state:<pipeline> changing state from PLAYING to PAUSED LOG (0x80d84f0 - 309872:04:22.663810000) GST_THREAD(19621) gstthread.c(436):gst_thread_change_state:<pipeline> grabbing lock DEBUG (0x80d84f0 - 309872:04:22.663850000) GST_THREAD(19621) gstthread.c(391):gst_thread_sync:<pipeline> syncing thread, grabbing lock And here's the repeating portion of the output (which appears immediately after the above output): LOG (0x80d84f0 - 309872:04:22.663889000) GST_THREAD(19621) gstthread.c(400):gst_thread_sync:<pipeline> syncing thread... DEBUG (0x80d84f0 - 309872:04:22.663928000) GST_THREAD(19621) gstthread.c(332):gst_thread_release_children_locks:<pipeline> waking element "src" DEBUG (0x80d84f0 - 309872:04:22.664012000) GST_THREAD(19621) gstthread.c(332):gst_thread_release_children_locks:<pipeline> waking element "typefind" DEBUG (0x80d84f0 - 309872:04:22.664057000) GST_THREAD(19621) gstthread.c(332):gst_thread_release_children_locks:<pipeline> waking element "decoder" DEBUG (0x80d84f0 - 309872:04:22.664101000) GST_THREAD(19621) gstthread.c(332):gst_thread_release_children_locks:<pipeline> waking element "volume" DEBUG (0x80d84f0 - 309872:04:22.664143000) GST_THREAD(19621) gstthread.c(332):gst_thread_release_children_locks:<pipeline> waking element "audioconvert" DEBUG (0x80d84f0 - 309872:04:22.664184000) GST_THREAD(19621) gstthread.c(332):gst_thread_release_children_locks:<pipeline> waking element "audioscale" DEBUG (0x80d84f0 - 309872:04:22.664224000) GST_THREAD(19621) gstthread.c(332):gst_thread_release_children_locks:<pipeline> waking element "bin0" DEBUG (0x80d84f0 - 309872:04:22.664314000) GST_THREAD(19621) gstthread.c(406):gst_thread_sync:<pipeline> wait -- Kevin Brown [EMAIL PROTECTED] -- To UNSUBSCRIBE, email to [EMAIL PROTECTED] with a subject of "unsubscribe". Trouble? Contact [EMAIL PROTECTED]
