multiqueue: Use new id-based debugging methods

Clarifies the debug logs

Part-of: <https://gitlab.freedesktop.org/gstreamer/gstreamer/-/merge_requests/3483>
This commit is contained in:
Edward Hervey 2022-11-29 10:03:14 +01:00 committed by GStreamer Marge Bot
parent a289c61c11
commit f84fe4710a

View file

@ -118,6 +118,11 @@ struct _GstSingleQueue
guint id;
/* group of streams to which this queue belongs to */
guint groupid;
#ifndef GST_DISABLE_GST_DEBUG
/* debug identifier */
gchar *debug_id;
#endif
GstClockTimeDiff group_high_time;
GWeakRef mqueue;
@ -946,8 +951,8 @@ gst_multi_queue_set_property (GObject * object, guint prop_id,
GstSingleQueue *q = (GstSingleQueue *) tmp->data;
gst_data_queue_get_level (q->queue, &size);
GST_DEBUG_OBJECT (mq, "Queue %d: Requested buffers size: %d,"
" current: %d, current max %d", q->id, new_size, size.visible,
GST_DEBUG_OBJECT_ID (q->debug_id, "Requested buffers size: %d,"
" current: %d, current max %d", new_size, size.visible,
q->max_size.visible);
/* do not reduce max size below current level if the single queue
@ -1340,7 +1345,7 @@ gst_single_queue_start (GstMultiQueue * mq, GstSingleQueue * sq)
gboolean res = FALSE;
GstPad *srcpad = g_weak_ref_get (&sq->srcpad);
GST_LOG_OBJECT (mq, "SingleQueue %d : starting task", sq->id);
GST_LOG_OBJECT_ID (sq->debug_id, "starting task");
if (srcpad) {
res = gst_pad_start_task (srcpad,
@ -1357,7 +1362,7 @@ gst_single_queue_pause (GstMultiQueue * mq, GstSingleQueue * sq)
gboolean result = FALSE;
GstPad *srcpad = g_weak_ref_get (&sq->srcpad);
GST_LOG_OBJECT (mq, "SingleQueue %d : pausing task", sq->id);
GST_LOG_OBJECT_ID (sq->debug_id, "pausing task");
if (srcpad) {
result = gst_pad_pause_task (srcpad);
gst_object_unref (srcpad);
@ -1374,7 +1379,7 @@ gst_single_queue_stop (GstMultiQueue * mq, GstSingleQueue * sq)
gboolean result = FALSE;
GstPad *srcpad = g_weak_ref_get (&sq->srcpad);
GST_LOG_OBJECT (mq, "SingleQueue %d : stopping task", sq->id);
GST_LOG_OBJECT_ID (sq->debug_id, "stopping task");
if (srcpad) {
result = gst_pad_stop_task (srcpad);
gst_object_unref (srcpad);
@ -1388,8 +1393,7 @@ static void
gst_single_queue_flush (GstMultiQueue * mq, GstSingleQueue * sq, gboolean flush,
gboolean full)
{
GST_DEBUG_OBJECT (mq, "flush %s queue %d", (flush ? "start" : "stop"),
sq->id);
GST_DEBUG_OBJECT_ID (sq->debug_id, "flush %s", (flush ? "start" : "stop"));
if (flush) {
GST_MULTI_QUEUE_MUTEX_LOCK (mq);
@ -1399,8 +1403,7 @@ gst_single_queue_flush (GstMultiQueue * mq, GstSingleQueue * sq, gboolean flush,
sq->flushing = TRUE;
/* wake up non-linked task */
GST_LOG_OBJECT (mq, "SingleQueue %d : waking up eventually waiting task",
sq->id);
GST_LOG_OBJECT_ID (sq->debug_id, "Waking up eventually waiting task");
g_cond_signal (&sq->turn);
sq->last_query = FALSE;
g_cond_signal (&sq->query_handled);
@ -1448,9 +1451,9 @@ get_buffering_level (GstMultiQueue * mq, GstSingleQueue * sq)
gst_data_queue_get_level (sq->queue, &size);
GST_DEBUG_OBJECT (mq,
"queue %d: visible %u/%u, bytes %u/%u, time %" G_GUINT64_FORMAT "/%"
G_GUINT64_FORMAT, sq->id, size.visible, sq->max_size.visible,
GST_DEBUG_OBJECT_ID (sq->debug_id,
"visible %u/%u, bytes %u/%u, time %" G_GUINT64_FORMAT "/%"
G_GUINT64_FORMAT, size.visible, sq->max_size.visible,
size.bytes, sq->max_size.bytes, sq->cur_time, sq->max_size.time);
/* get bytes and time buffer levels and take the max */
@ -1637,9 +1640,9 @@ calculate_interleave (GstMultiQueue * mq, GstSingleQueue * sq)
if (oq->cached_sinktime < 0)
some_inactive = TRUE;
}
GST_LOG_OBJECT (mq,
"queue %d , sinktime:%" GST_STIME_FORMAT " low:%" GST_STIME_FORMAT
" high:%" GST_STIME_FORMAT, oq->id,
GST_LOG_OBJECT_ID (oq->debug_id,
"sinktime:%" GST_STIME_FORMAT " low:%" GST_STIME_FORMAT
" high:%" GST_STIME_FORMAT,
GST_STIME_ARGS (oq->cached_sinktime), GST_STIME_ARGS (low),
GST_STIME_ARGS (high));
}
@ -1710,9 +1713,9 @@ update_time_level (GstMultiQueue * mq, GstSingleQueue * sq)
sink_time = sq->sinktime = my_segment_to_running_time (&sq->sink_segment,
sq->sink_segment.position);
GST_DEBUG_OBJECT (mq,
"queue %d sink_segment.position:%" GST_TIME_FORMAT ", sink_time:%"
GST_STIME_FORMAT, sq->id, GST_TIME_ARGS (sq->sink_segment.position),
GST_DEBUG_OBJECT_ID (sq->debug_id,
"sink_segment.position:%" GST_TIME_FORMAT ", sink_time:%"
GST_STIME_FORMAT, GST_TIME_ARGS (sq->sink_segment.position),
GST_STIME_ARGS (sink_time));
if (G_UNLIKELY (sq->last_time == GST_CLOCK_STIME_NONE)) {
@ -1761,8 +1764,8 @@ update_time_level (GstMultiQueue * mq, GstSingleQueue * sq)
} else
src_time = sq->srctime;
GST_DEBUG_OBJECT (mq,
"queue %d, sink %" GST_STIME_FORMAT ", src %" GST_STIME_FORMAT, sq->id,
GST_DEBUG_OBJECT_ID (sq->debug_id,
"sink %" GST_STIME_FORMAT ", src %" GST_STIME_FORMAT,
GST_STIME_ARGS (sink_time), GST_STIME_ARGS (src_time));
/* This allows for streams with out of order timestamping - sometimes the
@ -1817,8 +1820,8 @@ apply_segment (GstMultiQueue * mq, GstSingleQueue * sq, GstEvent * event,
GST_MULTI_QUEUE_MUTEX_LOCK (mq);
if (ppos) {
GST_DEBUG_OBJECT (mq, "queue %d, Applying base of %" GST_TIME_FORMAT,
sq->id, GST_TIME_ARGS (ppos));
GST_DEBUG_OBJECT_ID (sq->debug_id, "Applying base of %" GST_TIME_FORMAT,
GST_TIME_ARGS (ppos));
segment->base = ppos;
}
@ -1836,8 +1839,8 @@ apply_segment (GstMultiQueue * mq, GstSingleQueue * sq, GstEvent * event,
sq->src_tainted = TRUE;
}
GST_DEBUG_OBJECT (mq,
"queue %d, configured SEGMENT %" GST_SEGMENT_FORMAT, sq->id, segment);
GST_DEBUG_OBJECT_ID (sq->debug_id,
"configured SEGMENT %" GST_SEGMENT_FORMAT, segment);
/* segment can update the time level of the queue */
update_time_level (mq, sq);
@ -1862,9 +1865,8 @@ apply_buffer (GstMultiQueue * mq, GstSingleQueue * sq, GstClockTime timestamp,
if (duration != GST_CLOCK_TIME_NONE)
timestamp += duration;
GST_DEBUG_OBJECT (mq, "queue %d, %s position updated to %" GST_TIME_FORMAT,
sq->id, segment == &sq->sink_segment ? "sink" : "src",
GST_TIME_ARGS (timestamp));
GST_DEBUG_OBJECT_ID (sq->debug_id, "%s position updated to %" GST_TIME_FORMAT,
segment == &sq->sink_segment ? "sink" : "src", GST_TIME_ARGS (timestamp));
segment->position = timestamp;
@ -1896,8 +1898,9 @@ apply_gap (GstMultiQueue * mq, GstSingleQueue * sq, GstEvent * event,
timestamp += duration;
}
GST_DEBUG_OBJECT (mq, "queue %d, %s position updated to %" GST_TIME_FORMAT,
sq->id, segment == &sq->sink_segment ? "sink" : "src",
GST_DEBUG_OBJECT_ID (sq->debug_id,
"%s position updated to %" GST_TIME_FORMAT,
segment == &sq->sink_segment ? "sink" : "src",
GST_TIME_ARGS (timestamp));
segment->position = timestamp;
@ -2004,14 +2007,14 @@ gst_single_queue_push_one (GstMultiQueue * mq, GstSingleQueue * sq,
gst_data_queue_limits_changed (sq->queue);
if (G_UNLIKELY (*allow_drop)) {
GST_DEBUG_OBJECT (mq,
"SingleQueue %d : Dropping EOS buffer %p with ts %" GST_TIME_FORMAT,
sq->id, buffer, GST_TIME_ARGS (timestamp));
GST_DEBUG_OBJECT_ID (sq->debug_id,
"Dropping EOS buffer %p with ts %" GST_TIME_FORMAT,
buffer, GST_TIME_ARGS (timestamp));
gst_buffer_unref (buffer);
} else {
GST_DEBUG_OBJECT (mq,
"SingleQueue %d : Pushing buffer %p with ts %" GST_TIME_FORMAT,
sq->id, buffer, GST_TIME_ARGS (timestamp));
GST_DEBUG_OBJECT_ID (sq->debug_id,
"Pushing buffer %p with ts %" GST_TIME_FORMAT,
buffer, GST_TIME_ARGS (timestamp));
result = gst_pad_push (srcpad, buffer);
}
} else if (GST_IS_EVENT (object)) {
@ -2063,14 +2066,13 @@ gst_single_queue_push_one (GstMultiQueue * mq, GstSingleQueue * sq,
}
if (G_UNLIKELY (*allow_drop)) {
GST_DEBUG_OBJECT (mq,
"SingleQueue %d : Dropping EOS event %p of type %s",
sq->id, event, GST_EVENT_TYPE_NAME (event));
GST_DEBUG_OBJECT_ID (sq->debug_id,
"Dropping EOS event %p of type %s",
event, GST_EVENT_TYPE_NAME (event));
gst_event_unref (event);
} else {
GST_DEBUG_OBJECT (mq,
"SingleQueue %d : Pushing event %p of type %s",
sq->id, event, GST_EVENT_TYPE_NAME (event));
GST_DEBUG_OBJECT_ID (sq->debug_id,
"Pushing event %p of type %s", event, GST_EVENT_TYPE_NAME (event));
gst_pad_push_event (srcpad, event);
}
@ -2081,8 +2083,7 @@ gst_single_queue_push_one (GstMultiQueue * mq, GstSingleQueue * sq,
query = GST_QUERY_CAST (object);
if (G_UNLIKELY (*allow_drop)) {
GST_DEBUG_OBJECT (mq,
"SingleQueue %d : Dropping EOS query %p", sq->id, query);
GST_DEBUG_OBJECT_ID (sq->debug_id, "Dropping EOS query %p", query);
gst_query_unref (query);
res = FALSE;
} else {
@ -2190,7 +2191,7 @@ gst_multi_queue_loop (GstPad * pad)
goto done;
next:
GST_DEBUG_OBJECT (mq, "SingleQueue %d : trying to pop an object", sq->id);
GST_DEBUG_OBJECT_ID (sq->debug_id, "trying to pop an object");
if (sq->flushing)
goto out_flushing;
@ -2214,8 +2215,8 @@ next:
/* Get running time of the item. Events will have GST_CLOCK_STIME_NONE */
next_time = get_running_time (&sq->src_segment, object, FALSE);
GST_LOG_OBJECT (mq, "SingleQueue %d : newid:%d , oldid:%d",
sq->id, newid, sq->last_oldid);
GST_LOG_OBJECT_ID (sq->debug_id, "newid:%d , oldid:%d",
newid, sq->last_oldid);
/* If we're not-linked, we do some extra work because we might need to
* wait before pushing. If we're linked but there's a gap in the IDs,
@ -2226,7 +2227,7 @@ next:
if (sq->srcresult == GST_FLOW_NOT_LINKED
|| (sq->last_oldid == G_MAXUINT32) || (newid != (sq->last_oldid + 1))
|| sq->last_oldid > mq->highid) {
GST_LOG_OBJECT (mq, "CHECKING sq->srcresult: %s",
GST_LOG_OBJECT_ID (sq->debug_id, "CHECKING srcresult: %s",
gst_flow_get_name (sq->srcresult));
/* Check again if we're flushing after the lock is taken,
@ -2256,7 +2257,7 @@ next:
/* Recompute the high time */
compute_high_time (mq, sq->groupid);
GST_DEBUG_OBJECT (mq,
GST_DEBUG_OBJECT_ID (sq->debug_id,
"groupid %d high_time %" GST_STIME_FORMAT " next_time %"
GST_STIME_FORMAT, sq->groupid, GST_STIME_ARGS (sq->group_high_time),
GST_STIME_ARGS (next_time));
@ -2275,10 +2276,10 @@ next:
while (should_wait && sq->srcresult == GST_FLOW_NOT_LINKED) {
GST_DEBUG_OBJECT (mq,
"queue %d sleeping for not-linked wakeup with "
GST_DEBUG_OBJECT_ID (sq->debug_id,
"Sleeping for not-linked wakeup with "
"newid %u, highid %u, next_time %" GST_STIME_FORMAT
", high_time %" GST_STIME_FORMAT, sq->id, newid, mq->highid,
", high_time %" GST_STIME_FORMAT, newid, mq->highid,
GST_STIME_ARGS (next_time), GST_STIME_ARGS (sq->group_high_time));
/* Wake up all non-linked pads before we sleep */
@ -2297,10 +2298,10 @@ next:
compute_high_time (mq, sq->groupid);
compute_high_id (mq);
GST_DEBUG_OBJECT (mq, "queue %d woken from sleeping for not-linked "
GST_DEBUG_OBJECT_ID (sq->debug_id, "Woken from sleeping for not-linked "
"wakeup with newid %u, highid %u, next_time %" GST_STIME_FORMAT
", high_time %" GST_STIME_FORMAT " mq high_time %" GST_STIME_FORMAT,
sq->id, newid, mq->highid,
newid, mq->highid,
GST_STIME_ARGS (next_time), GST_STIME_ARGS (sq->group_high_time),
GST_STIME_ARGS (mq->high_time));
@ -2335,7 +2336,7 @@ next:
if (sq->flushing)
goto out_flushing;
GST_LOG_OBJECT (mq, "sq:%d BEFORE PUSHING sq->srcresult: %s", sq->id,
GST_LOG_OBJECT_ID (sq->debug_id, "BEFORE PUSHING sq->srcresult: %s",
gst_flow_get_name (sq->srcresult));
/* Update time stats */
@ -2369,8 +2370,7 @@ next:
&& result == GST_FLOW_NOT_LINKED) {
GList *tmp;
GST_LOG_OBJECT (mq, "SingleQueue %d : Changed from active to non-active",
sq->id);
GST_LOG_OBJECT_ID (sq->debug_id, "Changed from active to non-active");
compute_high_id (mq);
compute_high_time (mq, sq->groupid);
@ -2383,7 +2383,7 @@ next:
GstSingleQueue *sq2 = (GstSingleQueue *) tmp->data;
if (sq2->srcresult == GST_FLOW_NOT_LINKED) {
GST_LOG_OBJECT (mq, "Waking up singlequeue %d", sq2->id);
GST_LOG_OBJECT_ID (sq2->debug_id, "Waking up singlequeue");
sq2->pushed = FALSE;
sq2->srcresult = GST_FLOW_OK;
g_cond_signal (&sq2->turn);
@ -2401,7 +2401,7 @@ next:
* sure we are relaying the correct info wrt proper segment */
if (result == GST_FLOW_EOS && !dropping &&
sq->srcresult != GST_FLOW_NOT_LINKED) {
GST_DEBUG_OBJECT (mq, "starting EOS drop on sq %d", sq->id);
GST_DEBUG_OBJECT_ID (sq->debug_id, "starting EOS drop");
dropping = TRUE;
/* pretend we have not seen EOS yet for upstream's sake */
result = sq->srcresult;
@ -2409,7 +2409,7 @@ next:
/* queue empty, so stop dropping
* we can commit the result we have now,
* which is either OK after a segment, or EOS */
GST_DEBUG_OBJECT (mq, "committed EOS drop on sq %d", sq->id);
GST_DEBUG_OBJECT_ID (sq->debug_id, "committed EOS drop");
dropping = FALSE;
result = GST_FLOW_EOS;
}
@ -2422,8 +2422,9 @@ next:
GST_MULTI_QUEUE_MUTEX_UNLOCK (mq);
gst_multi_queue_post_buffering (mq);
GST_LOG_OBJECT (mq, "sq:%d AFTER PUSHING sq->srcresult: %s (is_eos:%d)",
sq->id, gst_flow_get_name (sq->srcresult), GST_PAD_IS_EOS (srcpad));
GST_LOG_OBJECT_ID (sq->debug_id,
"AFTER PUSHING sq->srcresult: %s (is_eos:%d)",
gst_flow_get_name (sq->srcresult), GST_PAD_IS_EOS (srcpad));
/* Need to make sure wake up any sleeping pads when we exit */
GST_MULTI_QUEUE_MUTEX_LOCK (mq);
@ -2477,9 +2478,8 @@ out_flushing:
single_queue_underrun_cb (sq->queue, sq);
gst_data_queue_set_flushing (sq->queue, TRUE);
gst_pad_pause_task (srcpad);
GST_CAT_LOG_OBJECT (multi_queue_debug, mq,
"SingleQueue[%d] task paused, reason:%s",
sq->id, gst_flow_get_name (sq->srcresult));
GST_LOG_OBJECT_ID (sq->debug_id,
"task paused, reason:%s", gst_flow_get_name (sq->srcresult));
goto done;
}
}
@ -2518,10 +2518,10 @@ gst_multi_queue_chain (GstPad * pad, GstObject * parent, GstBuffer * buffer)
timestamp = GST_BUFFER_DTS_OR_PTS (buffer);
duration = GST_BUFFER_DURATION (buffer);
GST_LOG_OBJECT (mq,
"SingleQueue %d : about to enqueue buffer %p with id %d (pts:%"
GST_LOG_OBJECT_ID (sq->debug_id,
"About to enqueue buffer %p with id %d (pts:%"
GST_TIME_FORMAT " dts:%" GST_TIME_FORMAT " dur:%" GST_TIME_FORMAT ")",
sq->id, buffer, curid, GST_TIME_ARGS (GST_BUFFER_PTS (buffer)),
buffer, curid, GST_TIME_ARGS (GST_BUFFER_PTS (buffer)),
GST_TIME_ARGS (GST_BUFFER_DTS (buffer)), GST_TIME_ARGS (duration));
item = gst_multi_queue_buffer_item_new (GST_MINI_OBJECT_CAST (buffer), curid);
@ -2540,9 +2540,9 @@ gst_multi_queue_chain (GstPad * pad, GstObject * parent, GstBuffer * buffer)
dval = my_segment_to_running_time (&sq->sink_segment, val);
if (GST_CLOCK_STIME_IS_VALID (dval)) {
sq->cached_sinktime = dval;
GST_DEBUG_OBJECT (mq,
"Queue %d cached sink time now %" G_GINT64_FORMAT " %"
GST_STIME_FORMAT, sq->id, sq->cached_sinktime,
GST_DEBUG_OBJECT_ID (sq->debug_id,
"Cached sink time now %" G_GINT64_FORMAT " %"
GST_STIME_FORMAT, sq->cached_sinktime,
GST_STIME_ARGS (sq->cached_sinktime));
calculate_interleave (mq, sq);
}
@ -2563,8 +2563,8 @@ done:
/* ERRORS */
flushing:
{
GST_LOG_OBJECT (mq, "SingleQueue %d : exit because task paused, reason: %s",
sq->id, gst_flow_get_name (sq->srcresult));
GST_LOG_OBJECT_ID (sq->debug_id, "exit because task paused, reason: %s",
gst_flow_get_name (sq->srcresult));
if (item)
gst_multi_queue_item_destroy (item);
goto done;
@ -2678,7 +2678,7 @@ gst_multi_queue_sink_event (GstPad * pad, GstObject * parent, GstEvent * event)
GstStreamFlags stream_flags;
gst_event_parse_stream_flags (event, &stream_flags);
if ((stream_flags & GST_STREAM_FLAG_SPARSE)) {
GST_INFO_OBJECT (mq, "SingleQueue %d is a sparse stream", sq->id);
GST_INFO_OBJECT_ID (sq->debug_id, "Stream is sparse");
sq->is_sparse = TRUE;
}
}
@ -2690,8 +2690,7 @@ gst_multi_queue_sink_event (GstPad * pad, GstObject * parent, GstEvent * event)
break;
}
case GST_EVENT_FLUSH_START:
GST_DEBUG_OBJECT (mq, "SingleQueue %d : received flush start event",
sq->id);
GST_DEBUG_OBJECT_ID (sq->debug_id, "Received flush start event");
res = gst_pad_push_event (srcpad, event);
@ -2700,8 +2699,7 @@ gst_multi_queue_sink_event (GstPad * pad, GstObject * parent, GstEvent * event)
goto done;
case GST_EVENT_FLUSH_STOP:
GST_DEBUG_OBJECT (mq, "SingleQueue %d : received flush stop event",
sq->id);
GST_DEBUG_OBJECT_ID (sq->debug_id, "Received flush stop event");
res = gst_pad_push_event (srcpad, event);
@ -2752,9 +2750,9 @@ gst_multi_queue_sink_event (GstPad * pad, GstObject * parent, GstEvent * event)
item = gst_multi_queue_mo_item_new ((GstMiniObject *) event, curid);
GST_DEBUG_OBJECT (mq,
"SingleQueue %d : Enqueuing event %p of type %s with id %d",
sq->id, event, GST_EVENT_TYPE_NAME (event), curid);
GST_DEBUG_OBJECT_ID (sq->debug_id,
"Enqueuing event %p of type %s with id %d",
event, GST_EVENT_TYPE_NAME (event), curid);
if (!gst_data_queue_push (sq->queue, (GstDataQueueItem *) item))
goto flushing;
@ -2815,15 +2813,15 @@ done:
gst_object_unref (srcpad);
if (res == FALSE)
flowret = GST_FLOW_ERROR;
GST_DEBUG_OBJECT (mq, "SingleQueue %d : returning %s", sq->id,
GST_DEBUG_OBJECT_ID (sq->debug_id, "Returning %s",
gst_flow_get_name (flowret));
return flowret;
flushing:
{
gst_object_unref (srcpad);
GST_LOG_OBJECT (mq, "SingleQueue %d : exit because task paused, reason: %s",
sq->id, gst_flow_get_name (sq->srcresult));
GST_LOG_OBJECT_ID (sq->debug_id, "Exit because task paused, reason: %s",
gst_flow_get_name (sq->srcresult));
if (sref)
gst_event_unref (sref);
gst_multi_queue_item_destroy (item);
@ -2871,9 +2869,9 @@ gst_multi_queue_sink_query (GstPad * pad, GstObject * parent, GstQuery * query)
item = gst_multi_queue_mo_item_new ((GstMiniObject *) query, curid);
GST_DEBUG_OBJECT (mq,
"SingleQueue %d : Enqueuing query %p of type %s with id %d",
sq->id, query, GST_QUERY_TYPE_NAME (query), curid);
GST_DEBUG_OBJECT_ID (sq->debug_id,
"Enqueuing query %p of type %s with id %d",
query, GST_QUERY_TYPE_NAME (query), curid);
GST_MULTI_QUEUE_MUTEX_UNLOCK (mq);
res = gst_data_queue_push (sq->queue, (GstDataQueueItem *) item);
GST_MULTI_QUEUE_MUTEX_LOCK (mq);
@ -2924,12 +2922,12 @@ gst_multi_queue_src_activate_mode (GstPad * pad, GstObject * parent,
mq = g_weak_ref_get (&sq->mqueue);
if (!mq) {
GST_ERROR_OBJECT (pad, "No multique set anymore, can't activate pad");
GST_ERROR_OBJECT (pad, "No multiqueue set anymore, can't activate pad");
return FALSE;
}
GST_DEBUG_OBJECT (mq, "SingleQueue %d", sq->id);
GST_DEBUG_OBJECT_ID (sq->debug_id, "active: %d", active);
switch (mode) {
case GST_PAD_MODE_PUSH:
@ -3031,7 +3029,7 @@ wake_up_next_non_linked (GstMultiQueue * mq)
if (GST_CLOCK_STIME_IS_VALID (sq->next_time) &&
GST_CLOCK_STIME_IS_VALID (high_time)
&& sq->next_time <= high_time) {
GST_LOG_OBJECT (mq, "Waking up singlequeue %d", sq->id);
GST_LOG_OBJECT_ID (sq->debug_id, "Waking up singlequeue");
g_cond_signal (&sq->turn);
}
}
@ -3042,7 +3040,7 @@ wake_up_next_non_linked (GstMultiQueue * mq)
GstSingleQueue *sq = (GstSingleQueue *) tmp->data;
if (sq->srcresult == GST_FLOW_NOT_LINKED &&
sq->nextid != 0 && sq->nextid <= mq->highid) {
GST_LOG_OBJECT (mq, "Waking up singlequeue %d", sq->id);
GST_LOG_OBJECT_ID (sq->debug_id, "Waking up singlequeue");
g_cond_signal (&sq->turn);
}
}
@ -3070,12 +3068,12 @@ compute_high_id (GstMultiQueue * mq)
continue;
}
GST_LOG_OBJECT (mq, "inspecting sq:%d , nextid:%d, oldid:%d, srcresult:%s",
sq->id, sq->nextid, sq->oldid, gst_flow_get_name (sq->srcresult));
GST_LOG_OBJECT_ID (sq->debug_id, "nextid:%d, oldid:%d, srcresult:%s",
sq->nextid, sq->oldid, gst_flow_get_name (sq->srcresult));
/* No need to consider queues which are not waiting */
if (sq->nextid == 0) {
GST_LOG_OBJECT (mq, "sq:%d is not waiting - ignoring", sq->id);
GST_LOG_OBJECT_ID (sq->debug_id, "not waiting - ignoring");
gst_object_unref (srcpad);
continue;
}
@ -3133,9 +3131,9 @@ compute_high_time (GstMultiQueue * mq, guint groupid)
continue;
}
GST_LOG_OBJECT (mq,
"inspecting sq:%d (group:%d) , next_time:%" GST_STIME_FORMAT
", last_time:%" GST_STIME_FORMAT ", srcresult:%s", sq->id, sq->groupid,
GST_LOG_OBJECT_ID (sq->debug_id,
"inspecting (group:%d) , next_time:%" GST_STIME_FORMAT
", last_time:%" GST_STIME_FORMAT ", srcresult:%s", sq->groupid,
GST_STIME_ARGS (sq->next_time), GST_STIME_ARGS (sq->last_time),
gst_flow_get_name (sq->srcresult));
@ -3145,7 +3143,7 @@ compute_high_time (GstMultiQueue * mq, guint groupid)
if (sq->srcresult == GST_FLOW_NOT_LINKED) {
/* No need to consider queues which are not waiting */
if (!GST_CLOCK_STIME_IS_VALID (sq->next_time)) {
GST_LOG_OBJECT (mq, "sq:%d is not waiting - ignoring", sq->id);
GST_LOG_OBJECT_ID (sq->debug_id, "Not waiting - ignoring");
gst_object_unref (srcpad);
continue;
}
@ -3228,9 +3226,9 @@ single_queue_overrun_cb (GstDataQueue * dq, GstSingleQueue * sq)
gst_data_queue_get_level (sq->queue, &size);
GST_LOG_OBJECT (mq,
"Single Queue %d: EOS %d, visible %u/%u, bytes %u/%u, time %"
G_GUINT64_FORMAT "/%" G_GUINT64_FORMAT, sq->id, sq->is_eos, size.visible,
GST_LOG_OBJECT_ID (sq->debug_id,
"EOS %d, visible %u/%u, bytes %u/%u, time %"
G_GUINT64_FORMAT "/%" G_GUINT64_FORMAT, sq->is_eos, size.visible,
sq->max_size.visible, size.bytes, sq->max_size.bytes, sq->cur_time,
sq->max_size.time);
@ -3251,13 +3249,13 @@ single_queue_overrun_cb (GstDataQueue * dq, GstSingleQueue * sq)
continue;
if (oq->srcresult == GST_FLOW_NOT_LINKED) {
GST_LOG_OBJECT (mq, "Queue %d is not-linked", oq->id);
GST_LOG_OBJECT_ID (sq->debug_id, "Queue is not-linked");
continue;
}
GST_LOG_OBJECT (mq, "Checking Queue %d", oq->id);
GST_LOG_OBJECT_ID (oq->debug_id, "Checking queue");
if (gst_data_queue_is_empty (oq->queue) && !oq->is_sparse) {
GST_LOG_OBJECT (mq, "Queue %d is empty", oq->id);
GST_LOG_OBJECT_ID (oq->debug_id, "Queue is empty");
empty_found = TRUE;
break;
}
@ -3268,9 +3266,8 @@ single_queue_overrun_cb (GstDataQueue * dq, GstSingleQueue * sq)
if (empty_found) {
if (IS_FILLED (sq, visible, size.visible)) {
sq->max_size.visible = size.visible + 1;
GST_DEBUG_OBJECT (mq,
"Bumping single queue %d max visible to %d",
sq->id, sq->max_size.visible);
GST_DEBUG_OBJECT_ID (sq->debug_id,
"Bumping max visible to %d", sq->max_size.visible);
filled = FALSE;
}
}
@ -3281,7 +3278,7 @@ done:
/* Overrun is always forwarded, since this is blocking the upstream element */
if (filled) {
GST_DEBUG_OBJECT (mq, "Queue %d is filled, signalling overrun", sq->id);
GST_DEBUG_OBJECT_ID (sq->debug_id, "Queue is filled, signalling overrun");
g_signal_emit (mq, gst_multi_queue_signals[SIGNAL_OVERRUN], 0);
}
}
@ -3300,12 +3297,12 @@ single_queue_underrun_cb (GstDataQueue * dq, GstSingleQueue * sq)
}
if (sq->srcresult == GST_FLOW_NOT_LINKED) {
GST_LOG_OBJECT (mq, "Single Queue %d is empty but not-linked", sq->id);
GST_LOG_OBJECT_ID (sq->debug_id, "Single Queue is empty but not-linked");
gst_object_unref (mq);
return;
} else {
GST_LOG_OBJECT (mq,
"Single Queue %d is empty, Checking other single queues", sq->id);
GST_LOG_OBJECT_ID (sq->debug_id,
"Single Queue is empty, Checking other single queues");
}
GST_MULTI_QUEUE_MUTEX_LOCK (mq);
@ -3318,8 +3315,8 @@ single_queue_underrun_cb (GstDataQueue * dq, GstSingleQueue * sq)
gst_data_queue_get_level (oq->queue, &size);
if (IS_FILLED (oq, visible, size.visible)) {
oq->max_size.visible = size.visible + 1;
GST_DEBUG_OBJECT (mq,
"queue %d is filled, bumping its max visible to %d", oq->id,
GST_DEBUG_OBJECT_ID (oq->debug_id,
"queue is filled, bumping its max visible to %d",
oq->max_size.visible);
gst_data_queue_limits_changed (oq->queue);
}
@ -3349,9 +3346,9 @@ single_queue_check_full (GstDataQueue * dataq, guint visible, guint bytes,
return TRUE;
}
GST_DEBUG_OBJECT (mq,
"queue %d: visible %u/%u, bytes %u/%u, time %" G_GUINT64_FORMAT "/%"
G_GUINT64_FORMAT, sq->id, visible, sq->max_size.visible, bytes,
GST_DEBUG_OBJECT_ID (sq->debug_id,
"visible %u/%u, bytes %u/%u, time %" G_GUINT64_FORMAT "/%"
G_GUINT64_FORMAT, visible, sq->max_size.visible, bytes,
sq->max_size.bytes, sq->cur_time, sq->max_size.time);
/* we are always filled on EOS */
@ -3448,6 +3445,9 @@ gst_single_queue_unref (GstSingleQueue * sq)
g_weak_ref_clear (&sq->sinkpad);
g_weak_ref_clear (&sq->srcpad);
g_weak_ref_clear (&sq->mqueue);
#ifndef GST_DISABLE_GST_DEBUG
g_free (sq->debug_id);
#endif
g_free (sq);
}
}
@ -3496,6 +3496,10 @@ gst_single_queue_new (GstMultiQueue * mqueue, guint id)
mqueue->nbqueues++;
sq->id = temp_id;
#ifndef GST_DISABLE_GST_DEBUG
sq->debug_id =
g_strdup_printf ("%s:queue_%d", GST_OBJECT_NAME (mqueue), temp_id);
#endif
sq->groupid = DEFAULT_PAD_GROUP_ID;
sq->group_high_time = GST_CLOCK_STIME_NONE;
@ -3603,8 +3607,7 @@ gst_single_queue_new (GstMultiQueue * mqueue, guint id)
}
g_rec_mutex_unlock (GST_STATE_GET_LOCK (mqueue));
GST_DEBUG_OBJECT (mqueue, "GstSingleQueue [%d] created and pads added",
sq->id);
GST_DEBUG_OBJECT_ID (sq->debug_id, "GstSingleQueue created and pads added");
return sq;
}