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;
91 log_trace (gst_structure_new ("new-element",
92 "ix", G_TYPE_UINT, stats->index,
93 "name", G_TYPE_STRING, GST_OBJECT_NAME (element),
94 "type", G_TYPE_STRING, G_OBJECT_TYPE_NAME (element),
95 "is-bin", G_TYPE_BOOLEAN, GST_IS_BIN (element), NULL));
100 static inline GstElementStats *
101 get_element_stats (GstStatsTracer * self, GstElement * element)
103 GstElementStats *stats;
106 no_elem_stats.index = G_MAXUINT;
107 return &no_elem_stats;
111 if (!(stats = g_object_get_qdata ((GObject *) element, data_quark))) {
112 stats = fill_element_stats (self, element);
113 g_object_set_qdata ((GObject *) element, data_quark, stats);
114 if (self->elements->len <= stats->index)
115 g_ptr_array_set_size (self->elements, stats->index + 1);
116 g_ptr_array_index (self->elements, stats->index) = stats;
119 if (G_UNLIKELY (stats->parent_ix == G_MAXUINT)) {
120 GstElement *parent = GST_ELEMENT_PARENT (element);
122 GstElementStats *parent_stats = get_element_stats (self, parent);
123 stats->parent_ix = parent_stats->index;
130 free_element_stats (gpointer data)
132 g_slice_free (GstElementStats, data);
135 static GstPadStats no_pad_stats = { 0, };
138 fill_pad_stats (GstStatsTracer * self, GstPad * pad)
140 GstPadStats *stats = g_slice_new0 (GstPadStats);
142 stats->index = self->num_pads++;
143 stats->parent_ix = G_MAXUINT;
145 log_trace (gst_structure_new ("new-pad",
146 "ix", G_TYPE_UINT, stats->index,
147 "name", G_TYPE_STRING, GST_OBJECT_NAME (pad),
148 "type", G_TYPE_STRING, G_OBJECT_TYPE_NAME (pad),
149 "is-ghostpad", G_TYPE_BOOLEAN, GST_IS_GHOST_PAD (pad),
150 "pad-direction", GST_TYPE_PAD_DIRECTION, GST_PAD_DIRECTION (pad),
151 "thread-id", G_TYPE_UINT, GPOINTER_TO_UINT (g_thread_self ()), NULL));
157 * Get the element/bin owning the pad.
163 * out: the element that contains the peer of the proxy
166 * out: the bin owning the ghostpad
168 /* TODO(ensonic): gst_pad_get_parent_element() would not work here, should we
169 * add this as new api, e.g. gst_pad_find_parent_element();
172 get_real_pad_parent (GstPad * pad)
179 parent = GST_OBJECT_PARENT (pad);
181 /* if parent of pad is a ghost-pad, then pad is a proxy_pad */
182 if (parent && GST_IS_GHOST_PAD (parent)) {
183 pad = GST_PAD_CAST (parent);
184 parent = GST_OBJECT_PARENT (pad);
186 /* if pad is a ghost-pad, then parent is a bin and it is the parent of a
188 while (parent && GST_IS_GHOST_PAD (pad)) {
189 pad = gst_ghost_pad_get_target (GST_GHOST_PAD (pad));
190 parent = pad ? GST_OBJECT_PARENT (pad) : NULL;
192 return GST_ELEMENT_CAST (parent);
196 get_pad_stats (GstStatsTracer * self, GstPad * pad)
201 no_pad_stats.index = G_MAXUINT;
202 return &no_pad_stats;
206 if (!(stats = g_object_get_qdata ((GObject *) pad, data_quark))) {
207 stats = fill_pad_stats (self, pad);
208 g_object_set_qdata ((GObject *) pad, data_quark, stats);
209 if (self->pads->len <= stats->index)
210 g_ptr_array_set_size (self->pads, stats->index + 1);
211 g_ptr_array_index (self->pads, stats->index) = stats;
214 if (G_UNLIKELY (stats->parent_ix == G_MAXUINT)) {
215 GstElement *elem = get_real_pad_parent (pad);
217 GstElementStats *elem_stats = get_element_stats (self, elem);
219 stats->parent_ix = elem_stats->index;
226 free_pad_stats (gpointer data)
228 g_slice_free (GstPadStats, data);
232 do_buffer_stats (GstStatsTracer * self, GstPad * this_pad,
233 GstPadStats * this_pad_stats, GstPad * that_pad,
234 GstPadStats * that_pad_stats, GstBuffer * buf, GstClockTime elapsed)
236 GstElement *this_elem = get_real_pad_parent (this_pad);
237 GstElementStats *this_elem_stats = get_element_stats (self, this_elem);
238 GstElement *that_elem = get_real_pad_parent (that_pad);
239 GstElementStats *that_elem_stats = get_element_stats (self, that_elem);
241 /* TODO(ensonic): need a quark-table (shared with the tracer-front-ends?) */
242 log_trace (gst_structure_new ("buffer",
243 "ts", G_TYPE_UINT64, elapsed,
244 "pad-ix", G_TYPE_UINT, this_pad_stats->index,
245 "elem-ix", G_TYPE_UINT, this_elem_stats->index,
246 "peer-pad-ix", G_TYPE_UINT, that_pad_stats->index,
247 "peer-elem-ix", G_TYPE_UINT, that_elem_stats->index,
248 "buffer-size", G_TYPE_UINT, gst_buffer_get_size (buf),
249 "buffer-ts", G_TYPE_UINT64, GST_BUFFER_TIMESTAMP (buf),
250 "buffer-duration", G_TYPE_UINT64, GST_BUFFER_DURATION (buf),
251 "buffer-flags", GST_TYPE_BUFFER_FLAGS, GST_BUFFER_FLAGS (buf),
253 scheduling-jitter: for this we need the last_ts on the pad
259 do_element_stats (GstStatsTracer * self, GstPad * pad, GstClockTime elapsed1,
260 GstClockTime elapsed2)
262 GstClockTimeDiff elapsed = GST_CLOCK_DIFF (elapsed1, elapsed2);
263 GstObject *parent = GST_OBJECT_PARENT (pad);
265 GST_ELEMENT_CAST (GST_IS_PAD (parent) ? GST_OBJECT_PARENT (parent) :
267 GstElementStats *this_stats = get_element_stats (self, this);
268 GstPad *peer_pad = GST_PAD_PEER (pad);
269 GstElementStats *peer_stats;
274 /* walk the ghost pad chain downstream to get the real pad */
275 /* if parent of peer_pad is a ghost-pad, then peer_pad is a proxy_pad */
276 parent = GST_OBJECT_PARENT (peer_pad);
277 if (parent && GST_IS_GHOST_PAD (parent)) {
278 peer_pad = GST_PAD_CAST (parent);
279 /* if this is now the ghost pad, get the peer of this */
280 get_pad_stats (self, peer_pad);
281 if ((parent = GST_OBJECT_PARENT (peer_pad))) {
282 get_element_stats (self, GST_ELEMENT_CAST (parent));
284 peer_pad = GST_PAD_PEER (GST_GHOST_PAD_CAST (peer_pad));
285 parent = peer_pad ? GST_OBJECT_PARENT (peer_pad) : NULL;
287 /* walk the ghost pad chain upstream to get the real pad */
288 /* if peer_pad is a ghost-pad, then parent is a bin and it is the parent of
290 while (peer_pad && GST_IS_GHOST_PAD (peer_pad)) {
291 get_pad_stats (self, peer_pad);
292 get_element_stats (self, GST_ELEMENT_CAST (parent));
293 peer_pad = gst_ghost_pad_get_target (GST_GHOST_PAD_CAST (peer_pad));
294 parent = peer_pad ? GST_OBJECT_PARENT (peer_pad) : NULL;
298 printf ("%" GST_TIME_FORMAT
299 " transmission on unparented target pad %s_%s -> %s_%s\n",
300 GST_TIME_ARGS (elapsed), GST_DEBUG_PAD_NAME (pad),
301 GST_DEBUG_PAD_NAME (peer_pad));
304 peer_stats = get_element_stats (self, GST_ELEMENT_CAST (parent));
306 /* we'd like to gather time spend in each element, but this does not make too
308 * pure push/pull-based:
309 * - the time spend in the push/pull_range is accounted for the peer and
310 * removed from the current element
311 * - this works for chains
312 * - drawback is sink elements that block to sync have a high time usage
313 * - we could rerun the ests with sync=false
315 * - a.g. demuxers both push and pull. thus we subtract time for the pull
316 * and the push operations, but never add anything.
317 * - can we start a counter after push/pull in such elements and add then
318 * time to the element upon next pad activity?
321 /* this does not make sense for demuxers */
322 this_stats->treal -= elapsed;
323 peer_stats->treal += elapsed;
325 /* this creates several >100% figures */
326 this_stats->treal += GST_CLOCK_DIFF (this_stats->last_ts, elapsed2) - elapsed;
327 peer_stats->treal += elapsed;
328 this_stats->last_ts = elapsed2;
329 peer_stats->last_ts = elapsed2;
335 static void gst_stats_tracer_finalize (GObject * obj);
336 static void gst_stats_tracer_invoke (GstTracer * obj, GstTracerHookId id,
337 GstTracerMessageId mid, va_list var_args);
340 gst_stats_tracer_class_init (GstStatsTracerClass * klass)
342 GObjectClass *gobject_class = G_OBJECT_CLASS (klass);
343 GstTracerClass *gst_tracer_class = GST_TRACER_CLASS (klass);
345 gobject_class->finalize = gst_stats_tracer_finalize;
347 gst_tracer_class->invoke = gst_stats_tracer_invoke;
351 gst_stats_tracer_init (GstStatsTracer * self)
353 g_object_set (self, "mask",
354 GST_TRACER_HOOK_BUFFERS | GST_TRACER_HOOK_EVENTS |
355 GST_TRACER_HOOK_MESSAGES | GST_TRACER_HOOK_QUERIES, NULL);
356 self->elements = g_ptr_array_new_with_free_func (free_element_stats);
357 self->pads = g_ptr_array_new_with_free_func (free_pad_stats);
363 do_push_buffer_pre (GstStatsTracer * self, va_list var_args)
365 guint64 ts = va_arg (var_args, guint64);
366 GstPad *this_pad = va_arg (var_args, GstPad *);
367 GstBuffer *buffer = va_arg (var_args, GstBuffer *);
368 GstPadStats *this_pad_stats = get_pad_stats (self, this_pad);
369 GstPad *that_pad = GST_PAD_PEER (this_pad);
370 GstPadStats *that_pad_stats = get_pad_stats (self, that_pad);
372 do_buffer_stats (self, this_pad, this_pad_stats, that_pad, that_pad_stats,
377 do_push_buffer_post (GstStatsTracer * self, va_list var_args)
379 guint64 ts = va_arg (var_args, guint64);
380 GstPad *pad = va_arg (var_args, GstPad *);
381 GstPadStats *stats = get_pad_stats (self, pad);
383 do_element_stats (self, pad, stats->last_ts, ts);
388 GstStatsTracer *self;
390 GstPadStats *this_pad_stats;
392 GstPadStats *that_pad_stats;
394 } DoPushBufferListArgs;
397 do_push_buffer_list_item (GstBuffer ** buffer, guint idx, gpointer user_data)
399 DoPushBufferListArgs *args = (DoPushBufferListArgs *) user_data;
401 do_buffer_stats (args->self, args->this_pad, args->this_pad_stats,
402 args->that_pad, args->that_pad_stats, *buffer, args->ts);
407 do_push_buffer_list_pre (GstStatsTracer * self, va_list var_args)
409 guint64 ts = va_arg (var_args, guint64);
410 GstPad *this_pad = va_arg (var_args, GstPad *);
411 GstBufferList *list = va_arg (var_args, GstBufferList *);
412 GstPadStats *this_pad_stats = get_pad_stats (self, this_pad);
413 GstPad *that_pad = GST_PAD_PEER (this_pad);
414 GstPadStats *that_pad_stats = get_pad_stats (self, that_pad);
415 DoPushBufferListArgs args = { self, this_pad, this_pad_stats, that_pad,
419 gst_buffer_list_foreach (list, do_push_buffer_list_item, &args);
423 do_push_buffer_list_post (GstStatsTracer * self, va_list var_args)
425 guint64 ts = va_arg (var_args, guint64);
426 GstPad *pad = va_arg (var_args, GstPad *);
427 GstPadStats *stats = get_pad_stats (self, pad);
429 do_element_stats (self, pad, stats->last_ts, ts);
433 do_pull_range_pre (GstStatsTracer * self, va_list var_args)
435 guint64 ts = va_arg (var_args, guint64);
436 GstPad *pad = va_arg (var_args, GstPad *);
437 GstPadStats *stats = get_pad_stats (self, pad);
442 do_pull_range_post (GstStatsTracer * self, va_list var_args)
444 guint64 ts = va_arg (var_args, guint64);
445 GstPad *this_pad = va_arg (var_args, GstPad *);
446 GstBuffer *buffer = va_arg (var_args, GstBuffer *);
447 GstPadStats *this_pad_stats = get_pad_stats (self, this_pad);
448 guint64 last_ts = this_pad_stats->last_ts;
449 GstPad *that_pad = GST_PAD_PEER (this_pad);
450 GstPadStats *that_pad_stats = get_pad_stats (self, that_pad);
452 if (buffer != NULL) {
453 do_buffer_stats (self, this_pad, this_pad_stats, that_pad, that_pad_stats,
456 do_element_stats (self, this_pad, last_ts, ts);
460 do_push_event_pre (GstStatsTracer * self, va_list var_args)
462 guint64 ts = va_arg (var_args, guint64);
463 GstPad *pad = va_arg (var_args, GstPad *);
464 GstElement *elem = get_real_pad_parent (pad);
465 GstPadStats *pad_stats = get_pad_stats (self, pad);
466 GstElementStats *elem_stats = get_element_stats (self, elem);
468 elem_stats->last_ts = ts;
469 log_trace (gst_structure_new ("event",
470 "ts", G_TYPE_UINT64, ts,
471 "pad-ix", G_TYPE_UINT, pad_stats->index,
472 "elem-ix", G_TYPE_UINT, elem_stats->index, NULL));
476 do_push_event_post (GstStatsTracer * self, va_list var_args)
479 guint64 ts = va_arg (var_args, guint64);
480 GstPad *pad = va_arg (var_args, GstPad *);
485 do_post_message_pre (GstStatsTracer * self, va_list var_args)
487 guint64 ts = va_arg (var_args, guint64);
488 GstElement *elem = va_arg (var_args, GstElement *);
489 GstElementStats *stats = get_element_stats (self, elem);
492 log_trace (gst_structure_new ("message",
493 "ts", G_TYPE_UINT64, ts, "elem-ix", G_TYPE_UINT, stats->index, NULL));
497 do_post_message_post (GstStatsTracer * self, va_list var_args)
500 guint64 ts = va_arg (var_args, guint64);
501 GstElement *elem = va_arg (var_args, GstElement *);
506 do_query_pre (GstStatsTracer * self, va_list var_args)
508 guint64 ts = va_arg (var_args, guint64);
509 GstElement *elem = va_arg (var_args, GstElement *);
510 GstElementStats *stats = get_element_stats (self, elem);
513 log_trace (gst_structure_new ("query",
514 "ts", G_TYPE_UINT64, ts, "elem-ix", G_TYPE_UINT, stats->index, NULL));
518 do_query_post (GstStatsTracer * self, va_list var_args)
521 guint64 ts = va_arg (var_args, guint64);
522 GstElement *elem = va_arg (var_args, GstElement *);
527 gst_stats_tracer_invoke (GstTracer * obj, GstTracerHookId hid,
528 GstTracerMessageId mid, va_list var_args)
530 GstStatsTracer *self = GST_STATS_TRACER_CAST (obj);
533 case GST_TRACER_MESSAGE_ID_PAD_PUSH_PRE:
534 do_push_buffer_pre (self, var_args);
536 case GST_TRACER_MESSAGE_ID_PAD_PUSH_POST:
537 do_push_buffer_post (self, var_args);
539 case GST_TRACER_MESSAGE_ID_PAD_PUSH_LIST_PRE:
540 do_push_buffer_list_pre (self, var_args);
542 case GST_TRACER_MESSAGE_ID_PAD_PUSH_LIST_POST:
543 do_push_buffer_list_post (self, var_args);
545 case GST_TRACER_MESSAGE_ID_PAD_PULL_RANGE_PRE:
546 do_pull_range_pre (self, var_args);
548 case GST_TRACER_MESSAGE_ID_PAD_PULL_RANGE_POST:
549 do_pull_range_post (self, var_args);
551 case GST_TRACER_MESSAGE_ID_PAD_PUSH_EVENT_PRE:
552 do_push_event_pre (self, var_args);
554 case GST_TRACER_MESSAGE_ID_PAD_PUSH_EVENT_POST:
555 do_push_event_post (self, var_args);
557 case GST_TRACER_MESSAGE_ID_ELEMENT_POST_MESSAGE_PRE:
558 do_post_message_pre (self, var_args);
560 case GST_TRACER_MESSAGE_ID_ELEMENT_POST_MESSAGE_POST:
561 do_post_message_post (self, var_args);
563 case GST_TRACER_MESSAGE_ID_ELEMENT_QUERY_PRE:
564 do_query_pre (self, var_args);
566 case GST_TRACER_MESSAGE_ID_ELEMENT_QUERY_POST:
567 do_query_post (self, var_args);
575 gst_stats_tracer_finalize (GObject * obj)
577 //GstStatsTracer *self = GST_STATS_TRACER_CAST (obj);
579 G_OBJECT_CLASS (parent_class)->finalize (obj);