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 gboolean have_latency = FALSE;
51 static gboolean have_element_latency = FALSE;
52 static gboolean have_element_reported_latency = FALSE;
56 /* the number of latencies counted */
58 /* the total of all latencies */
60 /* the min of all latencies */
62 /* the max of all latencies */
68 /* The element name */
70 /* The timestamp of the reported latency */
72 /* the min reported latency */
74 /* the max reported latency */
80 /* human readable pad name and details */
81 gchar *name, *type_name;
83 gboolean is_ghost_pad;
85 /* buffer statistics */
87 guint num_live, num_decode_only, num_discont, num_resync, num_corrupted,
88 num_marker, num_header, num_gap, num_droppable, num_delta;
89 guint min_size, max_size, avg_size;
90 /* first and last activity on the pad, expected next_ts */
91 GstClockTime first_ts, last_ts, next_ts;
92 /* in which thread does it operate */
100 /* human readable element name */
101 gchar *name, *type_name;
104 /* buffer statistics */
105 guint recv_buffers, sent_buffers;
106 guint64 recv_bytes, sent_bytes;
107 /* event, message statistics */
108 guint num_events, num_messages, num_queries;
109 /* first activity on the element */
110 GstClockTime first_ts, last_ts;
117 /* time spend in this thread */
118 GstClockTime tthread;
125 latencies_foreach_print_stats (gchar * key, GstLatencyStats * ls, gpointer data)
127 printf ("\t%s: mean=%" G_GUINT64_FORMAT " min=%" G_GUINT64_FORMAT " max=%"
128 G_GUINT64_FORMAT "\n", key, ls->total / ls->count, ls->min, ls->max);
132 reported_latencies_foreach_print_stats (GstReportedLatency * rl, gpointer data)
134 printf ("\t%s: min=%" G_GUINT64_FORMAT " max=%" G_GUINT64_FORMAT " ts=%"
135 GST_TIME_FORMAT "\n", rl->element, rl->min,
136 rl->max, GST_TIME_ARGS (rl->ts));
140 free_latency_stats (gpointer data)
142 g_slice_free (GstLatencyStats, data);
146 free_reported_latency (gpointer data)
148 GstReportedLatency *rl = data;
151 g_free (rl->element);
157 free_element_stats (gpointer data)
159 g_slice_free (GstElementStats, data);
162 static inline GstElementStats *
163 get_element_stats (guint ix)
165 return (ix != G_MAXUINT && ix < elements->len) ?
166 g_ptr_array_index (elements, ix) : NULL;
169 static inline GstPadStats *
170 get_pad_stats (guint ix)
172 return (ix != G_MAXUINT && ix < pads->len) ?
173 g_ptr_array_index (pads, ix) : NULL;
177 free_pad_stats (gpointer data)
179 g_slice_free (GstPadStats, data);
182 static inline GstThreadStats *
183 get_thread_stats (gpointer id)
185 GstThreadStats *stats = g_hash_table_lookup (threads, id);
187 if (G_UNLIKELY (!stats)) {
188 stats = g_slice_new0 (GstThreadStats);
189 stats->tthread = GST_CLOCK_TIME_NONE;
190 g_hash_table_insert (threads, id, stats);
196 new_pad_stats (GstStructure * s)
201 gboolean is_ghost_pad;
205 gst_structure_get (s,
206 "ix", G_TYPE_UINT, &ix,
207 "parent-ix", G_TYPE_UINT, &parent_ix,
208 "name", G_TYPE_STRING, &name,
209 "type", G_TYPE_STRING, &type,
210 "is-ghostpad", G_TYPE_BOOLEAN, &is_ghost_pad,
211 "pad-direction", GST_TYPE_PAD_DIRECTION, &dir,
212 "thread-id", G_TYPE_UINT64, &thread_id, NULL);
214 stats = g_slice_new0 (GstPadStats);
219 stats->type_name = type;
221 stats->is_ghost_pad = is_ghost_pad;
223 stats->min_size = G_MAXUINT;
224 stats->first_ts = stats->last_ts = stats->next_ts = GST_CLOCK_TIME_NONE;
225 stats->thread_id = (gpointer) (guintptr) thread_id;
226 stats->parent_ix = parent_ix;
229 g_ptr_array_set_size (pads, ix + 1);
230 g_ptr_array_index (pads, ix) = stats;
234 new_element_stats (GstStructure * s)
236 GstElementStats *stats;
241 gst_structure_get (s,
242 "ix", G_TYPE_UINT, &ix,
243 "parent-ix", G_TYPE_UINT, &parent_ix,
244 "name", G_TYPE_STRING, &name,
245 "type", G_TYPE_STRING, &type, "is-bin", G_TYPE_BOOLEAN, &is_bin, NULL);
247 stats = g_slice_new0 (GstElementStats);
253 stats->type_name = type;
254 stats->is_bin = is_bin;
255 stats->first_ts = GST_CLOCK_TIME_NONE;
256 stats->parent_ix = parent_ix;
258 if (elements->len <= ix)
259 g_ptr_array_set_size (elements, ix + 1);
260 g_ptr_array_index (elements, ix) = stats;
264 free_thread_stats (gpointer data)
266 g_slice_free (GstThreadStats, data);
270 do_pad_stats (GstPadStats * stats, guint elem_ix, guint size, guint64 ts,
271 guint64 buffer_ts, guint64 buffer_dur, GstBufferFlags buffer_flags)
276 if (stats->parent_ix == G_MAXUINT) {
277 stats->parent_ix = elem_ix;
280 if (stats->thread_id) {
281 get_thread_stats (stats->thread_id);
285 avg_size = (((gulong) stats->avg_size * (gulong) stats->num_buffers) + size);
286 stats->num_buffers++;
287 stats->avg_size = (guint) (avg_size / stats->num_buffers);
288 if (size < stats->min_size)
289 stats->min_size = size;
290 else if (size > stats->max_size)
291 stats->max_size = size;
293 if (!GST_CLOCK_TIME_IS_VALID (stats->last_ts))
294 stats->first_ts = ts;
297 if (buffer_flags & GST_BUFFER_FLAG_LIVE)
299 if (buffer_flags & GST_BUFFER_FLAG_DECODE_ONLY)
300 stats->num_decode_only++;
301 if (buffer_flags & GST_BUFFER_FLAG_DISCONT)
302 stats->num_discont++;
303 if (buffer_flags & GST_BUFFER_FLAG_RESYNC)
305 if (buffer_flags & GST_BUFFER_FLAG_CORRUPTED)
306 stats->num_corrupted++;
307 if (buffer_flags & GST_BUFFER_FLAG_MARKER)
309 if (buffer_flags & GST_BUFFER_FLAG_HEADER)
311 if (buffer_flags & GST_BUFFER_FLAG_GAP)
313 if (buffer_flags & GST_BUFFER_FLAG_DROPPABLE)
314 stats->num_droppable++;
315 if (buffer_flags & GST_BUFFER_FLAG_DELTA_UNIT)
317 /* update timestamps */
318 if (GST_CLOCK_TIME_IS_VALID (buffer_ts) &&
319 GST_CLOCK_TIME_IS_VALID (buffer_dur)) {
320 stats->next_ts = buffer_ts + buffer_dur;
322 stats->next_ts = GST_CLOCK_TIME_NONE;
327 do_element_stats (GstElementStats * stats, GstElementStats * peer_stats,
328 guint size, guint64 ts)
330 stats->sent_buffers++;
331 peer_stats->recv_buffers++;
332 stats->sent_bytes += size;
333 peer_stats->recv_bytes += size;
335 if (G_UNLIKELY (!GST_CLOCK_TIME_IS_VALID (stats->first_ts))) {
336 stats->first_ts = ts;
338 if (G_UNLIKELY (!GST_CLOCK_TIME_IS_VALID (peer_stats->first_ts))) {
339 peer_stats->first_ts = ts + 1;
344 do_buffer_stats (GstStructure * s)
347 guint64 buffer_pts = GST_CLOCK_TIME_NONE, buffer_dur = GST_CLOCK_TIME_NONE;
348 guint pad_ix, elem_ix, peer_elem_ix;
350 GstBufferFlags buffer_flags;
351 GstPadStats *pad_stats;
352 GstElementStats *elem_stats, *peer_elem_stats;
355 gst_structure_get (s, "ts", G_TYPE_UINT64, &ts,
356 "pad-ix", G_TYPE_UINT, &pad_ix,
357 "element-ix", G_TYPE_UINT, &elem_ix,
358 "peer-element-ix", G_TYPE_UINT, &peer_elem_ix,
359 "buffer-size", G_TYPE_UINT, &size,
360 "buffer-flags", GST_TYPE_BUFFER_FLAGS, &buffer_flags, NULL);
361 gst_structure_get_uint64 (s, "buffer-pts", &buffer_pts);
362 gst_structure_get_uint64 (s, "buffer-duration", &buffer_dur);
363 last_ts = MAX (last_ts, ts);
364 if (!(pad_stats = get_pad_stats (pad_ix))) {
365 GST_WARNING ("no pad stats found for ix=%u", pad_ix);
368 if (!(elem_stats = get_element_stats (elem_ix))) {
369 GST_WARNING ("no element stats found for ix=%u", elem_ix);
372 if (!(peer_elem_stats = get_element_stats (peer_elem_ix))) {
373 GST_WARNING ("no element stats found for ix=%u", peer_elem_ix);
376 do_pad_stats (pad_stats, elem_ix, size, ts, buffer_pts, buffer_dur,
378 if (pad_stats->dir == GST_PAD_SRC) {
380 do_element_stats (elem_stats, peer_elem_stats, size, ts);
383 do_element_stats (peer_elem_stats, elem_stats, size, ts);
388 do_event_stats (GstStructure * s)
391 guint pad_ix, elem_ix;
392 GstPadStats *pad_stats;
393 GstElementStats *elem_stats;
396 gst_structure_get (s, "ts", G_TYPE_UINT64, &ts,
397 "pad-ix", G_TYPE_UINT, &pad_ix, "element-ix", G_TYPE_UINT, &elem_ix,
399 last_ts = MAX (last_ts, ts);
400 if (!(pad_stats = get_pad_stats (pad_ix))) {
401 GST_WARNING ("no pad stats found for ix=%u", pad_ix);
404 if (!(elem_stats = get_element_stats (elem_ix))) {
405 // e.g. reconfigure events are send over unparented pads
406 GST_INFO ("no element stats found for ix=%u", elem_ix);
409 elem_stats->num_events++;
413 do_message_stats (GstStructure * s)
417 GstElementStats *elem_stats;
420 gst_structure_get (s, "ts", G_TYPE_UINT64, &ts,
421 "element-ix", G_TYPE_UINT, &elem_ix, NULL);
422 last_ts = MAX (last_ts, ts);
423 if (!(elem_stats = get_element_stats (elem_ix))) {
424 GST_WARNING ("no element stats found for ix=%u", elem_ix);
427 elem_stats->num_messages++;
431 do_query_stats (GstStructure * s)
435 GstElementStats *elem_stats;
438 gst_structure_get (s, "ts", G_TYPE_UINT64, &ts,
439 "element-ix", G_TYPE_UINT, &elem_ix, NULL);
440 last_ts = MAX (last_ts, ts);
441 if (!(elem_stats = get_element_stats (elem_ix))) {
442 GST_WARNING ("no element stats found for ix=%u", elem_ix);
445 elem_stats->num_queries++;
449 do_thread_rusage_stats (GstStructure * s)
451 guint64 ts, tthread, thread_id;
453 GstThreadStats *thread_stats;
455 gst_structure_get (s, "ts", G_TYPE_UINT64, &ts,
456 "thread-id", G_TYPE_UINT64, &thread_id,
457 "average-cpuload", G_TYPE_UINT, &cpuload, "time", G_TYPE_UINT64, &tthread,
459 thread_stats = get_thread_stats ((gpointer) (guintptr) thread_id);
460 thread_stats->cpuload = cpuload;
461 thread_stats->tthread = tthread;
462 last_ts = MAX (last_ts, ts);
466 do_proc_rusage_stats (GstStructure * s)
470 gst_structure_get (s, "ts", G_TYPE_UINT64, &ts,
471 "average-cpuload", G_TYPE_UINT, &total_cpuload, NULL);
472 last_ts = MAX (last_ts, ts);
477 update_latency_table (GHashTable * table, const gchar * key, guint64 time)
479 /* Find the values in the hash table */
480 GstLatencyStats *ls = g_hash_table_lookup (table, key);
482 /* Insert the new key if the value does not exist */
483 ls = g_new0 (GstLatencyStats, 1);
488 g_hash_table_insert (table, g_strdup (key), ls);
490 /* Otherwise update the existing value */
501 do_latency_stats (GstStructure * s)
504 const gchar *src = NULL, *sink = NULL, *src_element = NULL,
505 *sink_element = NULL, *src_element_id = NULL, *sink_element_id = NULL;
506 guint64 ts = 0, time = 0;
508 /* Get the values from the structure */
509 src = gst_structure_get_string (s, "src");
510 sink = gst_structure_get_string (s, "sink");
511 src_element = gst_structure_get_string (s, "src-element");
512 sink_element = gst_structure_get_string (s, "sink-element");
513 src_element_id = gst_structure_get_string (s, "src-element-id");
514 sink_element_id = gst_structure_get_string (s, "sink-element-id");
515 gst_structure_get (s, "time", G_TYPE_UINT64, &time, NULL);
516 gst_structure_get (s, "ts", G_TYPE_UINT64, &ts, NULL);
519 last_ts = MAX (last_ts, ts);
522 key = g_strdup_printf ("%s.%s.%s|%s.%s.%s", src_element_id, src_element,
523 src, sink_element_id, sink_element, sink);
525 /* Update the latency in the table */
526 update_latency_table (latencies, key, time);
535 do_element_latency_stats (GstStructure * s)
538 const gchar *src = NULL, *element = NULL, *element_id = NULL;
539 guint64 ts = 0, time = 0;
541 /* Get the values from the structure */
542 src = gst_structure_get_string (s, "src");
543 element = gst_structure_get_string (s, "element");
544 element_id = gst_structure_get_string (s, "element-id");
545 gst_structure_get (s, "time", G_TYPE_UINT64, &time, NULL);
546 gst_structure_get (s, "ts", G_TYPE_UINT64, &ts, NULL);
549 last_ts = MAX (last_ts, ts);
552 key = g_strdup_printf ("%s.%s.%s", element_id, element, src);
554 /* Update the latency in the table */
555 update_latency_table (element_latencies, key, time);
560 have_element_latency = TRUE;
564 do_element_reported_latency (GstStructure * s)
566 const gchar *element = NULL, *element_id = NULL;
567 guint64 ts = 0, min = 0, max = 0;
568 GstReportedLatency *rl = NULL;
570 /* Get the values from the structure */
571 element_id = gst_structure_get_string (s, "element-id");
572 element = gst_structure_get_string (s, "element");
573 gst_structure_get (s, "min", G_TYPE_UINT64, &min, NULL);
574 gst_structure_get (s, "max", G_TYPE_UINT64, &max, NULL);
575 gst_structure_get (s, "ts", G_TYPE_UINT64, &ts, NULL);
578 last_ts = MAX (last_ts, ts);
580 /* Insert/Update the key in the table */
581 rl = g_new0 (GstReportedLatency, 1);
582 rl->element = g_strdup_printf ("%s.%s", element_id, element);
586 g_queue_push_tail (element_reported_latencies, rl);
588 have_element_reported_latency = TRUE;
594 find_pad_stats_for_thread (gconstpointer value, gconstpointer user_data)
596 const GstPadStats *stats = (const GstPadStats *) value;
598 if ((stats->thread_id == user_data) && (stats->num_buffers)) {
605 print_pad_stats (gpointer value, gpointer user_data)
607 GstPadStats *stats = (GstPadStats *) value;
609 if (stats->thread_id == user_data) {
610 /* there seem to be some temporary pads */
611 if (stats->num_buffers) {
612 GstClockTimeDiff running =
613 GST_CLOCK_DIFF (stats->first_ts, stats->last_ts);
614 GstElementStats *elem_stats = get_element_stats (stats->parent_ix);
615 gchar fullname[30 + 1];
617 g_snprintf (fullname, 30, "%s.%s", elem_stats->name, stats->name);
620 (" %c %-30.30s: buffers %7u (live %5u,dec %5u,dis %5u,res %5u,"
621 "cor %5u,mar %5u,hdr %5u,gap %5u,drop %5u,dlt %5u),",
622 (stats->dir == GST_PAD_SRC) ? '>' : '<', fullname, stats->num_buffers,
623 stats->num_live, stats->num_decode_only, stats->num_discont,
624 stats->num_resync, stats->num_corrupted, stats->num_marker,
625 stats->num_header, stats->num_gap, stats->num_droppable,
627 if (stats->min_size == stats->max_size) {
628 printf (" size (min/avg/max) ......./%7u/.......,", stats->avg_size);
630 printf (" size (min/avg/max) %7u/%7u/%7u,",
631 stats->min_size, stats->avg_size, stats->max_size);
633 printf (" time %" GST_TIME_FORMAT ","
635 GST_TIME_ARGS (running),
636 ((gdouble) (stats->num_buffers * stats->avg_size) * GST_SECOND) /
637 ((gdouble) running));
643 print_thread_stats (gpointer key, gpointer value, gpointer user_data)
645 GSList *list = user_data;
646 GSList *node = g_slist_find_custom (list, key, find_pad_stats_for_thread);
647 GstThreadStats *stats = (GstThreadStats *) value;
649 /* skip stats if there are no pads for that thread (e.g. a pipeline) */
653 printf ("Thread %p Statistics:\n", key);
654 if (GST_CLOCK_TIME_IS_VALID (stats->tthread)) {
655 printf (" Time: %" GST_TIME_FORMAT "\n", GST_TIME_ARGS (stats->tthread));
656 printf (" Avg CPU load: %4.1f %%\n", (gfloat) stats->cpuload / 10.0);
659 puts (" Pad Statistics:");
660 g_slist_foreach (node, print_pad_stats, key);
664 print_element_stats (gpointer value, gpointer user_data)
666 GstElementStats *stats = (GstElementStats *) value;
668 /* skip temporary elements */
669 if (stats->first_ts != GST_CLOCK_TIME_NONE) {
670 gchar fullname[45 + 1];
672 g_snprintf (fullname, 45, "%s:%s", stats->type_name, stats->name);
674 printf (" %-45s:", fullname);
675 if (stats->recv_buffers)
676 printf (" buffers in/out %7u", stats->recv_buffers);
678 printf (" buffers in/out %7s", "-");
679 if (stats->sent_buffers)
680 printf ("/%7u", stats->sent_buffers);
682 printf ("/%7s", "-");
683 if (stats->recv_bytes)
684 printf (" bytes in/out %12" G_GUINT64_FORMAT, stats->recv_bytes);
686 printf (" bytes in/out %12s", "-");
687 if (stats->sent_bytes)
688 printf ("/%12" G_GUINT64_FORMAT, stats->sent_bytes);
690 printf ("/%12s", "-");
691 printf (" first activity %" GST_TIME_FORMAT ", "
692 " ev/msg/qry sent %5u/%5u/%5u\n", GST_TIME_ARGS (stats->first_ts),
693 stats->num_events, stats->num_messages, stats->num_queries);
698 accum_element_stats (gpointer value, gpointer user_data)
700 GstElementStats *stats = (GstElementStats *) value;
702 if (stats->parent_ix != G_MAXUINT) {
703 GstElementStats *parent_stats = get_element_stats (stats->parent_ix);
705 parent_stats->num_events += stats->num_events;
706 parent_stats->num_messages += stats->num_messages;
707 parent_stats->num_queries += stats->num_queries;
708 if (!GST_CLOCK_TIME_IS_VALID (parent_stats->first_ts)) {
709 parent_stats->first_ts = stats->first_ts;
710 } else if (GST_CLOCK_TIME_IS_VALID (stats->first_ts)) {
711 parent_stats->first_ts = MIN (parent_stats->first_ts, stats->first_ts);
713 if (!GST_CLOCK_TIME_IS_VALID (parent_stats->last_ts)) {
714 parent_stats->last_ts = stats->last_ts;
715 } else if (GST_CLOCK_TIME_IS_VALID (stats->last_ts)) {
716 parent_stats->last_ts = MAX (parent_stats->last_ts, stats->last_ts);
724 sort_pad_stats_by_first_activity (gconstpointer ps1, gconstpointer ps2)
726 GstPadStats *s1 = (GstPadStats *) ps1;
727 GstPadStats *s2 = (GstPadStats *) ps2;
729 gint order = GST_CLOCK_DIFF (s2->first_ts, s1->first_ts);
732 order = s1->dir - s2->dir;
738 sort_pad_stats (gpointer value, gpointer user_data)
740 GSList **list = user_data;
743 g_slist_insert_sorted (*list, value, sort_pad_stats_by_first_activity);
747 sort_element_stats_by_first_activity (gconstpointer es1, gconstpointer es2)
749 return (GST_CLOCK_DIFF (((GstElementStats *) es2)->first_ts,
750 ((GstElementStats *) es1)->first_ts));
754 sort_bin_stats (gpointer value, gpointer user_data)
756 if (((GstElementStats *) value)->is_bin) {
757 GSList **list = user_data;
760 g_slist_insert_sorted (*list, value,
761 sort_element_stats_by_first_activity);
766 sort_element_stats (gpointer value, gpointer user_data)
768 if (!(((GstElementStats *) value)->is_bin)) {
769 GSList **list = user_data;
772 g_slist_insert_sorted (*list, value,
773 sort_element_stats_by_first_activity);
778 check_bin_parent (gpointer key, gpointer value, gpointer user_data)
780 GstElementStats *stats = (GstElementStats *) value;
782 return (stats->parent_ix == GPOINTER_TO_UINT (user_data));
786 process_leaf_bins (gpointer key, gpointer value, gpointer user_data)
788 GHashTable *accum_bins = user_data;
790 /* if we find no bin that has this bin as a parent ... */
791 if (!g_hash_table_find (accum_bins, check_bin_parent, key)) {
792 /* accumulate stats to the parent and remove */
793 accum_element_stats (value, NULL);
804 /* compile the parser regexps */
805 /* 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" */
806 raw_log = g_regex_new (
817 /* 6: file:line:func: */
818 "([^:]*:[0-9]+:[^:]*:) +"
819 /* 7: (obj)? log-text */
820 "(.*)$", 0, 0, NULL);
822 GST_WARNING ("failed to compile the 'raw' parser");
826 ansi_log = g_regex_new (
830 "\\\x1b\\[[0-9;]+m *([0-9]+)\\\x1b\\[00m +"
834 "(?:\\\x1b\\[[0-9;]+m)?([A-Z]+) +\\\x1b\\[00m +"
836 "\\\x1b\\[[0-9;]+m +([a-zA-Z_-]+) +"
837 /* 6: file:line:func: */
838 "([^:]*:[0-9]+:[^:]*:)(?:\\\x1b\\[00m)? +"
839 /* 7: (obj)? log-text */
840 "(.*)$", 0, 0, NULL);
842 GST_WARNING ("failed to compile the 'ansi' parser");
846 elements = g_ptr_array_new_with_free_func (free_element_stats);
847 pads = g_ptr_array_new_with_free_func (free_pad_stats);
848 threads = g_hash_table_new_full (NULL, NULL, NULL, free_thread_stats);
849 latencies = g_hash_table_new_full (g_str_hash, g_str_equal, g_free,
851 element_latencies = g_hash_table_new_full (g_str_hash, g_str_equal, g_free,
853 element_reported_latencies = g_queue_new ();
862 g_ptr_array_free (pads, TRUE);
864 g_ptr_array_free (elements, TRUE);
866 g_hash_table_destroy (threads);
869 g_hash_table_remove_all (latencies);
870 g_hash_table_destroy (latencies);
873 if (element_latencies) {
874 g_hash_table_remove_all (element_latencies);
875 g_hash_table_destroy (element_latencies);
876 element_latencies = NULL;
878 if (element_reported_latencies) {
879 g_queue_free_full (element_reported_latencies, free_reported_latency);
880 element_reported_latencies = NULL;
884 g_regex_unref (raw_log);
886 g_regex_unref (ansi_log);
892 guint num_threads = g_hash_table_size (threads);
894 /* print overall stats */
895 puts ("\nOverall Statistics:");
896 printf ("Number of Threads: %u\n", num_threads);
897 printf ("Number of Elements: %u\n", num_elements - num_bins);
898 printf ("Number of Bins: %u\n", num_bins);
899 printf ("Number of Pads: %u\n", num_pads - num_ghostpads);
900 printf ("Number of GhostPads: %u\n", num_ghostpads);
901 printf ("Number of Buffers passed: %" G_GUINT64_FORMAT "\n", num_buffers);
902 printf ("Number of Events sent: %" G_GUINT64_FORMAT "\n", num_events);
903 printf ("Number of Message sent: %" G_GUINT64_FORMAT "\n", num_messages);
904 printf ("Number of Queries sent: %" G_GUINT64_FORMAT "\n", num_queries);
905 printf ("Time: %" GST_TIME_FORMAT "\n", GST_TIME_ARGS (last_ts));
907 printf ("Avg CPU load: %4.1f %%\n", (gfloat) total_cpuload / 10.0);
915 g_ptr_array_foreach (pads, sort_pad_stats, &list);
916 g_hash_table_foreach (threads, print_thread_stats, list);
925 puts ("Element Statistics:");
926 /* sort by first_activity */
927 g_ptr_array_foreach (elements, sort_element_stats, &list);
928 /* attribute element stats to bins */
929 g_slist_foreach (list, accum_element_stats, NULL);
930 g_slist_foreach (list, print_element_stats, NULL);
939 GHashTable *accum_bins = g_hash_table_new_full (NULL, NULL, NULL, NULL);
941 puts ("Bin Statistics:");
942 /* attribute bin stats to parent-bins */
943 for (i = 0; i < num_elements; i++) {
944 GstElementStats *stats = g_ptr_array_index (elements, i);
946 g_hash_table_insert (accum_bins, GUINT_TO_POINTER (i), stats);
949 while (g_hash_table_size (accum_bins)) {
950 g_hash_table_foreach_remove (accum_bins, process_leaf_bins, accum_bins);
952 g_hash_table_destroy (accum_bins);
953 /* sort by first_activity */
954 g_ptr_array_foreach (elements, sort_bin_stats, &list);
955 g_slist_foreach (list, print_element_stats, NULL);
962 puts ("Latency Statistics:");
963 g_hash_table_foreach (latencies, (GHFunc) latencies_foreach_print_stats,
968 /* element latency stats */
969 if (have_element_latency) {
970 puts ("Element Latency Statistics:");
971 g_hash_table_foreach (element_latencies,
972 (GHFunc) latencies_foreach_print_stats, NULL);
976 /* element reported latency stats */
977 if (have_element_reported_latency) {
978 puts ("Element Reported Latency:");
979 g_queue_foreach (element_reported_latencies,
980 (GFunc) reported_latencies_foreach_print_stats, NULL);
986 collect_stats (const gchar * filename)
990 if ((log = fopen (filename, "rt"))) {
994 if (fgets (line, 5000, log)) {
995 GMatchInfo *match_info;
1001 if (strchr (line, 27)) {
1003 GST_INFO ("format is 'ansi'");
1006 GST_INFO ("format is 'raw'");
1011 while (!feof (log)) {
1012 if (fgets (line, 5000, log)) {
1013 if (g_regex_match (parser, line, 0, &match_info)) {
1014 /* filter by level */
1015 level = g_match_info_fetch (match_info, 4);
1016 if (!strcmp (level, "TRACE")) {
1017 data = g_match_info_fetch (match_info, 7);
1018 if ((s = gst_structure_from_string (data, NULL))) {
1019 const gchar *name = gst_structure_get_name (s);
1021 if (!strcmp (name, "new-pad")) {
1023 } else if (!strcmp (name, "new-element")) {
1024 new_element_stats (s);
1025 } else if (!strcmp (name, "buffer")) {
1026 do_buffer_stats (s);
1027 } else if (!strcmp (name, "event")) {
1029 } else if (!strcmp (name, "message")) {
1030 do_message_stats (s);
1031 } else if (!strcmp (name, "query")) {
1033 } else if (!strcmp (name, "thread-rusage")) {
1034 do_thread_rusage_stats (s);
1035 } else if (!strcmp (name, "proc-rusage")) {
1036 do_proc_rusage_stats (s);
1037 } else if (!strcmp (name, "latency")) {
1038 do_latency_stats (s);
1039 } else if (!strcmp (name, "element-latency")) {
1040 do_element_latency_stats (s);
1041 } else if (!strcmp (name, "element-reported-latency")) {
1042 do_element_reported_latency (s);
1044 // TODO(ensonic): parse the xxx.class log lines
1045 if (!g_str_has_suffix (data, ".class")) {
1046 GST_WARNING ("unknown log entry: '%s'", data);
1049 gst_structure_free (s);
1051 GST_WARNING ("unknown log entry: '%s'", data);
1056 GST_WARNING ("foreign log entry: %s:%d:'%s'", filename, lnr,
1060 g_match_info_free (match_info);
1065 // TODO(ensonic): run wc -L on the log file
1066 fprintf (stderr, "line too long");
1071 GST_WARNING ("empty log");
1078 main (gint argc, gchar * argv[])
1080 gchar **filenames = NULL;
1083 GOptionContext *ctx;
1084 GOptionEntry options[] = {
1085 GST_TOOLS_GOPTION_VERSION,
1086 // TODO(ensonic): add a summary flag, if set read the whole thing, print
1087 // stats once, and exit
1088 {G_OPTION_REMAINING, 0, 0, G_OPTION_ARG_FILENAME_ARRAY, &filenames, NULL}
1094 bindtextdomain (GETTEXT_PACKAGE, LOCALEDIR);
1095 bind_textdomain_codeset (GETTEXT_PACKAGE, "UTF-8");
1096 textdomain (GETTEXT_PACKAGE);
1099 g_set_prgname ("gst-stats-" GST_API_VERSION);
1101 ctx = g_option_context_new ("FILE");
1102 g_option_context_add_main_entries (ctx, options, GETTEXT_PACKAGE);
1103 g_option_context_add_group (ctx, gst_init_get_option_group ());
1104 if (!g_option_context_parse (ctx, &argc, &argv, &err)) {
1105 g_print ("Error initializing: %s\n", GST_STR_NULL (err->message));
1108 g_option_context_free (ctx);
1110 gst_tools_print_version ();
1112 if (filenames == NULL || *filenames == NULL) {
1113 g_print ("Please give one filename to %s\n\n", g_get_prgname ());
1116 num = g_strv_length (filenames);
1117 if (num == 0 || num > 1) {
1118 g_print ("Please give exactly one filename to %s (%d given).\n\n",
1119 g_get_prgname (), num);
1124 collect_stats (filenames[0]);
1129 g_strfreev (filenames);