GNOME Bugzilla – Bug 565105
Gstreamer does not change from READY back to PAUSED in same cases
Last modified: 2009-02-24 09:52:28 UTC
1. Download gsttest.c and compile it 2. Run ./gsttest file://path_to_an.mp3 This program: 1. creates playbin2 pipeline 2. sets pause 3. sets volume mute and plays 4. when playing it sets pause 5. when paused it goes to ready 6. when ready it goes to pause 7. when paused it sets volume, mute and plays 8. it finishes with success Program here is that sometimes program hangs after step 6. It never goes to paused state to it never runs 7 and 8. I wrote a small script to run the program with a timeout of ten seconds, so if it hangs, script sends SIGUSR2 and program aborts. This allows running program many times and while loggin output to see how many time it fails. Script looks for /tmp/test.mp3, so copy one into that location and run: for i in `seq 1 100'; do ./timeout.sh; done | tee log.txt Frequency of occurance is 14% in my environment, which is a Debian lenny with amd64 architecture. GStreamer packages are: gstreamer0.10-alsa 0.10.19-2 gstreamer0.10-doc 0.10.19-3 gstreamer0.10-esd 0.10.8-4 gstreamer0.10-ffmpeg 0.10.4-3 gstreamer0.10-gnomevfs 0.10.19-2 gstreamer0.10-lame 0.10.10-0.0 gstreamer0.10-plugins-bad 0.10.7-2 gstreamer0.10-plugins-base 0.10.19-2 gstreamer0.10-plugins-base-dbg 0.10.19-2 gstreamer0.10-plugins-good 0.10.8-4 gstreamer0.10-plugins-good-dbg 0.10.8-4 gstreamer0.10-plugins-ugly 0.10.8-1 gstreamer0.10-plugins-ugly-dbg 0.10.8-1 gstreamer0.10-tools 0.10.19-3 gstreamer0.10-x 0.10.19-2 libgstreamer-plugins-base0.10-0 0.10.19-2 libgstreamer-plugins-base0.10-dev 0.10.19-2 libgstreamer0.10-0 0.10.19-3 libgstreamer0.10-0-dbg 0.10.19-3 libgstreamer0.10-dev 0.10.19-3
Created attachment 125009 [details] Program to test Program to test
Created attachment 125010 [details] Script to run the test many times
Created attachment 125011 [details] Log of batch execution of program for i in `seq 1 100`; do ./timeout.sh; done | tee log_out.txt
when I removed the kill statement from the script to see where it hangs, it did not happen anymore. Any chance that the signal is just sent too quickly, before it can complete the state change?
(In reply to comment #4) > when I removed the kill statement from the script to see where it hangs, it did > not happen anymore. Any chance that the signal is just sent too quickly, before > it can complete the state change? I don't think so, because usually the complete and right execution takes less than 6 seconds and the timeout is signal should kill the program after 10 seconds. I think that margin should be enough to change the state. But if you see the logs, when the signal is sent and captured, it always is in the same state, waiting to come back from READY to PAUSED. If you are not sure, you can use a longer timeout in the script or remove it. I only wrote it to run the program in batch because it would hang if I didn't add it. So yes, you can remove it and run it to see the hang. It should happen, I swear :-) .
Created attachment 127462 [details] another shell script to run the tests I can confirm the bug. It just happend 8 of 100 times. The test applications runs fine under valgrind memcheck (checking one leak now) - atleast no reads from uninitialized memory or such.
The test app should be reworked. In _handle_state_changed() don't use a own TransitionType, just use GstStateChange. Then have a switch case for all those state changes. Also please clean things like _go_to_gst_ready(), you can set in_ready=TRUE in _handle_state_changed() when receiving the GST_STATE_CHANGE_PAUSED_TO_READY.
Created attachment 127765 [details] Program to test I reworked this test program as suggested by ensonic.
With the new test program I got 26/200 failures.
Created attachment 128966 [details] Debug log of hanging pipeline Backtrace that goes with the attached log:
+ Trace 212656
Summary of what is happening: * state changes down to READY; playbin2 & co tear down the pipeline and remove elements, though not all, e.g. audiotee in playsink is put to READY state * state set to PAUSED again (mainloop), which in turns triggers dynamic pipeline building (by streaming thread) * streaming thread (and also possibly mainloop) is setting newly added element to PAUSED * however, audiotee is "disregarded", i.e. it is left to the mainloop to set it to PAUSED. This may only happen *after* streaming thread has finished building the pipeline (or at least believes this is fully finished and OK), upon which streaming resumes. (see also about log line 1790 and following) * but, with audiotee still in READY state, this leads to a wrong state, pausing streaming thread (filesrc loop in this case), and the pipeline can no longer preroll and make it to PAUSED, so app waits indefinitely for it to be reached
Created attachment 128969 [details] [review] Possible patch * Set audiotee to proper (PAUSED) state in any case.
Yah, that fixes it. Please commit!
commit bbd66c6bafe8bfc67ecf7d947d868275e3db4133 Author: Mark Nauwelaerts <mark.nauwelaerts@collabora.co.uk> Date: Wed Feb 18 11:59:58 2009 +0100 playbin2/playsink: Set audiotee to PAUSED state in all cases. Fixes #565105.