GNOME Bugzilla – Bug 734688
queue: race when receiving flush-stop event during shutdown, task gets re-started
Last modified: 2014-08-25 07:52:25 UTC
Created attachment 283230 [details] backtrace I have seen a deadlock when a queue element is about to get finalized. For some reason, the task is still running. Attached a backtrace with relevant threads.
Created attachment 283231 [details] prints of GstTask and GstQueue
Can you provide a testcase for reproducing this problem? This looks like the bin is removed from the server while it is still in a state > READY and doing data flow... without anything ever having it shut down.
Created attachment 283285 [details] [review] rtsp-stream: Remove the multicast group udp sources when removing from the bin
Does this fix it by any chance?
I'm working to find a way reproducing this faster with a test case, but no luck so far. The pipeline is in state NULL and so are the queue. The udp sources are still in PLAYING state, but I don't think that's the problem here.
Does my patch help? And which is the exact line in rtsp-stream.c where it deadlocks? Your line numbers are different than mine :)
Looks to me that the task_func is called for the queue element, when it shouldn't. There is a blocking probe installed on queue's sink pad looking like: gst_pad_add_probe (pad, GST_PAD_PROBE_TYPE_BLOCK | GST_PAD_PROBE_TYPE_BUFFER | GST_PAD_PROBE_TYPE_BUFFER_LIST, pad_drop, NULL, NULL); I have no idea if this makes any difference
This does not reproduce that easy. I'll have to wait at least one day to know if your patch helps slomo. The deadlock occurs here in gst_rtsp_stream_leave_bin: 1843 gst_bin_remove (bin, priv->appqueue[i]); (gdb) list 1842 if (priv->appqueue[i]) 1843 gst_bin_remove (bin, priv->appqueue[i]); 1844 if (priv->tee[i]) 1845 gst_bin_remove (bin, priv->tee[i]); In the backtrace, I guess that thread 8 (rtsp thread pool) and thread 10 (task thread for queue) are of interest. In thread 8, one can see that this wait's for a task to finish (namely the streaming thread in queue's task). But that task is executing the loop function in gstqueue.
Created attachment 283502 [details] backtrace
New backtrace supplied. This is another case, but the same element is involved as the first backtrace I supplied. It's not very easy to reproduce this, but I manage to do it more and more frequently. A couple of interesting observations is that it's always the same element (the queue after the tee in the tcp part of an rtsp-server pipeline, corresponding to RTP). In my test setup I'm streaming both video and audio, but I can not say that this always happen for the video part of the pipeline. The sync property on the sink is false in this particular pipeline.
In the last supplied backtrace one can see two tasks that (at least in my oponion) looks to be the streaming thread of the same element. Any idea on how this could happen is very welcome.
I'm getting different kind of deadlocks when reproducing this problem. As mentioned before it's always the same element (queue between tee and appsink. this is a pipeline in gst-rtsp-server when using tcp as transport) that causes problems. There always seem to be some problem with the task on the src pad of the queue. In one case I actually had two tasks, both of them looked like the task on the src pad. One task in state STOPPED and one task in state STARTED. The src pads task pointer pointed to the STARTED task. It looked like the STOPPED task was stopped from the rtsp server's client thread (currently running with only one thread serving clients, even if it's possible to use more). The STOPPED task was leaving state PAUSED and got stuck when it called g_rec_mutex_lock (lock) on it's way out of the while loop in gst_task_func. This lock was held by the STARTED task. The STARTED task waited for buffers in gst_queue_loop. I guess that the bug is that the second task even got started in this case. I got the output from GST_DEBUG=queue:6,queue_dataflow:6,task:6,rtspclient:6 today. When TEARDOWN is beging served, the pipeline is set to GST_STATE_NULL, but a deadlock occurs when finalizing the src pad of the queue (the queue is in state NULL). The task on the pad is set to state STOPPED, but the task's thread is executing gst_queue_loop (in NULL state). It looks like the streaming task is stopped when doing the state transition PAUSED->READY, but a new task is started. From the debug log I can see that gst_pad_start_task() when we received a FLASH_STOP event. I suspect that there might be a problem with this flush stop event. I don't know why I see this event and where it comes from.
I have located the problem that happened. We serve an RTSP TEARDOWN request which makes the pipeline to change state to NULL. At the same time the src element sends FLUSH_START and FLUSH_STOP. If the pipeline is doing the PAUSED->READY transition and the FLUSH_STOP arrives at the queue, the queue will create a new task that is never ended. This src element is a bin element (filesrc ! matroskademux ! multiqueue) that plays a sequence of matroska files and demuxes them to one stream. It will send FLUSH_START+FLUSH_STOP if it's in state PAUSED when it changes file to avoid a deadlock when multiqueue is full. When changing matroska file, the filesrc and matroskademux will temporarily be lowered to state READY in order to change the location property of the file src.
Created attachment 283963 [details] [review] Testcase that triggers a deadlock when changing state of a gstqueue I was able to reproduce this deadlock every time when running this GST_CHECKS=test_state_change_when_flushing make -C tests/check elements/queue.check
Created attachment 284082 [details] [review] queue: fix race when flush-stop event comes in whilst shutting down How about this? Don't re-start the queue push task on the source pad when a flush-stop event comes in and we're in the process of shutting down, otherwise that task will never be stopped again. When the element is set to READY state, the pads get de-activated. The source pad gets deactivated before the queue's own activate_mode function on the source pads gets called (which will stop the thread), so checking whether the pad is active before re-starting the task on receving flush-stop should be fine. The problem would happen when the flush-stop handler was called just after the queue's activate mode function had stopped the task.
Maybe we should ignore those flush events on in-active pads. Other events should already be ignored when the pad is flushing.
I was wondering whether we should just make gst_pad_start_task() do nothing if the pad is inactive. I'm not sure what you suggest would help in this case, since the sink pad might still be active.
Created attachment 284089 [details] [review] pad: don't accept flush-stop on inactive pads (possibly a good idea, but doesn't help with this bug)
(In reply to comment #17) > I was wondering whether we should just make gst_pad_start_task() do nothing if > the pad is inactive. That sounds like a good idea as well. > > I'm not sure what you suggest would help in this case, since the sink pad might > still be active. Ah, indeed.
Well, my patch makes sense but it doesn't solve this queue issue, you somewhere need to explicitly check the active status of the queue srcpad.
Nice work debugging this, and thanks for the unit test! Pushed these to master now, will cherry-pick the fix into 1.4 as well: commit ae74a1a83a8a5034c37da283d6176c3abab4b3cc Author: Linus Svensson <linussn@axis.com> Date: Wed Aug 20 12:55:51 2014 +0200 tests: add test that triggers deadlock in state change of queue When receiving FLASH_STOP in a state transition to READY, a queue element can end up with an active task that will never end. https://bugzilla.gnome.org/show_bug.cgi?id=734688 commit 93d8679b00c1402aaf44f37bb67487d1a3d0ffc4 Author: Tim-Philipp Müller <tim@centricular.com> Date: Thu Aug 21 14:02:16 2014 +0100 queue: fix race when flush-stop event comes in whilst shutting down Don't re-start the queue push task on the source pad when a flush-stop event comes in and we're in the process of shutting down, otherwise that task will never be stopped again. When the element is set to READY state, the pads get de-activated. The source pad gets deactivated before the queue's own activate_mode function on the source pads gets called (which will stop the thread), so checking whether the pad is active before re-starting the task on receiving flush-stop should be fine. The problem would happen when the flush-stop handler was called just after the queue's activate mode function had stopped the task. Spotted and debugged by Linus Svensson <linux.svensson@axis.com> https://bugzilla.gnome.org/show_bug.cgi?id=734688 Wim's patch is independent. We might still want to refuse to start a task on a deactivated pad, but should probably look at the code of the various users a bit before that.
(In reply to comment #20) > Well, my patch makes sense but it doesn't solve this queue issue, you somewhere > need to explicitly check the active status of the queue srcpad. Should we create another bug for this or how should we handle this patch?