GNOME Bugzilla – Bug 584185
GstQueue NEWSEGMENT handling increases curtime even when queue is empty
Last modified: 2010-04-07 10:45:18 UTC
Please describe the problem: In camerabin there is a queue which leads from videobin to viewfinder. In my setup this queue max-size-buffers is set to 1, and it is leaky downstream. I managed to get the following situation to happen: 1. in gst_queue_loop(): gst_queue_locked_dequeue() receives a NEWSEGMENT event, which is the only item in the queue. 2. Handling the event causes apply_segment() function to be called, which in turn calls update_time_level(). 3. Now queue->cur_level.time is set to non-zero, even when the queue is empty. In my case the value is quite big (bigger than max-size-time). 4. Next time when chain function is called, gst_queue_is_filled() thinks that queue is full and starts leaking it (downstream in my case, but this doesn't matter actually). 5. Trying to leak empty queue causes assertion failure: ERROR:gstqueue.c:858:gst_queue_leak_downstream: assertion failed: (leak != NULL) This happens when camerabin's video recording is switched to pause and back to recording multiple times in a row. Eventually this problem will show up. Attached is a log that shows what happens. I have added one debug line ("queue is full, leaking buffer on downstream end") myself to see that it really starts the leaking operation. Steps to reproduce: Actual results: Expected results: Does this happen every time? Other information:
Created attachment 135541 [details] Debug log showing the situation where this bug happens
Analysis of the log: 0:01:08.195709236: One buffer is added to queue. It is the only queue content. 0:01:08.197143563 NEWSEGMENT event is added to queue. It contains 2 items now. ... 0:01:08.206359872: Loop has taken the buffer and pushed it forward. Items = 1. 0:01:08.207580575: Loop starts handling the newsegment. Eventually update_time_level() is called, which contains following piece of code: if (sink_time >= src_time) queue->cur_level.time = sink_time - src_time; else queue->cur_level.time = 0; This sets the cur_level.time to non-zero value and makes the queue look full, even queue is now empty. 0:01:08.210968026: Loop waits for buffer. Note the changed queue duration! 0:01:08.235351571: New buffer arrives to queue 0:01:08.236206064: gst_queue_is_filled() returns TRUE 0:01:08.236938485: Queue tries to leak contents, but queue is empty
the queue keeps to counters: - keep track of the timestamps of data going into the queue - keep track of the timestamps going out of the queue the difference between those timestamps is the amount of data in the queue. Can you make a bigger log like with queue*:5 to see what is really going on? I'm suspecting that when it is leaking that the counters are not updated correctly.
Tommi, could you answer the question Wim raised in comment #3 and reopen this bug report then? Thanks in advance!