2 * Copyright (C) 2013 Stefan Sauer <ensonic@users.sf.net>
4 * gststats.c: tracing module that logs events
6 * This library is free software; you can redistribute it and/or
7 * modify it under the terms of the GNU Library General Public
8 * License as published by the Free Software Foundation; either
9 * version 2 of the License, or (at your option) any later version.
11 * This library is distributed in the hope that it will be useful,
12 * but WITHOUT ANY WARRANTY; without even the implied warranty of
13 * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the GNU
14 * Library General Public License for more details.
16 * You should have received a copy of the GNU Library General Public
17 * License along with this library; if not, write to the
18 * Free Software Foundation, Inc., 51 Franklin St, Fifth Floor,
19 * Boston, MA 02110-1301, USA.
30 GST_DEBUG_CATEGORY_STATIC (gst_stats_debug);
31 #define GST_CAT_DEFAULT gst_stats_debug
33 static GQuark data_quark;
34 G_LOCK_DEFINE (_stats);
37 GST_DEBUG_CATEGORY_INIT (gst_stats_debug, "stats", 0, "stats tracer"); \
38 data_quark = g_quark_from_static_string ("gststats:data");
39 #define gst_stats_tracer_parent_class parent_class
40 G_DEFINE_TYPE_WITH_CODE (GstStatsTracer, gst_stats_tracer, GST_TYPE_TRACER,
45 /* we can't rely on the address to be unique over time */
55 /* we can't rely on the address to be unique over time */
59 /* time spend in this element */
68 log_trace (GstStructure * s)
72 // TODO(ensonic): use a GVariant?
73 data = gst_structure_to_string (s);
74 GST_TRACE ("%s", data);
76 gst_structure_free (s);
81 static GstElementStats no_elem_stats = { 0, };
83 static GstElementStats *
84 fill_element_stats (GstStatsTracer * self, GstElement * element)
86 GstElementStats *stats = g_slice_new0 (GstElementStats);
88 stats->index = self->num_elements++;
89 stats->parent_ix = G_MAXUINT;
94 log_new_element_stats (GstElementStats * stats, GstElement * element)
96 log_trace (gst_structure_new ("new-element",
97 "ix", G_TYPE_UINT, stats->index,
98 "parent-ix", G_TYPE_UINT, stats->parent_ix,
99 "name", G_TYPE_STRING, GST_OBJECT_NAME (element),
100 "type", G_TYPE_STRING, G_OBJECT_TYPE_NAME (element),
101 "is-bin", G_TYPE_BOOLEAN, GST_IS_BIN (element), NULL));
104 static inline GstElementStats *
105 get_element_stats (GstStatsTracer * self, GstElement * element)
107 GstElementStats *stats;
108 gboolean is_new = FALSE;
111 no_elem_stats.index = G_MAXUINT;
112 return &no_elem_stats;
116 if (!(stats = g_object_get_qdata ((GObject *) element, data_quark))) {
117 stats = fill_element_stats (self, element);
118 g_object_set_qdata ((GObject *) element, data_quark, stats);
119 if (self->elements->len <= stats->index)
120 g_ptr_array_set_size (self->elements, stats->index + 1);
121 g_ptr_array_index (self->elements, stats->index) = stats;
125 if (G_UNLIKELY (stats->parent_ix == G_MAXUINT)) {
126 GstElement *parent = GST_ELEMENT_PARENT (element);
128 GstElementStats *parent_stats = get_element_stats (self, parent);
129 stats->parent_ix = parent_stats->index;
132 if (G_UNLIKELY (is_new)) {
133 log_new_element_stats (stats, element);
139 free_element_stats (gpointer data)
141 g_slice_free (GstElementStats, data);
145 * Get the element/bin owning the pad.
151 * out: the element that contains the peer of the proxy
154 * out: the bin owning the ghostpad
156 /* TODO(ensonic): gst_pad_get_parent_element() would not work here, should we
157 * add this as new api, e.g. gst_pad_find_parent_element();
160 get_real_pad_parent (GstPad * pad)
167 parent = GST_OBJECT_PARENT (pad);
169 /* if parent of pad is a ghost-pad, then pad is a proxy_pad */
170 if (parent && GST_IS_GHOST_PAD (parent)) {
171 pad = GST_PAD_CAST (parent);
172 parent = GST_OBJECT_PARENT (pad);
174 /* if pad is a ghost-pad, then parent is a bin and it is the parent of a
176 while (parent && GST_IS_GHOST_PAD (pad)) {
177 pad = gst_ghost_pad_get_target (GST_GHOST_PAD (pad));
178 parent = pad ? GST_OBJECT_PARENT (pad) : NULL;
180 return GST_ELEMENT_CAST (parent);
183 static GstPadStats no_pad_stats = { 0, };
186 fill_pad_stats (GstStatsTracer * self, GstPad * pad)
188 GstPadStats *stats = g_slice_new0 (GstPadStats);
190 stats->index = self->num_pads++;
191 stats->parent_ix = G_MAXUINT;
197 log_new_pad_stats (GstPadStats * stats, GstPad * pad)
199 log_trace (gst_structure_new ("new-pad",
200 "ix", G_TYPE_UINT, stats->index,
201 "parent-ix", G_TYPE_UINT, stats->parent_ix,
202 "name", G_TYPE_STRING, GST_OBJECT_NAME (pad),
203 "type", G_TYPE_STRING, G_OBJECT_TYPE_NAME (pad),
204 "is-ghostpad", G_TYPE_BOOLEAN, GST_IS_GHOST_PAD (pad),
205 "pad-direction", GST_TYPE_PAD_DIRECTION, GST_PAD_DIRECTION (pad),
206 "thread-id", G_TYPE_UINT, GPOINTER_TO_UINT (g_thread_self ()), NULL));
210 get_pad_stats (GstStatsTracer * self, GstPad * pad)
213 gboolean is_new = FALSE;
216 no_pad_stats.index = G_MAXUINT;
217 return &no_pad_stats;
221 if (!(stats = g_object_get_qdata ((GObject *) pad, data_quark))) {
222 stats = fill_pad_stats (self, pad);
223 g_object_set_qdata ((GObject *) pad, data_quark, stats);
224 if (self->pads->len <= stats->index)
225 g_ptr_array_set_size (self->pads, stats->index + 1);
226 g_ptr_array_index (self->pads, stats->index) = stats;
230 if (G_UNLIKELY (stats->parent_ix == G_MAXUINT)) {
231 GstElement *elem = get_real_pad_parent (pad);
233 GstElementStats *elem_stats = get_element_stats (self, elem);
235 stats->parent_ix = elem_stats->index;
238 if (G_UNLIKELY (is_new)) {
239 log_new_pad_stats (stats, pad);
245 free_pad_stats (gpointer data)
247 g_slice_free (GstPadStats, data);
251 do_buffer_stats (GstStatsTracer * self, GstPad * this_pad,
252 GstPadStats * this_pad_stats, GstPad * that_pad,
253 GstPadStats * that_pad_stats, GstBuffer * buf, GstClockTime elapsed)
255 GstElement *this_elem = get_real_pad_parent (this_pad);
256 GstElementStats *this_elem_stats = get_element_stats (self, this_elem);
257 GstElement *that_elem = get_real_pad_parent (that_pad);
258 GstElementStats *that_elem_stats = get_element_stats (self, that_elem);
260 /* TODO(ensonic): need a quark-table (shared with the tracer-front-ends?) */
261 log_trace (gst_structure_new ("buffer",
262 "ts", G_TYPE_UINT64, elapsed,
263 "pad-ix", G_TYPE_UINT, this_pad_stats->index,
264 "elem-ix", G_TYPE_UINT, this_elem_stats->index,
265 "peer-pad-ix", G_TYPE_UINT, that_pad_stats->index,
266 "peer-elem-ix", G_TYPE_UINT, that_elem_stats->index,
267 "buffer-size", G_TYPE_UINT, gst_buffer_get_size (buf),
268 "buffer-ts", G_TYPE_UINT64, GST_BUFFER_TIMESTAMP (buf),
269 "buffer-duration", G_TYPE_UINT64, GST_BUFFER_DURATION (buf),
270 "buffer-flags", GST_TYPE_BUFFER_FLAGS, GST_BUFFER_FLAGS (buf),
272 scheduling-jitter: for this we need the last_ts on the pad
278 do_element_stats (GstStatsTracer * self, GstPad * pad, GstClockTime elapsed1,
279 GstClockTime elapsed2)
281 GstClockTimeDiff elapsed = GST_CLOCK_DIFF (elapsed1, elapsed2);
282 GstObject *parent = GST_OBJECT_PARENT (pad);
284 GST_ELEMENT_CAST (GST_IS_PAD (parent) ? GST_OBJECT_PARENT (parent) :
286 GstElementStats *this_stats = get_element_stats (self, this);
287 GstPad *peer_pad = GST_PAD_PEER (pad);
288 GstElementStats *peer_stats;
293 /* walk the ghost pad chain downstream to get the real pad */
294 /* if parent of peer_pad is a ghost-pad, then peer_pad is a proxy_pad */
295 parent = GST_OBJECT_PARENT (peer_pad);
296 if (parent && GST_IS_GHOST_PAD (parent)) {
297 peer_pad = GST_PAD_CAST (parent);
298 /* if this is now the ghost pad, get the peer of this */
299 get_pad_stats (self, peer_pad);
300 if ((parent = GST_OBJECT_PARENT (peer_pad))) {
301 get_element_stats (self, GST_ELEMENT_CAST (parent));
303 peer_pad = GST_PAD_PEER (GST_GHOST_PAD_CAST (peer_pad));
304 parent = peer_pad ? GST_OBJECT_PARENT (peer_pad) : NULL;
306 /* walk the ghost pad chain upstream to get the real pad */
307 /* if peer_pad is a ghost-pad, then parent is a bin and it is the parent of
309 while (peer_pad && GST_IS_GHOST_PAD (peer_pad)) {
310 get_pad_stats (self, peer_pad);
311 get_element_stats (self, GST_ELEMENT_CAST (parent));
312 peer_pad = gst_ghost_pad_get_target (GST_GHOST_PAD_CAST (peer_pad));
313 parent = peer_pad ? GST_OBJECT_PARENT (peer_pad) : NULL;
317 printf ("%" GST_TIME_FORMAT
318 " transmission on unparented target pad %s_%s -> %s_%s\n",
319 GST_TIME_ARGS (elapsed), GST_DEBUG_PAD_NAME (pad),
320 GST_DEBUG_PAD_NAME (peer_pad));
323 peer_stats = get_element_stats (self, GST_ELEMENT_CAST (parent));
325 /* we'd like to gather time spend in each element, but this does not make too
327 * pure push/pull-based:
328 * - the time spend in the push/pull_range is accounted for the peer and
329 * removed from the current element
330 * - this works for chains
331 * - drawback is sink elements that block to sync have a high time usage
332 * - we could rerun the ests with sync=false
334 * - a.g. demuxers both push and pull. thus we subtract time for the pull
335 * and the push operations, but never add anything.
336 * - can we start a counter after push/pull in such elements and add then
337 * time to the element upon next pad activity?
340 /* this does not make sense for demuxers */
341 this_stats->treal -= elapsed;
342 peer_stats->treal += elapsed;
344 /* this creates several >100% figures */
345 this_stats->treal += GST_CLOCK_DIFF (this_stats->last_ts, elapsed2) - elapsed;
346 peer_stats->treal += elapsed;
347 this_stats->last_ts = elapsed2;
348 peer_stats->last_ts = elapsed2;
354 static void gst_stats_tracer_finalize (GObject * obj);
355 static void gst_stats_tracer_invoke (GstTracer * obj, GstTracerHookId id,
356 GstTracerMessageId mid, va_list var_args);
359 gst_stats_tracer_class_init (GstStatsTracerClass * klass)
361 GObjectClass *gobject_class = G_OBJECT_CLASS (klass);
362 GstTracerClass *gst_tracer_class = GST_TRACER_CLASS (klass);
364 gobject_class->finalize = gst_stats_tracer_finalize;
366 gst_tracer_class->invoke = gst_stats_tracer_invoke;
370 gst_stats_tracer_init (GstStatsTracer * self)
372 g_object_set (self, "mask",
373 GST_TRACER_HOOK_BUFFERS | GST_TRACER_HOOK_EVENTS |
374 GST_TRACER_HOOK_MESSAGES | GST_TRACER_HOOK_QUERIES, NULL);
375 self->elements = g_ptr_array_new_with_free_func (free_element_stats);
376 self->pads = g_ptr_array_new_with_free_func (free_pad_stats);
382 do_push_buffer_pre (GstStatsTracer * self, va_list var_args)
384 guint64 ts = va_arg (var_args, guint64);
385 GstPad *this_pad = va_arg (var_args, GstPad *);
386 GstBuffer *buffer = va_arg (var_args, GstBuffer *);
387 GstPadStats *this_pad_stats = get_pad_stats (self, this_pad);
388 GstPad *that_pad = GST_PAD_PEER (this_pad);
389 GstPadStats *that_pad_stats = get_pad_stats (self, that_pad);
391 do_buffer_stats (self, this_pad, this_pad_stats, that_pad, that_pad_stats,
396 do_push_buffer_post (GstStatsTracer * self, va_list var_args)
398 guint64 ts = va_arg (var_args, guint64);
399 GstPad *pad = va_arg (var_args, GstPad *);
400 GstPadStats *stats = get_pad_stats (self, pad);
402 do_element_stats (self, pad, stats->last_ts, ts);
407 GstStatsTracer *self;
409 GstPadStats *this_pad_stats;
411 GstPadStats *that_pad_stats;
413 } DoPushBufferListArgs;
416 do_push_buffer_list_item (GstBuffer ** buffer, guint idx, gpointer user_data)
418 DoPushBufferListArgs *args = (DoPushBufferListArgs *) user_data;
420 do_buffer_stats (args->self, args->this_pad, args->this_pad_stats,
421 args->that_pad, args->that_pad_stats, *buffer, args->ts);
426 do_push_buffer_list_pre (GstStatsTracer * self, va_list var_args)
428 guint64 ts = va_arg (var_args, guint64);
429 GstPad *this_pad = va_arg (var_args, GstPad *);
430 GstBufferList *list = va_arg (var_args, GstBufferList *);
431 GstPadStats *this_pad_stats = get_pad_stats (self, this_pad);
432 GstPad *that_pad = GST_PAD_PEER (this_pad);
433 GstPadStats *that_pad_stats = get_pad_stats (self, that_pad);
434 DoPushBufferListArgs args = { self, this_pad, this_pad_stats, that_pad,
438 gst_buffer_list_foreach (list, do_push_buffer_list_item, &args);
442 do_push_buffer_list_post (GstStatsTracer * self, va_list var_args)
444 guint64 ts = va_arg (var_args, guint64);
445 GstPad *pad = va_arg (var_args, GstPad *);
446 GstPadStats *stats = get_pad_stats (self, pad);
448 do_element_stats (self, pad, stats->last_ts, ts);
452 do_pull_range_pre (GstStatsTracer * self, va_list var_args)
454 guint64 ts = va_arg (var_args, guint64);
455 GstPad *pad = va_arg (var_args, GstPad *);
456 GstPadStats *stats = get_pad_stats (self, pad);
461 do_pull_range_post (GstStatsTracer * self, va_list var_args)
463 guint64 ts = va_arg (var_args, guint64);
464 GstPad *this_pad = va_arg (var_args, GstPad *);
465 GstBuffer *buffer = va_arg (var_args, GstBuffer *);
466 GstPadStats *this_pad_stats = get_pad_stats (self, this_pad);
467 guint64 last_ts = this_pad_stats->last_ts;
468 GstPad *that_pad = GST_PAD_PEER (this_pad);
469 GstPadStats *that_pad_stats = get_pad_stats (self, that_pad);
471 if (buffer != NULL) {
472 do_buffer_stats (self, this_pad, this_pad_stats, that_pad, that_pad_stats,
475 do_element_stats (self, this_pad, last_ts, ts);
479 do_push_event_pre (GstStatsTracer * self, va_list var_args)
481 guint64 ts = va_arg (var_args, guint64);
482 GstPad *pad = va_arg (var_args, GstPad *);
483 GstEvent *ev = va_arg (var_args, GstEvent *);
484 GstElement *elem = get_real_pad_parent (pad);
485 GstElementStats *elem_stats = get_element_stats (self, elem);
486 GstPadStats *pad_stats = get_pad_stats (self, pad);
488 elem_stats->last_ts = ts;
489 log_trace (gst_structure_new ("event",
490 "ts", G_TYPE_UINT64, ts,
491 "pad-ix", G_TYPE_UINT, pad_stats->index,
492 "elem-ix", G_TYPE_UINT, elem_stats->index,
493 "name", G_TYPE_STRING, GST_EVENT_TYPE_NAME (ev), NULL));
497 do_push_event_post (GstStatsTracer * self, va_list var_args)
500 guint64 ts = va_arg (var_args, guint64);
501 GstPad *pad = va_arg (var_args, GstPad *);
506 do_post_message_pre (GstStatsTracer * self, va_list var_args)
508 guint64 ts = va_arg (var_args, guint64);
509 GstElement *elem = va_arg (var_args, GstElement *);
510 GstMessage *msg = va_arg (var_args, GstMessage *);
511 GstElementStats *stats = get_element_stats (self, elem);
514 log_trace (gst_structure_new ("message",
515 "ts", G_TYPE_UINT64, ts,
516 "elem-ix", G_TYPE_UINT, stats->index,
517 "name", G_TYPE_STRING, GST_MESSAGE_TYPE_NAME (msg), NULL));
521 do_post_message_post (GstStatsTracer * self, va_list var_args)
524 guint64 ts = va_arg (var_args, guint64);
525 GstElement *elem = va_arg (var_args, GstElement *);
530 do_query_pre (GstStatsTracer * self, va_list var_args)
532 guint64 ts = va_arg (var_args, guint64);
533 GstElement *elem = va_arg (var_args, GstElement *);
534 GstQuery *qry = va_arg (var_args, GstQuery *);
535 GstElementStats *stats = get_element_stats (self, elem);
538 log_trace (gst_structure_new ("query",
539 "ts", G_TYPE_UINT64, ts,
540 "elem-ix", G_TYPE_UINT, stats->index,
541 "name", G_TYPE_STRING, GST_QUERY_TYPE_NAME (qry), NULL));
545 do_query_post (GstStatsTracer * self, va_list var_args)
548 guint64 ts = va_arg (var_args, guint64);
549 GstElement *elem = va_arg (var_args, GstElement *);
554 gst_stats_tracer_invoke (GstTracer * obj, GstTracerHookId hid,
555 GstTracerMessageId mid, va_list var_args)
557 GstStatsTracer *self = GST_STATS_TRACER_CAST (obj);
560 case GST_TRACER_MESSAGE_ID_PAD_PUSH_PRE:
561 do_push_buffer_pre (self, var_args);
563 case GST_TRACER_MESSAGE_ID_PAD_PUSH_POST:
564 do_push_buffer_post (self, var_args);
566 case GST_TRACER_MESSAGE_ID_PAD_PUSH_LIST_PRE:
567 do_push_buffer_list_pre (self, var_args);
569 case GST_TRACER_MESSAGE_ID_PAD_PUSH_LIST_POST:
570 do_push_buffer_list_post (self, var_args);
572 case GST_TRACER_MESSAGE_ID_PAD_PULL_RANGE_PRE:
573 do_pull_range_pre (self, var_args);
575 case GST_TRACER_MESSAGE_ID_PAD_PULL_RANGE_POST:
576 do_pull_range_post (self, var_args);
578 case GST_TRACER_MESSAGE_ID_PAD_PUSH_EVENT_PRE:
579 do_push_event_pre (self, var_args);
581 case GST_TRACER_MESSAGE_ID_PAD_PUSH_EVENT_POST:
582 do_push_event_post (self, var_args);
584 case GST_TRACER_MESSAGE_ID_ELEMENT_POST_MESSAGE_PRE:
585 do_post_message_pre (self, var_args);
587 case GST_TRACER_MESSAGE_ID_ELEMENT_POST_MESSAGE_POST:
588 do_post_message_post (self, var_args);
590 case GST_TRACER_MESSAGE_ID_ELEMENT_QUERY_PRE:
591 do_query_pre (self, var_args);
593 case GST_TRACER_MESSAGE_ID_ELEMENT_QUERY_POST:
594 do_query_post (self, var_args);
602 gst_stats_tracer_finalize (GObject * obj)
604 //GstStatsTracer *self = GST_STATS_TRACER_CAST (obj);
606 G_OBJECT_CLASS (parent_class)->finalize (obj);