GNOME Bugzilla – Bug 340286
[shout2send] segfaults when changing state from PLAYING->READY->PLAYING
Last modified: 2006-06-17 11:50:56 UTC
the gst-shout2send element crashes when switching from PLAYING to READY state when the pipeline was in PLAYING state before. the shout_t is allocated when switching from NULL to READY state and is released when switching from PAUSED to READY state. switching back to PLAYING state than, produces a segfault.
shout2send has been rewritten a while ago in gst-plugins-good CVS. Could you try the version in CVS and check whether that one works as expected?
the version in CVS doesnt segfault .. but also doesnt work as expected. the problem is that, i can't switch the pipeline state from PLAYING to READY and then back to PLAYING. when setting the state back to PLAYING the pipeline seems to hang after sending the first chunk of data to the server, which causes the icecast server to drop the source connection (timeout). the old shout2send did detect the connection error after some time, the new one doesnt. i thought shout2send should disconnect when going to READY and reconnect when neccessary, cause we don't know how long the pipeline will stay in READY state. i modified the shout2send to disconnect when going to READY state... but the timeout error didn't go away, cause of the hanging pipeline. any ideas?
You could try running your code with $ export GST_DEBUG=shout2:5 and/or $ export GST_DEBUG=shout2:5,basesink:5 and see if that narrows down the problem.
ok, here is the log output... i cant see any cause why the pipeline hangs... any idea ? --- DEBUG (0x694fd0 - 0:00:25.751555000) basesink(18763) gstbasesink.c(1117):gst_base_sink_do_sync:<shout2send> waiting for clock to reach 0:00:22.899229024 DEBUG (0x694fd0 - 0:00:25.751570000) basesink(18763) gstbasesink.c(1015):gst_base_sink_wait_clock:<shout2send> sync disabled DEBUG (0x694fd0 - 0:00:25.751582000) basesink(18763) gstbasesink.c(1123):gst_base_sink_do_sync:<shout2send> clock returned 4 DEBUG (0x694fd0 - 0:00:25.751596000) basesink(18763) gstbasesink.c(1462):gst_base_sink_render_object:<shout2send> rendering buffer 0x784990 LOG (0x694fd0 - 0:00:26.052280000) shout2(18763) gstshout2.c(567):gst_shout2send_render:<shout2send> sending 2799 bytes of data DEBUG (0x694fd0 - 0:00:26.052382000) basesink(18763) gstbasesink.c(1518):gst_base_sink_render_object:<shout2send> object unref after render 0x784990 (c_treamer:18763): GStreamer-WARNING **: trying to join task 0x694980 from its thread would deadlock DEBUG (0x64d9f0 - 0:00:27.069188000) basesink(18763) gstbasesink.c(2474):gst_base_sink_change_state:<shout2send> PLAYING to PAUSED DEBUG (0x64d9f0 - 0:00:27.069272000) basesink(18763) gstbasesink.c(1831):gst_base_sink_is_prerolled:<shout2send> have_preroll: 0, EOS: 0 => prerolled: 0 DEBUG (0x64d9f0 - 0:00:27.069290000) basesink(18763) gstbasesink.c(2489):gst_base_sink_change_state:<shout2send> PLAYING to PAUSED, need preroll DEBUG (0x64d9f0 - 0:00:27.069303000) basesink(18763) gstbasesink.c(2495):gst_base_sink_change_state:<shout2send> rendered: 66, dropped: 0 DEBUG (0x64d9f0 - 0:00:27.071660000) basesink(18763) gstbasesink.c(2035):gst_base_sink_set_flushing:<shout2send> flushing out data thread, need preroll to TRUE DEBUG (0x64d9f0 - 0:00:27.071738000) basesink(18763) gstbasesink.c(678):gst_base_sink_preroll_queue_flush:<shout2send> flushing queue 0x626d00 --- EOS is received and pipeline is set to READY, after this a new location is given to the filesrc element and the pipeline is set to PLAYING... DEBUG (0x64d9f0 - 0:00:38.078636000) basesink(18763) gstbasesink.c(2421):gst_base_sink_change_state:<shout2send> READY to PAUSED, need preroll DEBUG (0x64d9f0 - 0:00:38.078724000) basesink(18763) gstbasesink.c(2064):gst_base_sink_activate:<shout2send> Trying pull mode first DEBUG (0x64d9f0 - 0:00:38.078741000) basesink(18763) gstbasesink.c(2073):gst_base_sink_activate:<shout2send> Falling back to push mode DEBUG (0x64d9f0 - 0:00:38.078757000) basesink(18763) gstbasesink.c(2075):gst_base_sink_activate:<shout2send> Success activating push mode DEBUG (0x6a6790 - 0:00:38.094232000) basesink(18763) gstbasesink.c(1711):gst_base_sink_event:<shout2send> event 0x6bfd40 (newsegment) DEBUG (0x6a6790 - 0:00:38.094512000) basesink(18763) gstbasesink.c(725):gst_base_sink_configure_segment:<shout2send> configured NEWSEGMENT update 0, rate 1.000000, format GST_FORMAT_TIME, 0:00:00.000000000 -- 0:00:23.906666666, time 0:00:00.000000000, accum 0:00:00.000000000 DEBUG (0x6a6790 - 0:00:38.094724000) basesink(18763) gstbasesink.c(1613):gst_base_sink_queue_object_unlocked:<shout2send> now 0 prerolled items DEBUG (0x6a6790 - 0:00:38.094856000) basesink(18763) gstbasesink.c(1661):gst_base_sink_queue_object_unlocked:<shout2send> need more preroll data 0 <= 0 DEBUG (0x6a6790 - 0:00:38.095121000) basesink(18763) gstbasesink.c(1711):gst_base_sink_event:<shout2send> event 0x676050 (tag) DEBUG (0x6a6790 - 0:00:38.095257000) basesink(18763) gstbasesink.c(1613):gst_base_sink_queue_object_unlocked:<shout2send> now 0 prerolled items DEBUG (0x6a6790 - 0:00:38.095384000) basesink(18763) gstbasesink.c(1661):gst_base_sink_queue_object_unlocked:<shout2send> need more preroll data 0 <= 0 DEBUG (0x6a6790 - 0:00:38.127990000) shout2(18763) gstshout2.c(694):gst_shout2send_setcaps:<shout2send> mimetype of caps given is: application/ogg DEBUG (0x6a6790 - 0:00:38.128305000) basesink(18763) gstbasesink.c(1885):gst_base_sink_chain_unlocked:<shout2send> got times start: 99:99:99.999999999, end: 99:99:99.999999999 DEBUG (0x6a6790 - 0:00:38.128495000) basesink(18763) gstbasesink.c(1613):gst_base_sink_queue_object_unlocked:<shout2send> now 1 prerolled items DEBUG (0x6a6790 - 0:00:38.128622000) basesink(18763) gstbasesink.c(1551):gst_base_sink_preroll_object:<shout2send> do preroll 0x7e50b0 DEBUG (0x6a6790 - 0:00:38.128749000) basesink(18763) gstbasesink.c(1559):gst_base_sink_preroll_object:<shout2send> preroll buffer 99:99:99.999999999 DEBUG (0x6a6790 - 0:00:38.128877000) basesink(18763) gstbasesink.c(779):gst_base_sink_commit_state:<shout2send> commiting state to PAUSED DEBUG (0x6a6790 - 0:00:38.129112000) basesink(18763) gstbasesink.c(1637):gst_base_sink_queue_object_unlocked:<shout2send> rendering queued object 0x6bfd40 DEBUG (0x6a6790 - 0:00:38.129253000) basesink(18763) gstbasesink.c(1153):gst_base_sink_do_sync:<shout2send> non syncable object 0x6bfd40 DEBUG (0x6a6790 - 0:00:38.129379000) basesink(18763) gstbasesink.c(1485):gst_base_sink_render_object:<shout2send> rendering event 0x6bfd40, type newsegment LOG (0x6a6790 - 0:00:38.129517000) shout2(18763) gstshout2.c(344):gst_shout2send_event:<shout2send> got newsegment event LOG (0x6a6790 - 0:00:38.129639000) shout2(18763) gstshout2.c(375):gst_shout2send_event:<shout2send> let base class handle event DEBUG (0x6a6790 - 0:00:38.129772000) basesink(18763) gstbasesink.c(725):gst_base_sink_configure_segment:<shout2send> configured NEWSEGMENT update 0, rate 1.000000, format GST_FORMAT_TIME, 0:00:00.000000000 -- 0:00:23.906666666, time 0:00:00.000000000, accum 0:00:00.000000000 DEBUG (0x6a6790 - 0:00:38.129972000) basesink(18763) gstbasesink.c(1518):gst_base_sink_render_object:<shout2send> object unref after render 0x6bfd40 DEBUG (0x6a6790 - 0:00:38.130111000) basesink(18763) gstbasesink.c(1637):gst_base_sink_queue_object_unlocked:<shout2send> rendering queued object 0x676050 DEBUG (0x6a6790 - 0:00:38.130241000) basesink(18763) gstbasesink.c(1153):gst_base_sink_do_sync:<shout2send> non syncable object 0x676050 DEBUG (0x6a6790 - 0:00:38.130366000) basesink(18763) gstbasesink.c(1485):gst_base_sink_render_object:<shout2send> rendering event 0x676050, type tag LOG (0x6a6790 - 0:00:38.130505000) shout2(18763) gstshout2.c(344):gst_shout2send_event:<shout2send> got tag event DEBUG (0x6a6790 - 0:00:38.130625000) basesink(18763) gstbasesink.c(1518):gst_base_sink_render_object:<shout2send> object unref after render 0x676050 DEBUG (0x6a6790 - 0:00:38.130758000) basesink(18763) gstbasesink.c(905):gst_base_sink_get_sync_times:<shout2send> got times start: 99:99:99.999999999, stop: 99:99:99.999999999 DEBUG (0x6a6790 - 0:00:38.130922000) basesink(18763) gstbasesink.c(926):gst_base_sink_get_sync_times:<shout2send> clipped to: start 99:99:99.999999999, stop: 0:00:23.906666666 DEBUG (0x6a6790 - 0:00:38.131087000) basesink(18763) gstbasesink.c(1089):gst_base_sink_do_sync:<shout2send> prerolling object 0x7e50b0 DEBUG (0x6a6790 - 0:00:38.131213000) basesink(18763) gstbasesink.c(1102):gst_base_sink_do_sync:<shout2send> waiting to finish preroll DEBUG (0x7e54a0 - 0:00:38.131487000) basesink(18763) gstbasesink.c(1831):gst_base_sink_is_prerolled:<shout2send> have_preroll: 1, EOS: 0 => prerolled: 1 DEBUG (0x7e54a0 - 0:00:38.131644000) basesink(18763) gstbasesink.c(2440):gst_base_sink_change_state:<shout2send> PAUSED to PLAYING, don't need preroll DEBUG (0x7e54a0 - 0:00:38.131773000) basesink(18763) gstbasesink.c(2449):gst_base_sink_change_state:<shout2send> signal preroll DEBUG (0x6a6790 - 0:00:38.131903000) basesink(18763) gstbasesink.c(1106):gst_base_sink_do_sync:<shout2send> done preroll DEBUG (0x6a6790 - 0:00:38.132025000) basesink(18763) gstbasesink.c(1462):gst_base_sink_render_object:<shout2send> rendering buffer 0x7e50b0 LOG (0x6a6790 - 0:00:38.132153000) shout2(18763) gstshout2.c(567):gst_shout2send_render:<shout2send> sending 98 bytes of data DEBUG (0x6a6790 - 0:00:38.132317000) basesink(18763) gstbasesink.c(1518):gst_base_sink_render_object:<shout2send> object unref after render 0x7e50b0 DEBUG (0x6a6790 - 0:00:38.132502000) basesink(18763) gstbasesink.c(1885):gst_base_sink_chain_unlocked:<shout2send> got times start: 99:99:99.999999999, end: 99:99:99.999999999 DEBUG (0x6a6790 - 0:00:38.132682000) basesink(18763) gstbasesink.c(905):gst_base_sink_get_sync_times:<shout2send> got times start: 99:99:99.999999999, stop: 99:99:99.999999999 DEBUG (0x6a6790 - 0:00:38.132845000) basesink(18763) gstbasesink.c(926):gst_base_sink_get_sync_times:<shout2send> clipped to: start 99:99:99.999999999, stop: 0:00:23.906666666 DEBUG (0x6a6790 - 0:00:38.133010000) basesink(18763) gstbasesink.c(1462):gst_base_sink_render_object:<shout2send> rendering buffer 0x7e5270 LOG (0x6a6790 - 0:00:38.133136000) shout2(18763) gstshout2.c(567):gst_shout2send_render:<shout2send> sending 4044 bytes of data DEBUG (0x6a6790 - 0:00:38.133309000) basesink(18763) gstbasesink.c(1518):gst_base_sink_render_object:<shout2send> object unref after render 0x7e5270 DEBUG (0x6a6790 - 0:00:38.136631000) basesink(18763) gstbasesink.c(1885):gst_base_sink_chain_unlocked:<shout2send> got times start: 0:00:23.410068027, end: 0:00:00.036281179 DEBUG (0x6a6790 - 0:00:38.136959000) basesink(18763) gstbasesink.c(905):gst_base_sink_get_sync_times:<shout2send> got times start: 0:00:23.410068027, stop: 0:00:00.036281179 DEBUG (0x6a6790 - 0:00:38.137129000) basesink(18763) gstbasesink.c(1117):gst_base_sink_do_sync:<shout2send> waiting for clock to reach 0:00:23.410068027 DEBUG (0x6a6790 - 0:00:38.137260000) basesink(18763) gstbasesink.c(1015):gst_base_sink_wait_clock:<shout2send> sync disabled DEBUG (0x6a6790 - 0:00:38.137382000) basesink(18763) gstbasesink.c(1123):gst_base_sink_do_sync:<shout2send> clock returned 4 DEBUG (0x6a6790 - 0:00:38.137542000) basesink(18763) gstbasesink.c(1462):gst_base_sink_render_object:<shout2send> rendering buffer 0x6e31b0
This warning looks pretty evil: (c_treamer:18763): GStreamer-WARNING **: trying to join task 0x694980 from its thread would deadlock You should track down where it comes from exactly, by setting the G_DEBUG environment variable like this: $ export G_DEBUG=fatal_warnings and then running your program in gdb (it will then abort at the warning and the stack trace will show you where it was triggered from). As for the hanging - no idea. Did you try connecting to your program with gdb while it hangs and seeing where exactly it's hanging? $ gdb -p <pid of your program> (gdb) thread apply all bt
ok, i tracked down the "join task" problem and fixed it ... it was caused by setting the pipeline state in an event-probe callback. however, the pipeline keeps hanging .. funny thing is that the backtrace shows that two threads are streaming to the shout2 plugin ? (but i don't know the threading details of gstreamer) both threads keep hanging in _shout_timing_sleep (). Many thanks for your help. Program received signal SIGINT, Interrupt.
+ Trace 67975
Thread 46912538548768 (LWP 16828)
Thread 12 (Thread 1098934624 (LWP 16857))
Thread 5 (Thread 1098934624 (LWP 16857))
Thread 1 (Thread 46912538548768 (LWP 16828))
What's the layout of your pipeline here? I noticed a 'gst_adder_collected' in the stack trace? are you using the 'adder' element? (which doesn't work that well, at least not with currently released versions, there have been a bunch of fixes in core/base CVS for it though). Also, maybe you could run your server/program with the GST_DEBUG environment variable set to '*:5' and attach the (bzip2'ed) debug log, e.g. $ GST_DEBUG=*:5 myserver 2>dbg.log
Closing this bug report as no further information has been provided. Please feel free to reopen this bug if you can provide the information asked for. Thanks!