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