2 * Copyright (C) 2013 Stefan Sauer <ensonic@users.sf.net>
4 * gst-stats.c: statistics tracing front end
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.
33 static GRegex *raw_log = NULL;
34 static GRegex *ansi_log = NULL;
36 /* global statistics */
37 static GHashTable *threads = NULL;
38 static GPtrArray *elements = NULL;
39 static GPtrArray *pads = NULL;
40 static GHashTable *latencies = NULL;
41 static GHashTable *element_latencies = NULL;
42 static GQueue *element_reported_latencies = NULL;
43 static guint64 num_buffers = 0, num_events = 0, num_messages = 0, num_queries =
45 static guint num_elements = 0, num_bins = 0, num_pads = 0, num_ghostpads = 0;
46 static GstClockTime last_ts = G_GUINT64_CONSTANT (0);
47 static guint total_cpuload = 0;
48 static gboolean have_cpuload = FALSE;
50 static GPtrArray *plugin_stats = NULL;
52 static gboolean have_latency = FALSE;
53 static gboolean have_element_latency = FALSE;
54 static gboolean have_element_reported_latency = FALSE;
58 /* display name of the element */
60 /* the number of latencies counted */
62 /* the total of all latencies */
64 /* the min of all latencies */
66 /* the max of all latencies */
68 GstClockTime first_latency_ts;
73 /* The element name */
75 /* The timestamp of the reported latency */
77 /* the min reported latency */
79 /* the max reported latency */
85 /* human readable pad name and details */
86 gchar *name, *type_name;
88 gboolean is_ghost_pad;
90 /* buffer statistics */
92 guint num_live, num_decode_only, num_discont, num_resync, num_corrupted,
93 num_marker, num_header, num_gap, num_droppable, num_delta;
94 guint min_size, max_size, avg_size;
95 /* first and last activity on the pad, expected next_ts */
96 GstClockTime first_ts, last_ts, next_ts;
97 /* in which thread does it operate */
105 /* human readable element name */
106 gchar *name, *type_name;
109 /* buffer statistics */
110 guint recv_buffers, sent_buffers;
111 guint64 recv_bytes, sent_bytes;
112 /* event, message statistics */
113 guint num_events, num_messages, num_queries;
114 /* first activity on the element */
115 GstClockTime first_ts, last_ts;
122 /* time spend in this thread */
123 GstClockTime tthread;
127 static const gchar *FACTORY_TYPES[] = {
134 #define N_FACTORY_TYPES G_N_ELEMENTS(FACTORY_TYPES)
140 GPtrArray *factories[N_FACTORY_TYPES];
146 sort_latency_stats_by_first_ts (gconstpointer a, gconstpointer b)
148 const GstLatencyStats *ls1 = a, *ls2 = b;
150 return (GST_CLOCK_DIFF (ls2->first_latency_ts, ls1->first_latency_ts));
154 print_latency_stats (gpointer value, gpointer user_data)
156 GstLatencyStats *ls = value;
158 printf ("\t%s: mean=%" GST_TIME_FORMAT " min=%" GST_TIME_FORMAT " max=%"
159 GST_TIME_FORMAT "\n", ls->name, GST_TIME_ARGS (ls->total / ls->count),
160 GST_TIME_ARGS (ls->min), GST_TIME_ARGS (ls->max));
164 reported_latencies_foreach_print_stats (GstReportedLatency * rl, gpointer data)
166 printf ("\t%s: min=%" GST_TIME_FORMAT " max=%" GST_TIME_FORMAT " ts=%"
167 GST_TIME_FORMAT "\n", rl->element, GST_TIME_ARGS (rl->min),
168 GST_TIME_ARGS (rl->max), GST_TIME_ARGS (rl->ts));
172 free_latency_stats (gpointer data)
174 GstLatencyStats *ls = data;
177 g_slice_free (GstLatencyStats, data);
181 free_reported_latency (gpointer data)
183 GstReportedLatency *rl = data;
186 g_free (rl->element);
192 free_element_stats (gpointer data)
194 g_slice_free (GstElementStats, data);
197 static inline GstElementStats *
198 get_element_stats (guint ix)
200 return (ix != G_MAXUINT && ix < elements->len) ?
201 g_ptr_array_index (elements, ix) : NULL;
204 static inline GstPadStats *
205 get_pad_stats (guint ix)
207 return (ix != G_MAXUINT && ix < pads->len) ?
208 g_ptr_array_index (pads, ix) : NULL;
212 free_pad_stats (gpointer data)
214 g_slice_free (GstPadStats, data);
217 static inline GstThreadStats *
218 get_thread_stats (gpointer id)
220 GstThreadStats *stats = g_hash_table_lookup (threads, id);
222 if (G_UNLIKELY (!stats)) {
223 stats = g_slice_new0 (GstThreadStats);
224 stats->tthread = GST_CLOCK_TIME_NONE;
225 g_hash_table_insert (threads, id, stats);
231 new_pad_stats (GstStructure * s)
236 gboolean is_ghost_pad;
240 gst_structure_get (s,
241 "ix", G_TYPE_UINT, &ix,
242 "parent-ix", G_TYPE_UINT, &parent_ix,
243 "name", G_TYPE_STRING, &name,
244 "type", G_TYPE_STRING, &type,
245 "is-ghostpad", G_TYPE_BOOLEAN, &is_ghost_pad,
246 "pad-direction", GST_TYPE_PAD_DIRECTION, &dir,
247 "thread-id", G_TYPE_UINT64, &thread_id, NULL);
249 stats = g_slice_new0 (GstPadStats);
254 stats->type_name = type;
256 stats->is_ghost_pad = is_ghost_pad;
258 stats->min_size = G_MAXUINT;
259 stats->first_ts = stats->last_ts = stats->next_ts = GST_CLOCK_TIME_NONE;
260 stats->thread_id = (gpointer) (guintptr) thread_id;
261 stats->parent_ix = parent_ix;
264 g_ptr_array_set_size (pads, ix + 1);
265 g_ptr_array_index (pads, ix) = stats;
269 new_element_stats (GstStructure * s)
271 GstElementStats *stats;
276 gst_structure_get (s,
277 "ix", G_TYPE_UINT, &ix,
278 "parent-ix", G_TYPE_UINT, &parent_ix,
279 "name", G_TYPE_STRING, &name,
280 "type", G_TYPE_STRING, &type, "is-bin", G_TYPE_BOOLEAN, &is_bin, NULL);
282 stats = g_slice_new0 (GstElementStats);
288 stats->type_name = type;
289 stats->is_bin = is_bin;
290 stats->first_ts = GST_CLOCK_TIME_NONE;
291 stats->parent_ix = parent_ix;
293 if (elements->len <= ix)
294 g_ptr_array_set_size (elements, ix + 1);
295 g_ptr_array_index (elements, ix) = stats;
299 free_thread_stats (gpointer data)
301 g_slice_free (GstThreadStats, data);
304 static GstPluginStats *
305 new_plugin_stats (const gchar * plugin_name)
307 GstPluginStats *plugin = g_slice_new (GstPluginStats);
310 plugin->name = g_strdup (plugin_name);
312 for (i = 0; i < N_FACTORY_TYPES; i++)
313 plugin->factories[i] = g_ptr_array_new_with_free_func (g_free);
315 g_ptr_array_add (plugin_stats, plugin);
321 free_plugin_stats (gpointer data)
323 GstPluginStats *plugin = data;
326 g_free (plugin->name);
328 for (i = 0; i < N_FACTORY_TYPES; i++)
329 g_ptr_array_unref (plugin->factories[i]);
331 g_slice_free (GstPluginStats, data);
335 do_pad_stats (GstPadStats * stats, guint elem_ix, guint size, guint64 ts,
336 guint64 buffer_ts, guint64 buffer_dur, GstBufferFlags buffer_flags)
341 if (stats->parent_ix == G_MAXUINT) {
342 stats->parent_ix = elem_ix;
345 if (stats->thread_id) {
346 get_thread_stats (stats->thread_id);
350 avg_size = (((gulong) stats->avg_size * (gulong) stats->num_buffers) + size);
351 stats->num_buffers++;
352 stats->avg_size = (guint) (avg_size / stats->num_buffers);
353 if (size < stats->min_size)
354 stats->min_size = size;
355 else if (size > stats->max_size)
356 stats->max_size = size;
358 if (!GST_CLOCK_TIME_IS_VALID (stats->last_ts))
359 stats->first_ts = ts;
362 if (buffer_flags & GST_BUFFER_FLAG_LIVE)
364 if (buffer_flags & GST_BUFFER_FLAG_DECODE_ONLY)
365 stats->num_decode_only++;
366 if (buffer_flags & GST_BUFFER_FLAG_DISCONT)
367 stats->num_discont++;
368 if (buffer_flags & GST_BUFFER_FLAG_RESYNC)
370 if (buffer_flags & GST_BUFFER_FLAG_CORRUPTED)
371 stats->num_corrupted++;
372 if (buffer_flags & GST_BUFFER_FLAG_MARKER)
374 if (buffer_flags & GST_BUFFER_FLAG_HEADER)
376 if (buffer_flags & GST_BUFFER_FLAG_GAP)
378 if (buffer_flags & GST_BUFFER_FLAG_DROPPABLE)
379 stats->num_droppable++;
380 if (buffer_flags & GST_BUFFER_FLAG_DELTA_UNIT)
382 /* update timestamps */
383 if (GST_CLOCK_TIME_IS_VALID (buffer_ts) &&
384 GST_CLOCK_TIME_IS_VALID (buffer_dur)) {
385 stats->next_ts = buffer_ts + buffer_dur;
387 stats->next_ts = GST_CLOCK_TIME_NONE;
392 do_element_stats (GstElementStats * stats, GstElementStats * peer_stats,
393 guint size, guint64 ts)
395 stats->sent_buffers++;
396 peer_stats->recv_buffers++;
397 stats->sent_bytes += size;
398 peer_stats->recv_bytes += size;
400 if (G_UNLIKELY (!GST_CLOCK_TIME_IS_VALID (stats->first_ts))) {
401 stats->first_ts = ts;
403 if (G_UNLIKELY (!GST_CLOCK_TIME_IS_VALID (peer_stats->first_ts))) {
404 peer_stats->first_ts = ts + 1;
409 do_buffer_stats (GstStructure * s)
412 guint64 buffer_pts = GST_CLOCK_TIME_NONE, buffer_dur = GST_CLOCK_TIME_NONE;
413 guint pad_ix, elem_ix, peer_elem_ix;
415 GstBufferFlags buffer_flags;
416 GstPadStats *pad_stats;
417 GstElementStats *elem_stats, *peer_elem_stats;
420 gst_structure_get (s, "ts", G_TYPE_UINT64, &ts,
421 "pad-ix", G_TYPE_UINT, &pad_ix,
422 "element-ix", G_TYPE_UINT, &elem_ix,
423 "peer-element-ix", G_TYPE_UINT, &peer_elem_ix,
424 "buffer-size", G_TYPE_UINT, &size,
425 "buffer-flags", GST_TYPE_BUFFER_FLAGS, &buffer_flags, NULL);
426 gst_structure_get_uint64 (s, "buffer-pts", &buffer_pts);
427 gst_structure_get_uint64 (s, "buffer-duration", &buffer_dur);
428 last_ts = MAX (last_ts, ts);
429 if (!(pad_stats = get_pad_stats (pad_ix))) {
430 GST_WARNING ("no pad stats found for ix=%u", pad_ix);
433 if (!(elem_stats = get_element_stats (elem_ix))) {
434 GST_WARNING ("no element stats found for ix=%u", elem_ix);
437 if (!(peer_elem_stats = get_element_stats (peer_elem_ix))) {
438 GST_WARNING ("no element stats found for ix=%u", peer_elem_ix);
441 do_pad_stats (pad_stats, elem_ix, size, ts, buffer_pts, buffer_dur,
443 if (pad_stats->dir == GST_PAD_SRC) {
445 do_element_stats (elem_stats, peer_elem_stats, size, ts);
448 do_element_stats (peer_elem_stats, elem_stats, size, ts);
453 do_event_stats (GstStructure * s)
456 guint pad_ix, elem_ix;
457 GstPadStats *pad_stats;
458 GstElementStats *elem_stats;
461 gst_structure_get (s, "ts", G_TYPE_UINT64, &ts,
462 "pad-ix", G_TYPE_UINT, &pad_ix, "element-ix", G_TYPE_UINT, &elem_ix,
464 last_ts = MAX (last_ts, ts);
465 if (!(pad_stats = get_pad_stats (pad_ix))) {
466 GST_WARNING ("no pad stats found for ix=%u", pad_ix);
469 if (!(elem_stats = get_element_stats (elem_ix))) {
470 // e.g. reconfigure events are send over unparented pads
471 GST_INFO ("no element stats found for ix=%u", elem_ix);
474 elem_stats->num_events++;
478 do_message_stats (GstStructure * s)
482 GstElementStats *elem_stats;
485 gst_structure_get (s, "ts", G_TYPE_UINT64, &ts,
486 "element-ix", G_TYPE_UINT, &elem_ix, NULL);
487 last_ts = MAX (last_ts, ts);
488 if (!(elem_stats = get_element_stats (elem_ix))) {
489 GST_WARNING ("no element stats found for ix=%u", elem_ix);
492 elem_stats->num_messages++;
496 do_query_stats (GstStructure * s)
500 GstElementStats *elem_stats;
503 gst_structure_get (s, "ts", G_TYPE_UINT64, &ts,
504 "element-ix", G_TYPE_UINT, &elem_ix, NULL);
505 last_ts = MAX (last_ts, ts);
506 if (!(elem_stats = get_element_stats (elem_ix))) {
507 GST_WARNING ("no element stats found for ix=%u", elem_ix);
510 elem_stats->num_queries++;
514 do_thread_rusage_stats (GstStructure * s)
516 guint64 ts, tthread, thread_id;
518 GstThreadStats *thread_stats;
520 gst_structure_get (s, "ts", G_TYPE_UINT64, &ts,
521 "thread-id", G_TYPE_UINT64, &thread_id,
522 "average-cpuload", G_TYPE_UINT, &cpuload, "time", G_TYPE_UINT64, &tthread,
524 thread_stats = get_thread_stats ((gpointer) (guintptr) thread_id);
525 thread_stats->cpuload = cpuload;
526 thread_stats->tthread = tthread;
527 last_ts = MAX (last_ts, ts);
531 do_proc_rusage_stats (GstStructure * s)
535 gst_structure_get (s, "ts", G_TYPE_UINT64, &ts,
536 "average-cpuload", G_TYPE_UINT, &total_cpuload, NULL);
537 last_ts = MAX (last_ts, ts);
542 update_latency_table (GHashTable * table, const gchar * key, guint64 time,
545 /* Find the values in the hash table */
546 GstLatencyStats *ls = g_hash_table_lookup (table, key);
548 /* Insert the new key if the value does not exist */
549 ls = g_new0 (GstLatencyStats, 1);
550 ls->name = g_strdup (key);
555 ls->first_latency_ts = ts;
556 g_hash_table_insert (table, g_strdup (key), ls);
558 /* Otherwise update the existing value */
569 do_latency_stats (GstStructure * s)
572 const gchar *src = NULL, *sink = NULL, *src_element = NULL,
573 *sink_element = NULL, *src_element_id = NULL, *sink_element_id = NULL;
574 guint64 ts = 0, time = 0;
576 /* Get the values from the structure */
577 src = gst_structure_get_string (s, "src");
578 sink = gst_structure_get_string (s, "sink");
579 src_element = gst_structure_get_string (s, "src-element");
580 sink_element = gst_structure_get_string (s, "sink-element");
581 src_element_id = gst_structure_get_string (s, "src-element-id");
582 sink_element_id = gst_structure_get_string (s, "sink-element-id");
583 gst_structure_get (s, "time", G_TYPE_UINT64, &time, NULL);
584 gst_structure_get (s, "ts", G_TYPE_UINT64, &ts, NULL);
587 last_ts = MAX (last_ts, ts);
590 key = g_strdup_printf ("%s.%s.%s|%s.%s.%s", src_element_id, src_element,
591 src, sink_element_id, sink_element, sink);
593 /* Update the latency in the table */
594 update_latency_table (latencies, key, time, ts);
603 do_element_latency_stats (GstStructure * s)
606 const gchar *src = NULL, *element = NULL, *element_id = NULL;
607 guint64 ts = 0, time = 0;
609 /* Get the values from the structure */
610 src = gst_structure_get_string (s, "src");
611 element = gst_structure_get_string (s, "element");
612 element_id = gst_structure_get_string (s, "element-id");
613 gst_structure_get (s, "time", G_TYPE_UINT64, &time, NULL);
614 gst_structure_get (s, "ts", G_TYPE_UINT64, &ts, NULL);
617 last_ts = MAX (last_ts, ts);
620 key = g_strdup_printf ("%s.%s.%s", element_id, element, src);
622 /* Update the latency in the table */
623 update_latency_table (element_latencies, key, time, ts);
628 have_element_latency = TRUE;
632 do_element_reported_latency (GstStructure * s)
634 const gchar *element = NULL, *element_id = NULL;
635 guint64 ts = 0, min = 0, max = 0;
636 GstReportedLatency *rl = NULL;
638 /* Get the values from the structure */
639 element_id = gst_structure_get_string (s, "element-id");
640 element = gst_structure_get_string (s, "element");
641 gst_structure_get (s, "min", G_TYPE_UINT64, &min, NULL);
642 gst_structure_get (s, "max", G_TYPE_UINT64, &max, NULL);
643 gst_structure_get (s, "ts", G_TYPE_UINT64, &ts, NULL);
646 last_ts = MAX (last_ts, ts);
648 /* Insert/Update the key in the table */
649 rl = g_new0 (GstReportedLatency, 1);
650 rl->element = g_strdup_printf ("%s.%s", element_id, element);
654 g_queue_push_tail (element_reported_latencies, rl);
656 have_element_reported_latency = TRUE;
660 do_factory_used (GstStructure * s)
662 const gchar *factory = NULL;
663 const gchar *factory_type = NULL;
664 const gchar *plugin_name = NULL;
665 GstPluginStats *plugin = NULL;
668 factory = gst_structure_get_string (s, "factory");
669 factory_type = gst_structure_get_string (s, "factory-type");
670 plugin_name = gst_structure_get_string (s, "plugin");
672 if (!g_strcmp0 (plugin_name, "staticelements"))
675 if (plugin_name == NULL || plugin_name[0] == 0)
676 plugin_name = "built-in";
678 for (f = 0; f < N_FACTORY_TYPES; f++)
679 if (!g_strcmp0 (factory_type, FACTORY_TYPES[f]))
681 if (f == N_FACTORY_TYPES)
684 for (i = 0; i < plugin_stats->len; i++) {
685 GstPluginStats *tmp_plugin = g_ptr_array_index (plugin_stats, i);
686 if (!strcmp (tmp_plugin->name, plugin_name)) {
693 plugin = new_plugin_stats (plugin_name);
695 if (factory && factory[0] &&
696 !g_ptr_array_find_with_equal_func (plugin->factories[f], factory,
698 g_ptr_array_add (plugin->factories[f], g_strdup (factory));
704 find_pad_stats_for_thread (gconstpointer value, gconstpointer user_data)
706 const GstPadStats *stats = (const GstPadStats *) value;
708 if ((stats->thread_id == user_data) && (stats->num_buffers)) {
715 print_pad_stats (gpointer value, gpointer user_data)
717 GstPadStats *stats = (GstPadStats *) value;
719 if (stats->thread_id == user_data) {
720 /* there seem to be some temporary pads */
721 if (stats->num_buffers) {
722 GstClockTimeDiff running =
723 GST_CLOCK_DIFF (stats->first_ts, stats->last_ts);
724 GstElementStats *elem_stats = get_element_stats (stats->parent_ix);
725 gchar fullname[30 + 1];
727 g_snprintf (fullname, 30, "%s.%s", elem_stats->name, stats->name);
730 (" %c %-30.30s: buffers %7u (live %5u,dec %5u,dis %5u,res %5u,"
731 "cor %5u,mar %5u,hdr %5u,gap %5u,drop %5u,dlt %5u),",
732 (stats->dir == GST_PAD_SRC) ? '>' : '<', fullname, stats->num_buffers,
733 stats->num_live, stats->num_decode_only, stats->num_discont,
734 stats->num_resync, stats->num_corrupted, stats->num_marker,
735 stats->num_header, stats->num_gap, stats->num_droppable,
737 if (stats->min_size == stats->max_size) {
738 printf (" size (min/avg/max) ......./%7u/.......,", stats->avg_size);
740 printf (" size (min/avg/max) %7u/%7u/%7u,",
741 stats->min_size, stats->avg_size, stats->max_size);
743 printf (" time %" GST_TIME_FORMAT ","
745 GST_TIME_ARGS (running),
746 ((gdouble) (stats->num_buffers * stats->avg_size) * GST_SECOND) /
747 ((gdouble) running));
753 print_thread_stats (gpointer key, gpointer value, gpointer user_data)
755 GSList *list = user_data;
756 GSList *node = g_slist_find_custom (list, key, find_pad_stats_for_thread);
757 GstThreadStats *stats = (GstThreadStats *) value;
759 /* skip stats if there are no pads for that thread (e.g. a pipeline) */
763 printf ("Thread %p Statistics:\n", key);
764 if (GST_CLOCK_TIME_IS_VALID (stats->tthread)) {
765 printf (" Time: %" GST_TIME_FORMAT "\n", GST_TIME_ARGS (stats->tthread));
766 printf (" Avg CPU load: %4.1f %%\n", (gfloat) stats->cpuload / 10.0);
769 puts (" Pad Statistics:");
770 g_slist_foreach (node, print_pad_stats, key);
774 print_element_stats (gpointer value, gpointer user_data)
776 GstElementStats *stats = (GstElementStats *) value;
778 /* skip temporary elements */
779 if (stats->first_ts != GST_CLOCK_TIME_NONE) {
780 gchar fullname[45 + 1];
782 g_snprintf (fullname, 45, "%s:%s", stats->type_name, stats->name);
784 printf (" %-45s:", fullname);
785 if (stats->recv_buffers)
786 g_print (" buffers in/out %7u", stats->recv_buffers);
788 g_print (" buffers in/out %7s", "-");
789 if (stats->sent_buffers)
790 g_print ("/%7u", stats->sent_buffers);
792 g_print ("/%7s", "-");
793 if (stats->recv_bytes)
794 g_print (" bytes in/out %12" G_GUINT64_FORMAT, stats->recv_bytes);
796 g_print (" bytes in/out %12s", "-");
797 if (stats->sent_bytes)
798 g_print ("/%12" G_GUINT64_FORMAT, stats->sent_bytes);
800 printf ("/%12s", "-");
801 g_print (" first activity %" GST_TIME_FORMAT ", "
802 " ev/msg/qry sent %5u/%5u/%5u\n", GST_TIME_ARGS (stats->first_ts),
803 stats->num_events, stats->num_messages, stats->num_queries);
808 accum_element_stats (gpointer value, gpointer user_data)
810 GstElementStats *stats = (GstElementStats *) value;
812 if (stats->parent_ix != G_MAXUINT) {
813 GstElementStats *parent_stats = get_element_stats (stats->parent_ix);
815 parent_stats->num_events += stats->num_events;
816 parent_stats->num_messages += stats->num_messages;
817 parent_stats->num_queries += stats->num_queries;
818 if (!GST_CLOCK_TIME_IS_VALID (parent_stats->first_ts)) {
819 parent_stats->first_ts = stats->first_ts;
820 } else if (GST_CLOCK_TIME_IS_VALID (stats->first_ts)) {
821 parent_stats->first_ts = MIN (parent_stats->first_ts, stats->first_ts);
823 if (!GST_CLOCK_TIME_IS_VALID (parent_stats->last_ts)) {
824 parent_stats->last_ts = stats->last_ts;
825 } else if (GST_CLOCK_TIME_IS_VALID (stats->last_ts)) {
826 parent_stats->last_ts = MAX (parent_stats->last_ts, stats->last_ts);
834 sort_pad_stats_by_first_activity (gconstpointer ps1, gconstpointer ps2)
836 GstPadStats *s1 = (GstPadStats *) ps1;
837 GstPadStats *s2 = (GstPadStats *) ps2;
839 gint order = GST_CLOCK_DIFF (s2->first_ts, s1->first_ts);
842 order = s1->dir - s2->dir;
848 sort_pad_stats (gpointer value, gpointer user_data)
850 GSList **list = user_data;
853 g_slist_insert_sorted (*list, value, sort_pad_stats_by_first_activity);
857 sort_element_stats_by_first_activity (gconstpointer es1, gconstpointer es2)
859 return (GST_CLOCK_DIFF (((GstElementStats *) es2)->first_ts,
860 ((GstElementStats *) es1)->first_ts));
864 sort_bin_stats (gpointer value, gpointer user_data)
866 if (value != NULL && ((GstElementStats *) value)->is_bin) {
867 GSList **list = user_data;
870 g_slist_insert_sorted (*list, value,
871 sort_element_stats_by_first_activity);
876 sort_element_stats (gpointer value, gpointer user_data)
878 if (value != NULL && !(((GstElementStats *) value)->is_bin)) {
879 GSList **list = user_data;
882 g_slist_insert_sorted (*list, value,
883 sort_element_stats_by_first_activity);
888 check_bin_parent (gpointer key, gpointer value, gpointer user_data)
890 GstElementStats *stats = (GstElementStats *) value;
892 return (stats->parent_ix == GPOINTER_TO_UINT (user_data));
896 process_leaf_bins (gpointer key, gpointer value, gpointer user_data)
898 GHashTable *accum_bins = user_data;
900 /* if we find no bin that has this bin as a parent ... */
901 if (!g_hash_table_find (accum_bins, check_bin_parent, key)) {
902 /* accumulate stats to the parent and remove */
903 accum_element_stats (value, NULL);
914 /* compile the parser regexps */
915 /* 0:00:00.004925027 31586 0x1c5c600 DEBUG GST_REGISTRY gstregistry.c:463:gst_registry_add_plugin:<registry0> adding plugin 0x1c79160 for filename "/usr/lib/gstreamer-1.0/libgstxxx.so"
916 * 0:00:02.719599000 35292 000001C031A49C60 DEBUG GST_TRACER gsttracer.c:162:gst_tracer_register:<registry0> update existing feature 000001C02F9843C0 (latency)
918 raw_log = g_regex_new (
924 "(0?x?[0-9a-fA-F]+) +"
929 /* 6: file:line:func: */
930 "([^:]*:[0-9]+:[^:]*:) +"
931 /* 7: (obj)? log-text */
932 "(.*)$", 0, 0, NULL);
934 GST_WARNING ("failed to compile the 'raw' parser");
938 ansi_log = g_regex_new (
942 "\\\x1b\\[[0-9;]+m *([0-9]+)\\\x1b\\[00m +"
946 "(?:\\\x1b\\[[0-9;]+m)?([A-Z]+) +\\\x1b\\[00m +"
948 "\\\x1b\\[[0-9;]+m +([a-zA-Z_-]+) +"
949 /* 6: file:line:func: */
950 "([^:]*:[0-9]+:[^:]*:)(?:\\\x1b\\[00m)? +"
951 /* 7: (obj)? log-text */
952 "(.*)$", 0, 0, NULL);
954 GST_WARNING ("failed to compile the 'ansi' parser");
958 elements = g_ptr_array_new_with_free_func (free_element_stats);
959 pads = g_ptr_array_new_with_free_func (free_pad_stats);
960 threads = g_hash_table_new_full (NULL, NULL, NULL, free_thread_stats);
961 latencies = g_hash_table_new_full (g_str_hash, g_str_equal, g_free,
963 element_latencies = g_hash_table_new_full (g_str_hash, g_str_equal, g_free,
965 element_reported_latencies = g_queue_new ();
967 plugin_stats = g_ptr_array_new_with_free_func (free_plugin_stats);
976 g_ptr_array_free (pads, TRUE);
978 g_ptr_array_free (elements, TRUE);
980 g_hash_table_destroy (threads);
983 g_hash_table_remove_all (latencies);
984 g_hash_table_destroy (latencies);
987 if (element_latencies) {
988 g_hash_table_remove_all (element_latencies);
989 g_hash_table_destroy (element_latencies);
990 element_latencies = NULL;
992 if (element_reported_latencies) {
993 g_queue_free_full (element_reported_latencies, free_reported_latency);
994 element_reported_latencies = NULL;
997 g_clear_pointer (&plugin_stats, g_ptr_array_unref);
1000 g_regex_unref (raw_log);
1002 g_regex_unref (ansi_log);
1006 compare_plugin_stats (gconstpointer a, gconstpointer b)
1008 const GstPluginStats *plugin_a = *(GstPluginStats **) a;
1009 const GstPluginStats *plugin_b = *(GstPluginStats **) b;
1011 return strcmp (plugin_a->name, plugin_b->name);
1015 compare_string (gconstpointer a, gconstpointer b)
1017 const char *str_a = *(const char **) a;
1018 const char *str_b = *(const char **) b;
1020 return strcmp (str_a, str_b);
1026 guint num_threads = g_hash_table_size (threads);
1028 /* print overall stats */
1029 g_print ("\nOverall Statistics:\n");
1030 g_print ("Number of Threads: %u\n", num_threads);
1031 g_print ("Number of Elements: %u\n", num_elements - num_bins);
1032 g_print ("Number of Bins: %u\n", num_bins);
1033 g_print ("Number of Pads: %u\n", num_pads - num_ghostpads);
1034 g_print ("Number of GhostPads: %u\n", num_ghostpads);
1035 g_print ("Number of Buffers passed: %" G_GUINT64_FORMAT "\n", num_buffers);
1036 g_print ("Number of Events sent: %" G_GUINT64_FORMAT "\n", num_events);
1037 g_print ("Number of Message sent: %" G_GUINT64_FORMAT "\n", num_messages);
1038 g_print ("Number of Queries sent: %" G_GUINT64_FORMAT "\n", num_queries);
1039 g_print ("Time: %" GST_TIME_FORMAT "\n", GST_TIME_ARGS (last_ts));
1041 g_print ("Avg CPU load: %4.1f %%\n", (gfloat) total_cpuload / 10.0);
1047 GSList *list = NULL;
1049 g_ptr_array_foreach (pads, sort_pad_stats, &list);
1050 g_hash_table_foreach (threads, print_thread_stats, list);
1052 g_slist_free (list);
1057 GSList *list = NULL;
1059 puts ("Element Statistics:");
1060 /* sort by first_activity */
1061 g_ptr_array_foreach (elements, sort_element_stats, &list);
1062 /* attribute element stats to bins */
1063 g_slist_foreach (list, accum_element_stats, NULL);
1064 g_slist_foreach (list, print_element_stats, NULL);
1066 g_slist_free (list);
1071 GSList *list = NULL;
1073 GHashTable *accum_bins = g_hash_table_new_full (NULL, NULL, NULL, NULL);
1075 puts ("Bin Statistics:");
1076 /* attribute bin stats to parent-bins */
1077 for (i = 0; i < num_elements; i++) {
1078 GstElementStats *stats = g_ptr_array_index (elements, i);
1079 if (stats != NULL && stats->is_bin) {
1080 g_hash_table_insert (accum_bins, GUINT_TO_POINTER (i), stats);
1083 while (g_hash_table_size (accum_bins)) {
1084 g_hash_table_foreach_remove (accum_bins, process_leaf_bins, accum_bins);
1086 g_hash_table_destroy (accum_bins);
1087 /* sort by first_activity */
1088 g_ptr_array_foreach (elements, sort_bin_stats, &list);
1089 g_slist_foreach (list, print_element_stats, NULL);
1091 g_slist_free (list);
1098 puts ("Latency Statistics:");
1099 list = g_hash_table_get_values (latencies);
1100 /* Sort by first activity */
1101 list = g_list_sort (list, sort_latency_stats_by_first_ts);
1102 g_list_foreach (list, print_latency_stats, NULL);
1107 /* element latency stats */
1108 if (have_element_latency) {
1111 puts ("Element Latency Statistics:");
1112 list = g_hash_table_get_values (element_latencies);
1113 /* Sort by first activity */
1114 list = g_list_sort (list, sort_latency_stats_by_first_ts);
1115 g_list_foreach (list, print_latency_stats, NULL);
1120 /* element reported latency stats */
1121 if (have_element_reported_latency) {
1122 puts ("Element Reported Latency:");
1123 g_queue_foreach (element_reported_latencies,
1124 (GFunc) reported_latencies_foreach_print_stats, NULL);
1128 if (plugin_stats->len > 0) {
1131 g_ptr_array_sort (plugin_stats, compare_plugin_stats);
1133 printf ("Plugins used: ");
1134 for (i = 0; i < plugin_stats->len; i++) {
1135 GstPluginStats *ps = g_ptr_array_index (plugin_stats, i);
1136 printf ("%s%s", i == 0 ? "" : ";", ps->name);
1140 for (f = 0; f < N_FACTORY_TYPES; f++) {
1141 gboolean first = TRUE;
1143 printf ("%c%ss: ", g_ascii_toupper (FACTORY_TYPES[f][0]),
1144 FACTORY_TYPES[f] + 1);
1145 for (i = 0; i < plugin_stats->len; i++) {
1146 GstPluginStats *ps = g_ptr_array_index (plugin_stats, i);
1148 if (ps->factories[f]->len > 0) {
1149 printf ("%s%s:", first ? "" : ";", ps->name);
1152 g_ptr_array_sort (ps->factories[f], compare_string);
1154 for (j = 0; j < ps->factories[f]->len; j++) {
1155 const gchar *factory = g_ptr_array_index (ps->factories[f], j);
1157 printf ("%s%s", j == 0 ? "" : ",", factory);
1167 collect_stats (const gchar * filename)
1171 if ((log = fopen (filename, "rt"))) {
1175 if (fgets (line, 5000, log)) {
1176 GMatchInfo *match_info;
1180 gchar *level, *data;
1182 if (strchr (line, 27)) {
1184 GST_INFO ("format is 'ansi'");
1187 GST_INFO ("format is 'raw'");
1192 while (!feof (log)) {
1193 if (fgets (line, 5000, log)) {
1194 if (g_regex_match (parser, line, 0, &match_info)) {
1195 /* filter by level */
1196 level = g_match_info_fetch (match_info, 4);
1197 if (!strcmp (level, "TRACE")) {
1198 data = g_match_info_fetch (match_info, 7);
1199 if ((s = gst_structure_from_string (data, NULL))) {
1200 const gchar *name = gst_structure_get_name (s);
1202 if (!strcmp (name, "new-pad")) {
1204 } else if (!strcmp (name, "new-element")) {
1205 new_element_stats (s);
1206 } else if (!strcmp (name, "buffer")) {
1207 do_buffer_stats (s);
1208 } else if (!strcmp (name, "event")) {
1210 } else if (!strcmp (name, "message")) {
1211 do_message_stats (s);
1212 } else if (!strcmp (name, "query")) {
1214 } else if (!strcmp (name, "thread-rusage")) {
1215 do_thread_rusage_stats (s);
1216 } else if (!strcmp (name, "proc-rusage")) {
1217 do_proc_rusage_stats (s);
1218 } else if (!strcmp (name, "latency")) {
1219 do_latency_stats (s);
1220 } else if (!strcmp (name, "element-latency")) {
1221 do_element_latency_stats (s);
1222 } else if (!strcmp (name, "element-reported-latency")) {
1223 do_element_reported_latency (s);
1224 } else if (!strcmp (name, "factory-used")) {
1225 do_factory_used (s);
1227 // TODO(ensonic): parse the xxx.class log lines
1228 if (!g_str_has_suffix (data, ".class")) {
1229 GST_WARNING ("unknown log entry: '%s'", data);
1232 gst_structure_free (s);
1234 GST_WARNING ("unknown log entry: '%s'", data);
1241 GST_WARNING ("foreign log entry: %s:%d:'%s'", filename, lnr,
1245 g_match_info_free (match_info);
1250 // TODO(ensonic): run wc -L on the log file
1251 fprintf (stderr, "line too long");
1256 GST_WARNING ("empty log");
1263 main (gint argc, gchar * argv[])
1265 gchar **filenames = NULL;
1268 GOptionContext *ctx;
1269 GOptionEntry options[] = {
1270 GST_TOOLS_GOPTION_VERSION,
1271 // TODO(ensonic): add a summary flag, if set read the whole thing, print
1272 // stats once, and exit
1273 {G_OPTION_REMAINING, 0, 0, G_OPTION_ARG_FILENAME_ARRAY, &filenames, NULL}
1279 bindtextdomain (GETTEXT_PACKAGE, LOCALEDIR);
1280 bind_textdomain_codeset (GETTEXT_PACKAGE, "UTF-8");
1281 textdomain (GETTEXT_PACKAGE);
1284 g_set_prgname ("gst-stats-" GST_API_VERSION);
1286 ctx = g_option_context_new ("FILE");
1287 g_option_context_add_main_entries (ctx, options, GETTEXT_PACKAGE);
1288 g_option_context_add_group (ctx, gst_init_get_option_group ());
1289 if (!g_option_context_parse (ctx, &argc, &argv, &err)) {
1290 g_print ("Error initializing: %s\n", GST_STR_NULL (err->message));
1293 g_option_context_free (ctx);
1295 gst_tools_print_version ();
1297 if (filenames == NULL || *filenames == NULL) {
1298 g_print ("Please give one filename to %s\n\n", g_get_prgname ());
1301 num = g_strv_length (filenames);
1302 if (num == 0 || num > 1) {
1303 g_print ("Please give exactly one filename to %s (%d given).\n\n",
1304 g_get_prgname (), num);
1309 collect_stats (filenames[0]);
1314 g_strfreev (filenames);