95bba8cb943c9ca260c0a4d9fdc7bcf501ef951d
[platform/upstream/gstreamer.git] / tools / gst-stats.c
1 /* GStreamer
2  * Copyright (C) 2013 Stefan Sauer <ensonic@users.sf.net>
3  *
4  * gst-stats.c: statistics tracing front end
5  *
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.
10  *
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.
15  *
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.
20  */
21
22 #ifdef HAVE_CONFIG_H
23 #  include "config.h"
24 #endif
25
26 #include <stdlib.h>
27 #include <stdio.h>
28 #include <string.h>
29
30 #include "tools.h"
31
32 /* log parser */
33 static GRegex *raw_log = NULL;
34 static GRegex *ansi_log = NULL;
35
36 /* global statistics */
37 static GHashTable *threads = NULL;
38 static GPtrArray *elements = NULL;
39 static GPtrArray *pads = NULL;
40 static guint64 num_buffers = 0, num_events = 0, num_messages = 0, num_queries =
41     0;
42 static guint num_elements = 0, num_bins = 0, num_pads = 0, num_ghostpads = 0;
43 static GstClockTime last_ts = G_GUINT64_CONSTANT (0);
44 static guint total_cpuload = 0;
45 static gboolean have_cpuload = FALSE;
46
47 typedef struct
48 {
49   /* human readable pad name and details */
50   gchar *name, *type_name;
51   guint index;
52   gboolean is_ghost_pad;
53   GstPadDirection dir;
54   /* buffer statistics */
55   guint num_buffers;
56   guint num_live, num_decode_only, num_discont, num_resync, num_corrupted,
57       num_marker, num_header, num_gap, num_droppable, num_delta;
58   guint min_size, max_size, avg_size;
59   /* first and last activity on the pad, expected next_ts */
60   GstClockTime first_ts, last_ts, next_ts;
61   /* in which thread does it operate */
62   guint thread_id;
63   /* hierarchy */
64   guint parent_ix;
65 } GstPadStats;
66
67 typedef struct
68 {
69   /* human readable element name */
70   gchar *name, *type_name;
71   guint index;
72   gboolean is_bin;
73   /* buffer statistics */
74   guint recv_buffers, sent_buffers;
75   guint64 recv_bytes, sent_bytes;
76   /* event, message statistics */
77   guint num_events, num_messages, num_queries;
78   /* first activity on the element */
79   GstClockTime first_ts, last_ts;
80   /* hierarchy */
81   guint parent_ix;
82 } GstElementStats;
83
84 typedef struct
85 {
86   /* time spend in this thread */
87   GstClockTime tthread;
88   guint cpuload;
89 } GstThreadStats;
90
91 /* stats helper */
92
93 static void
94 free_element_stats (gpointer data)
95 {
96   g_slice_free (GstElementStats, data);
97 }
98
99 static inline GstElementStats *
100 get_element_stats (guint ix)
101 {
102   return (ix != G_MAXUINT) ? g_ptr_array_index (elements, ix) : NULL;
103 }
104
105 static inline GstPadStats *
106 get_pad_stats (guint ix)
107 {
108   return (ix != G_MAXUINT) ? g_ptr_array_index (pads, ix) : NULL;
109 }
110
111 static void
112 free_pad_stats (gpointer data)
113 {
114   g_slice_free (GstPadStats, data);
115 }
116
117 static inline GstThreadStats *
118 get_thread_stats (guint id)
119 {
120   GstThreadStats *stats = g_hash_table_lookup (threads, GUINT_TO_POINTER (id));
121
122   if (G_UNLIKELY (!stats)) {
123     stats = g_slice_new0 (GstThreadStats);
124     stats->tthread = GST_CLOCK_TIME_NONE;
125     g_hash_table_insert (threads, GUINT_TO_POINTER (id), stats);
126   }
127   return stats;
128 }
129
130 static void
131 new_pad_stats (GstStructure * s)
132 {
133   GstPadStats *stats;
134   guint ix, parent_ix;
135   gchar *type, *name;
136   gboolean is_ghost_pad;
137   GstPadDirection dir;
138   guint thread_id;
139
140   gst_structure_get (s,
141       "ix", G_TYPE_UINT, &ix,
142       "parent-ix", G_TYPE_UINT, &parent_ix,
143       "name", G_TYPE_STRING, &name,
144       "type", G_TYPE_STRING, &type,
145       "is-ghostpad", G_TYPE_BOOLEAN, &is_ghost_pad,
146       "pad-direction", GST_TYPE_PAD_DIRECTION, &dir,
147       "thread-id", G_TYPE_UINT, &thread_id, NULL);
148
149   stats = g_slice_new0 (GstPadStats);
150   if (is_ghost_pad)
151     num_ghostpads++;
152   num_pads++;
153   stats->name = name;
154   stats->type_name = type;
155   stats->index = ix;
156   stats->is_ghost_pad = is_ghost_pad;
157   stats->dir = dir;
158   stats->min_size = G_MAXUINT;
159   stats->first_ts = stats->last_ts = stats->next_ts = GST_CLOCK_TIME_NONE;
160   stats->thread_id = thread_id;
161   stats->parent_ix = parent_ix;
162
163   if (pads->len <= ix)
164     g_ptr_array_set_size (pads, ix + 1);
165   g_ptr_array_index (pads, ix) = stats;
166 }
167
168 static void
169 new_element_stats (GstStructure * s)
170 {
171   GstElementStats *stats;
172   guint ix, parent_ix;
173   gchar *type, *name;
174   gboolean is_bin;
175
176   gst_structure_get (s,
177       "ix", G_TYPE_UINT, &ix,
178       "parent-ix", G_TYPE_UINT, &parent_ix,
179       "name", G_TYPE_STRING, &name,
180       "type", G_TYPE_STRING, &type, "is-bin", G_TYPE_BOOLEAN, &is_bin, NULL);
181
182   stats = g_slice_new0 (GstElementStats);
183   if (is_bin)
184     num_bins++;
185   num_elements++;
186   stats->index = ix;
187   stats->name = name;
188   stats->type_name = type;
189   stats->is_bin = is_bin;
190   stats->first_ts = GST_CLOCK_TIME_NONE;
191   stats->parent_ix = parent_ix;
192
193   if (elements->len <= ix)
194     g_ptr_array_set_size (elements, ix + 1);
195   g_ptr_array_index (elements, ix) = stats;
196 }
197
198 static void
199 free_thread_stats (gpointer data)
200 {
201   g_slice_free (GstThreadStats, data);
202 }
203
204 static void
205 do_pad_stats (GstPadStats * stats, guint elem_ix, guint size, guint64 ts,
206     guint64 buffer_ts, guint64 buffer_dur, GstBufferFlags buffer_flags)
207 {
208   gulong avg_size;
209
210   /* parentage */
211   if (stats->parent_ix == G_MAXUINT) {
212     stats->parent_ix = elem_ix;
213   }
214
215   if (stats->thread_id) {
216     get_thread_stats (stats->thread_id);
217   }
218
219   /* size stats */
220   avg_size = (((gulong) stats->avg_size * (gulong) stats->num_buffers) + size);
221   stats->num_buffers++;
222   stats->avg_size = (guint) (avg_size / stats->num_buffers);
223   if (size < stats->min_size)
224     stats->min_size = size;
225   else if (size > stats->max_size)
226     stats->max_size = size;
227   /* time stats */
228   if (!GST_CLOCK_TIME_IS_VALID (stats->last_ts))
229     stats->first_ts = ts;
230   stats->last_ts = ts;
231   /* flag stats */
232   if (buffer_flags & GST_BUFFER_FLAG_LIVE)
233     stats->num_live++;
234   if (buffer_flags & GST_BUFFER_FLAG_DECODE_ONLY)
235     stats->num_decode_only++;
236   if (buffer_flags & GST_BUFFER_FLAG_DISCONT)
237     stats->num_discont++;
238   if (buffer_flags & GST_BUFFER_FLAG_RESYNC)
239     stats->num_resync++;
240   if (buffer_flags & GST_BUFFER_FLAG_CORRUPTED)
241     stats->num_corrupted++;
242   if (buffer_flags & GST_BUFFER_FLAG_MARKER)
243     stats->num_marker++;
244   if (buffer_flags & GST_BUFFER_FLAG_HEADER)
245     stats->num_header++;
246   if (buffer_flags & GST_BUFFER_FLAG_GAP)
247     stats->num_gap++;
248   if (buffer_flags & GST_BUFFER_FLAG_DROPPABLE)
249     stats->num_droppable++;
250   if (buffer_flags & GST_BUFFER_FLAG_DELTA_UNIT)
251     stats->num_delta++;
252   /* update timestamps */
253   if (GST_CLOCK_TIME_IS_VALID (buffer_ts) &&
254       GST_CLOCK_TIME_IS_VALID (buffer_dur)) {
255     stats->next_ts = buffer_ts + buffer_dur;
256   } else {
257     stats->next_ts = GST_CLOCK_TIME_NONE;
258   }
259 }
260
261 static void
262 do_element_stats (GstElementStats * stats, GstElementStats * peer_stats,
263     guint size, guint64 ts)
264 {
265   stats->sent_buffers++;
266   peer_stats->recv_buffers++;
267   stats->sent_bytes += size;
268   peer_stats->recv_bytes += size;
269   /* time stats */
270   if (G_UNLIKELY (!GST_CLOCK_TIME_IS_VALID (stats->first_ts))) {
271     stats->first_ts = ts;
272   }
273   if (G_UNLIKELY (!GST_CLOCK_TIME_IS_VALID (peer_stats->first_ts))) {
274     peer_stats->first_ts = ts + 1;
275   }
276 }
277
278 static void
279 do_buffer_stats (GstStructure * s)
280 {
281   guint64 ts, buffer_ts, buffer_dur;
282   guint pad_ix, elem_ix, peer_elem_ix;
283   guint size;
284   GstBufferFlags buffer_flags;
285   GstPadStats *pad_stats;
286   GstElementStats *elem_stats, *peer_elem_stats;
287
288   num_buffers++;
289   gst_structure_get (s, "ts", G_TYPE_UINT64, &ts,
290       "pad-ix", G_TYPE_UINT, &pad_ix,
291       "elem-ix", G_TYPE_UINT, &elem_ix,
292       "peer-elem-ix", G_TYPE_UINT, &peer_elem_ix,
293       "buffer-size", G_TYPE_UINT, &size,
294       "buffer-ts", G_TYPE_UINT64, &buffer_ts,
295       "buffer-duration", G_TYPE_UINT64, &buffer_dur,
296       "buffer-flags", GST_TYPE_BUFFER_FLAGS, &buffer_flags, NULL);
297   last_ts = MAX (last_ts, ts);
298   if (!(pad_stats = get_pad_stats (pad_ix))) {
299     GST_WARNING ("no pad stats found for ix=%u", pad_ix);
300     return;
301   }
302   if (!(elem_stats = get_element_stats (elem_ix))) {
303     GST_WARNING ("no element stats found for ix=%u", elem_ix);
304     return;
305   }
306   if (!(peer_elem_stats = get_element_stats (peer_elem_ix))) {
307     GST_WARNING ("no element stats found for ix=%u", peer_elem_ix);
308     return;
309   }
310   do_pad_stats (pad_stats, elem_ix, size, ts, buffer_ts, buffer_dur,
311       buffer_flags);
312   if (pad_stats->dir == GST_PAD_SRC) {
313     /* push */
314     do_element_stats (elem_stats, peer_elem_stats, size, ts);
315   } else {
316     /* pull */
317     do_element_stats (peer_elem_stats, elem_stats, size, ts);
318   }
319 }
320
321 static void
322 do_event_stats (GstStructure * s)
323 {
324   guint64 ts;
325   guint pad_ix, elem_ix;
326   GstPadStats *pad_stats;
327   GstElementStats *elem_stats;
328
329   num_events++;
330   gst_structure_get (s, "ts", G_TYPE_UINT64, &ts,
331       "pad-ix", G_TYPE_UINT, &pad_ix, "elem-ix", G_TYPE_UINT, &elem_ix, NULL);
332   last_ts = MAX (last_ts, ts);
333   if (!(pad_stats = get_pad_stats (pad_ix))) {
334     GST_WARNING ("no pad stats found for ix=%u", pad_ix);
335     return;
336   }
337   if (!(elem_stats = get_element_stats (elem_ix))) {
338     // e.g. reconfigure events are send over unparented pads
339     GST_INFO ("no element stats found for ix=%u", elem_ix);
340     return;
341   }
342   elem_stats->num_events++;
343 }
344
345 static void
346 do_message_stats (GstStructure * s)
347 {
348   guint64 ts;
349   guint elem_ix;
350   GstElementStats *elem_stats;
351
352   num_messages++;
353   gst_structure_get (s, "ts", G_TYPE_UINT64, &ts,
354       "elem-ix", G_TYPE_UINT, &elem_ix, NULL);
355   last_ts = MAX (last_ts, ts);
356   if (!(elem_stats = get_element_stats (elem_ix))) {
357     GST_WARNING ("no element stats found for ix=%u", elem_ix);
358     return;
359   }
360   elem_stats->num_messages++;
361 }
362
363 static void
364 do_query_stats (GstStructure * s)
365 {
366   guint64 ts;
367   guint elem_ix;
368   GstElementStats *elem_stats;
369
370   num_queries++;
371   gst_structure_get (s, "ts", G_TYPE_UINT64, &ts,
372       "elem-ix", G_TYPE_UINT, &elem_ix, NULL);
373   last_ts = MAX (last_ts, ts);
374   if (!(elem_stats = get_element_stats (elem_ix))) {
375     GST_WARNING ("no element stats found for ix=%u", elem_ix);
376     return;
377   }
378   elem_stats->num_queries++;
379 }
380
381 static void
382 do_thread_rusage_stats (GstStructure * s)
383 {
384   guint64 ts, tthread;
385   guint thread_id, cpuload;
386   GstThreadStats *thread_stats;
387
388   gst_structure_get (s, "ts", G_TYPE_UINT64, &ts,
389       "thread-id", G_TYPE_UINT, &thread_id,
390       "average-cpuload", G_TYPE_UINT, &cpuload, "time", G_TYPE_UINT64, &tthread,
391       NULL);
392   thread_stats = get_thread_stats (thread_id);
393   thread_stats->cpuload = cpuload;
394   thread_stats->tthread = tthread;
395   last_ts = MAX (last_ts, ts);
396 }
397
398 static void
399 do_proc_rusage_stats (GstStructure * s)
400 {
401   guint64 ts;
402
403   gst_structure_get (s, "ts", G_TYPE_UINT64, &ts,
404       "average-cpuload", G_TYPE_UINT, &total_cpuload, NULL);
405   last_ts = MAX (last_ts, ts);
406   have_cpuload = TRUE;
407 }
408
409 /* reporting */
410
411 static gint
412 find_pad_stats_for_thread (gconstpointer value, gconstpointer user_data)
413 {
414   const GstPadStats *stats = (const GstPadStats *) value;
415
416   if ((stats->thread_id == GPOINTER_TO_UINT (user_data)) &&
417       (stats->num_buffers)) {
418     return 0;
419   }
420   return 1;
421 }
422
423 static void
424 print_pad_stats (gpointer value, gpointer user_data)
425 {
426   GstPadStats *stats = (GstPadStats *) value;
427
428   if (stats->thread_id == GPOINTER_TO_UINT (user_data)) {
429     /* there seem to be some temporary pads */
430     if (stats->num_buffers) {
431       GstClockTimeDiff running =
432           GST_CLOCK_DIFF (stats->first_ts, stats->last_ts);
433       GstElementStats *elem_stats = get_element_stats (stats->parent_ix);
434       gchar fullname[30 + 1];
435
436       g_snprintf (fullname, 30, "%s.%s", elem_stats->name, stats->name);
437
438       printf
439           ("    %c %-30.30s: buffers %7u (live %5u,dec %5u,dis %5u,res %5u,"
440           "cor %5u,mar %5u,hdr %5u,gap %5u,drop %5u,dlt %5u),",
441           (stats->dir == GST_PAD_SRC) ? '>' : '<', fullname, stats->num_buffers,
442           stats->num_live, stats->num_decode_only, stats->num_discont,
443           stats->num_resync, stats->num_corrupted, stats->num_marker,
444           stats->num_header, stats->num_gap, stats->num_droppable,
445           stats->num_delta);
446       if (stats->min_size == stats->max_size) {
447         printf (" size (min/avg/max) ......./%7u/.......,", stats->avg_size);
448       } else {
449         printf (" size (min/avg/max) %7u/%7u/%7u,",
450             stats->min_size, stats->avg_size, stats->max_size);
451       }
452       printf (" time %" GST_TIME_FORMAT ","
453           " bytes/sec %lf\n",
454           GST_TIME_ARGS (running),
455           ((gdouble) (stats->num_buffers * stats->avg_size) * GST_SECOND) /
456           ((gdouble) running));
457     }
458   }
459 }
460
461 static void
462 print_thread_stats (gpointer key, gpointer value, gpointer user_data)
463 {
464   GSList *list = user_data;
465   GSList *node = g_slist_find_custom (list, key, find_pad_stats_for_thread);
466   GstThreadStats *stats = (GstThreadStats *) value;
467
468   /* skip stats if there are no pads for that thread (e.g. a pipeline) */
469   if (!node)
470     return;
471
472   printf ("Thread %p Statistics:\n", key);
473   if (GST_CLOCK_TIME_IS_VALID (stats->tthread)) {
474     printf ("  Time: %" GST_TIME_FORMAT "\n", GST_TIME_ARGS (stats->tthread));
475     printf ("  Avg CPU load: %4.1f %%\n", (gfloat) stats->cpuload / 10.0);
476   }
477
478   puts ("  Pad Statistics:");
479   g_slist_foreach (node, print_pad_stats, key);
480 }
481
482 static void
483 print_element_stats (gpointer value, gpointer user_data)
484 {
485   GstElementStats *stats = (GstElementStats *) value;
486
487   /* skip temporary elements */
488   if (stats->first_ts != GST_CLOCK_TIME_NONE) {
489     gchar fullname[45 + 1];
490
491     g_snprintf (fullname, 45, "%s:%s", stats->type_name, stats->name);
492
493     printf ("  %-45s:", fullname);
494     if (stats->recv_buffers)
495       printf (" buffers in/out %7u", stats->recv_buffers);
496     else
497       printf (" buffers in/out %7s", "-");
498     if (stats->sent_buffers)
499       printf ("/%7u", stats->sent_buffers);
500     else
501       printf ("/%7s", "-");
502     if (stats->recv_bytes)
503       printf (" bytes in/out %12" G_GUINT64_FORMAT, stats->recv_bytes);
504     else
505       printf (" bytes in/out %12s", "-");
506     if (stats->sent_bytes)
507       printf ("/%12" G_GUINT64_FORMAT, stats->sent_bytes);
508     else
509       printf ("/%12s", "-");
510     printf (" first activity %" GST_TIME_FORMAT ", "
511         " ev/msg/qry sent %5u/%5u/%5u\n", GST_TIME_ARGS (stats->first_ts),
512         stats->num_events, stats->num_messages, stats->num_queries);
513   }
514 }
515
516 static void
517 accum_element_stats (gpointer value, gpointer user_data)
518 {
519   GstElementStats *stats = (GstElementStats *) value;
520
521   if (stats->parent_ix != G_MAXUINT) {
522     GstElementStats *parent_stats = get_element_stats (stats->parent_ix);
523
524     parent_stats->num_events += stats->num_events;
525     parent_stats->num_messages += stats->num_messages;
526     parent_stats->num_queries += stats->num_queries;
527     if (!GST_CLOCK_TIME_IS_VALID (parent_stats->first_ts)) {
528       parent_stats->first_ts = stats->first_ts;
529     } else if (GST_CLOCK_TIME_IS_VALID (stats->first_ts)) {
530       parent_stats->first_ts = MIN (parent_stats->first_ts, stats->first_ts);
531     }
532     if (!GST_CLOCK_TIME_IS_VALID (parent_stats->last_ts)) {
533       parent_stats->last_ts = stats->last_ts;
534     } else if (GST_CLOCK_TIME_IS_VALID (stats->last_ts)) {
535       parent_stats->last_ts = MAX (parent_stats->last_ts, stats->last_ts);
536     }
537   }
538 }
539
540 /* sorting */
541
542 static gint
543 sort_pad_stats_by_first_activity (gconstpointer ps1, gconstpointer ps2)
544 {
545   GstPadStats *s1 = (GstPadStats *) ps1;
546   GstPadStats *s2 = (GstPadStats *) ps2;
547
548   gint order = GST_CLOCK_DIFF (s2->first_ts, s1->first_ts);
549
550   if (!order) {
551     order = s1->dir - s2->dir;
552   }
553   return (order);
554 }
555
556 static void
557 sort_pad_stats (gpointer value, gpointer user_data)
558 {
559   GSList **list = user_data;
560
561   *list =
562       g_slist_insert_sorted (*list, value, sort_pad_stats_by_first_activity);
563 }
564
565 static gint
566 sort_element_stats_by_first_activity (gconstpointer es1, gconstpointer es2)
567 {
568   return (GST_CLOCK_DIFF (((GstElementStats *) es2)->first_ts,
569           ((GstElementStats *) es1)->first_ts));
570 }
571
572 static void
573 sort_bin_stats (gpointer value, gpointer user_data)
574 {
575   if (((GstElementStats *) value)->is_bin) {
576     GSList **list = user_data;
577
578     *list =
579         g_slist_insert_sorted (*list, value,
580         sort_element_stats_by_first_activity);
581   }
582 }
583
584 static void
585 sort_element_stats (gpointer value, gpointer user_data)
586 {
587   if (!(((GstElementStats *) value)->is_bin)) {
588     GSList **list = user_data;
589
590     *list =
591         g_slist_insert_sorted (*list, value,
592         sort_element_stats_by_first_activity);
593   }
594 }
595
596 static gboolean
597 check_bin_parent (gpointer key, gpointer value, gpointer user_data)
598 {
599   GstElementStats *stats = (GstElementStats *) value;
600
601   return (stats->parent_ix == GPOINTER_TO_UINT (user_data));
602 }
603
604 static gboolean
605 process_leaf_bins (gpointer key, gpointer value, gpointer user_data)
606 {
607   GHashTable *accum_bins = user_data;
608
609   /* if we find no bin that has this bin as a parent ... */
610   if (!g_hash_table_find (accum_bins, check_bin_parent, key)) {
611     /* accumulate stats to the parent and remove */
612     accum_element_stats (value, NULL);
613     return TRUE;
614   }
615   return FALSE;
616 }
617
618 /* main */
619
620 static gboolean
621 init (void)
622 {
623   /* compile the parser regexps */
624   /* 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" */
625   raw_log = g_regex_new (
626       /* 1: ts */
627       "^([0-9:.]+) +"
628       /* 2: pid */
629       "([0-9]+) +"
630       /* 3: thread */
631       "(0x[0-9a-fA-F]+) +"
632       /* 4: level */
633       "([A-Z]+) +"
634       /* 5: category */
635       "([a-zA-Z_-]+) +"
636       /* 6: file:line:func: */
637       "([^:]+:[0-9]+:[^:]+:)"
638       /* 7: (obj)? log-text */
639       "(.*)$", 0, 0, NULL);
640   if (!raw_log) {
641     GST_WARNING ("failed to compile the 'raw' parser");
642     return FALSE;
643   }
644
645   ansi_log = g_regex_new (
646       /* 1: ts */
647       "^([0-9:.]+) +"
648       /* 2: pid */
649       "\\\e\\\[[0-9;]+m *([0-9]+)\\\e\\\[00m +"
650       /* 3: thread */
651       "(0x[0-9a-fA-F]+) +"
652       /* 4: level */
653       "(?:\\\e\\\[[0-9;]+m)?([A-Z]+) +\\\e\\\[00m +"
654       /* 5: category */
655       "\\\e\\\[[0-9;]+m +([a-zA-Z_-]+) +"
656       /* 6: file:line:func: */
657       "([^:]+:[0-9]+:[^:]+:)(?:\\\e\\\[00m)?"
658       /* 7: (obj)? log-text */
659       "(.*)$", 0, 0, NULL);
660   if (!raw_log) {
661     GST_WARNING ("failed to compile the 'ansi' parser");
662     return FALSE;
663   }
664
665   elements = g_ptr_array_new_with_free_func (free_element_stats);
666   pads = g_ptr_array_new_with_free_func (free_pad_stats);
667   threads = g_hash_table_new_full (NULL, NULL, NULL, free_thread_stats);
668
669   return TRUE;
670 }
671
672 static void
673 done (void)
674 {
675   if (pads)
676     g_ptr_array_free (pads, TRUE);
677   if (elements)
678     g_ptr_array_free (elements, TRUE);
679   if (threads)
680     g_hash_table_destroy (threads);
681
682   if (raw_log)
683     g_regex_unref (raw_log);
684   if (ansi_log)
685     g_regex_unref (ansi_log);
686 }
687
688 static void
689 print_stats (void)
690 {
691   guint num_threads = g_hash_table_size (threads);
692
693   /* print overall stats */
694   puts ("\nOverall Statistics:");
695   printf ("Number of Threads: %u\n", num_threads);
696   printf ("Number of Elements: %u\n", num_elements - num_bins);
697   printf ("Number of Bins: %u\n", num_bins);
698   printf ("Number of Pads: %u\n", num_pads - num_ghostpads);
699   printf ("Number of GhostPads: %u\n", num_ghostpads);
700   printf ("Number of Buffers passed: %" G_GUINT64_FORMAT "\n", num_buffers);
701   printf ("Number of Events sent: %" G_GUINT64_FORMAT "\n", num_events);
702   printf ("Number of Message sent: %" G_GUINT64_FORMAT "\n", num_messages);
703   printf ("Number of Queries sent: %" G_GUINT64_FORMAT "\n", num_queries);
704   printf ("Time: %" GST_TIME_FORMAT "\n", GST_TIME_ARGS (last_ts));
705   if (have_cpuload) {
706     printf ("Avg CPU load: %4.1f %%\n", (gfloat) total_cpuload / 10.0);
707   }
708   puts ("");
709
710   /* thread stats */
711   if (num_threads) {
712     GSList *list = NULL;
713
714     g_ptr_array_foreach (pads, sort_pad_stats, &list);
715     g_hash_table_foreach (threads, print_thread_stats, list);
716     puts ("");
717     g_slist_free (list);
718   }
719
720   /* element stats */
721   if (num_elements) {
722     GSList *list = NULL;
723
724     puts ("Element Statistics:");
725     /* sort by first_activity */
726     g_ptr_array_foreach (elements, sort_element_stats, &list);
727     /* attribute element stats to bins */
728     g_slist_foreach (list, accum_element_stats, NULL);
729     g_slist_foreach (list, print_element_stats, NULL);
730     puts ("");
731     g_slist_free (list);
732   }
733
734   /* bin stats */
735   if (num_bins) {
736     GSList *list = NULL;
737     guint i;
738     GHashTable *accum_bins = g_hash_table_new_full (NULL, NULL, NULL, NULL);
739
740     puts ("Bin Statistics:");
741     /* attribute bin stats to parent-bins */
742     for (i = 0; i < num_elements; i++) {
743       GstElementStats *stats = g_ptr_array_index (elements, i);
744       if (stats->is_bin) {
745         g_hash_table_insert (accum_bins, GUINT_TO_POINTER (i), stats);
746       }
747     }
748     while (g_hash_table_size (accum_bins)) {
749       g_hash_table_foreach_remove (accum_bins, process_leaf_bins, accum_bins);
750     }
751     g_hash_table_destroy (accum_bins);
752     /* sort by first_activity */
753     g_ptr_array_foreach (elements, sort_bin_stats, &list);
754     g_slist_foreach (list, print_element_stats, NULL);
755     puts ("");
756     g_slist_free (list);
757   }
758 }
759
760 static void
761 collect_stats (const gchar * filename)
762 {
763   FILE *log;
764
765   if ((log = fopen (filename, "rt"))) {
766     gchar line[5001];
767
768     /* probe format */
769     if (fgets (line, 5000, log)) {
770       GMatchInfo *match_info;
771       GRegex *parser;
772       GstStructure *s;
773       guint lnr = 0;
774       gchar *level, *data;
775
776       if (strchr (line, 27)) {
777         parser = ansi_log;
778         GST_INFO ("format is 'ansi'");
779       } else {
780         parser = raw_log;
781         GST_INFO ("format is 'raw'");
782       }
783       rewind (log);
784
785       /* parse the log */
786       while (!feof (log)) {
787         if (fgets (line, 5000, log)) {
788           if (g_regex_match (parser, line, 0, &match_info)) {
789             /* filter by level */
790             level = g_match_info_fetch (match_info, 4);
791             if (!strcmp (level, "TRACE")) {
792               data = g_match_info_fetch (match_info, 7);
793               if ((s = gst_structure_from_string (data, NULL))) {
794                 const gchar *name = gst_structure_get_name (s);
795
796                 if (!strcmp (name, "new-pad")) {
797                   new_pad_stats (s);
798                 } else if (!strcmp (name, "new-element")) {
799                   new_element_stats (s);
800                 } else if (!strcmp (name, "buffer")) {
801                   do_buffer_stats (s);
802                 } else if (!strcmp (name, "event")) {
803                   do_event_stats (s);
804                 } else if (!strcmp (name, "message")) {
805                   do_message_stats (s);
806                 } else if (!strcmp (name, "query")) {
807                   do_query_stats (s);
808                 } else if (!strcmp (name, "thread-rusage")) {
809                   do_thread_rusage_stats (s);
810                 } else if (!strcmp (name, "proc-rusage")) {
811                   do_proc_rusage_stats (s);
812                 } else {
813                   // TODO(ensonic): parse the xxx.class log lines
814                   if (!g_str_has_suffix (data, ".class")) {
815                     GST_WARNING ("unknown log entry: '%s'", data);
816                   }
817                 }
818                 gst_structure_free (s);
819               } else {
820                 GST_WARNING ("unknown log entry: '%s'", data);
821               }
822             }
823           } else {
824             if (*line) {
825               GST_WARNING ("foreign log entry: %s:%d:'%s'", filename, lnr,
826                   g_strchomp (line));
827             }
828           }
829           g_match_info_free (match_info);
830           match_info = NULL;
831           lnr++;
832         } else {
833           if (!feof (log)) {
834             // TODO(ensonic): run wc -L on the log file
835             fprintf (stderr, "line too long");
836           }
837         }
838       }
839       fclose (log);
840     } else {
841       GST_WARNING ("empty log");
842     }
843   }
844 }
845
846 gint
847 main (gint argc, gchar * argv[])
848 {
849   gchar **filenames = NULL;
850   guint num;
851   GError *err = NULL;
852   GOptionContext *ctx;
853   GOptionEntry options[] = {
854     GST_TOOLS_GOPTION_VERSION,
855     // TODO(ensonic): add a summary flag, if set read the whole thing, print
856     // stats once, and exit
857     {G_OPTION_REMAINING, 0, 0, G_OPTION_ARG_FILENAME_ARRAY, &filenames, NULL}
858     ,
859     {NULL}
860   };
861
862 #ifdef ENABLE_NLS
863   bindtextdomain (GETTEXT_PACKAGE, LOCALEDIR);
864   bind_textdomain_codeset (GETTEXT_PACKAGE, "UTF-8");
865   textdomain (GETTEXT_PACKAGE);
866 #endif
867
868   g_set_prgname ("gst-stats-" GST_API_VERSION);
869
870   ctx = g_option_context_new ("FILE");
871   g_option_context_add_main_entries (ctx, options, GETTEXT_PACKAGE);
872   g_option_context_add_group (ctx, gst_init_get_option_group ());
873   if (!g_option_context_parse (ctx, &argc, &argv, &err)) {
874     g_print ("Error initializing: %s\n", GST_STR_NULL (err->message));
875     exit (1);
876   }
877   g_option_context_free (ctx);
878
879   gst_tools_print_version ();
880
881   if (filenames == NULL || *filenames == NULL) {
882     g_print ("Please give one filename to %s\n\n", g_get_prgname ());
883     return 1;
884   }
885   num = g_strv_length (filenames);
886   if (num == 0 || num > 1) {
887     g_print ("Please give exactly one filename to %s (%d given).\n\n",
888         g_get_prgname (), num);
889     return 1;
890   }
891
892   if (init ()) {
893     collect_stats (filenames[0]);
894     print_stats ();
895   }
896   done ();
897
898   g_strfreev (filenames);
899   return 0;
900 }