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 GstClockTime tusersys = G_GUINT64_CONSTANT (0);
  45 static guint64 total_cpuload = 0;
  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   /* time spend in this element */
  81   GstClockTime treal;
  82   /* hierarchy */
  83   guint parent_ix;
  84 } GstElementStats;
  85
  86 typedef struct
  87 {
  88   /* time spend in this thread */
  89   GstClockTime treal;
  90 } GstThreadStats;
  91
  92 /* stats helper */
  93
  94 static void
  95 free_element_stats (gpointer data)
  96 {
  97   g_slice_free (GstElementStats, data);
  98 }
  99
 100 static inline GstElementStats *
 101 get_element_stats (guint ix)
 102 {
 103   return (ix != G_MAXUINT) ? 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) ? g_ptr_array_index (pads, ix) : NULL;
 110 }
 111
 112 static void
 113 free_pad_stats (gpointer data)
 114 {
 115   g_slice_free (GstPadStats, data);
 116 }
 117
 118 static inline GstThreadStats *
 119 get_thread_stats (guint id)
 120 {
 121   GstThreadStats *stats = g_hash_table_lookup (threads, GUINT_TO_POINTER (id));
 122
 123   if (G_UNLIKELY (!stats)) {
 124     stats = g_slice_new0 (GstThreadStats);
 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 = 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 = 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 = 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 = 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_rusage_stats (GstStructure * s)
 383 {
 384   guint64 ts, treal;
 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       "cpuload", G_TYPE_UINT, &cpuload,
 391       "treal", G_TYPE_UINT64, &treal, "tsum", G_TYPE_UINT64, &tusersys, NULL);
 392   thread_stats = get_thread_stats (thread_id);
 393   thread_stats->treal = treal;
 394   last_ts = ts;
 395 }
 396
 397 /* reporting */
 398
 399 static gint
 400 find_pad_stats_for_thread (gconstpointer value, gconstpointer user_data)
 401 {
 402   const GstPadStats *stats = (const GstPadStats *) value;
 403
 404   if ((stats->thread_id == GPOINTER_TO_UINT (user_data)) &&
 405       (stats->num_buffers)) {
 406     return 0;
 407   }
 408   return 1;
 409 }
 410
 411 static void
 412 print_pad_stats (gpointer value, gpointer user_data)
 413 {
 414   GstPadStats *stats = (GstPadStats *) value;
 415
 416   if (stats->thread_id == GPOINTER_TO_UINT (user_data)) {
 417     /* there seem to be some temporary pads */
 418     if (stats->num_buffers) {
 419       GstClockTimeDiff running =
 420           GST_CLOCK_DIFF (stats->first_ts, stats->last_ts);
 421       GstElementStats *elem_stats = get_element_stats (stats->parent_ix);
 422       gchar fullname[30 + 1];
 423
 424       g_snprintf (fullname, 30, "%s.%s", elem_stats->name, stats->name);
 425
 426       printf
 427           ("    %c %-30.30s: buffers %7u (live %5u,dec %5u,dis %5u,res %5u,"
 428           "cor %5u,mar %5u,hdr %5u,gap %5u,drop %5u,dlt %5u),",
 429           (stats->dir == GST_PAD_SRC) ? '>' : '<', fullname, stats->num_buffers,
 430           stats->num_live, stats->num_decode_only, stats->num_discont,
 431           stats->num_resync, stats->num_corrupted, stats->num_marker,
 432           stats->num_header, stats->num_gap, stats->num_droppable,
 433           stats->num_delta);
 434       if (stats->min_size == stats->max_size) {
 435         printf (" size (min/avg/max) ......./%7u/.......,", stats->avg_size);
 436       } else {
 437         printf (" size (min/avg/max) %7u/%7u/%7u,",
 438             stats->min_size, stats->avg_size, stats->max_size);
 439       }
 440       printf (" time %" GST_TIME_FORMAT ","
 441           " bytes/sec %lf\n",
 442           GST_TIME_ARGS (running),
 443           ((gdouble) (stats->num_buffers * stats->avg_size) * GST_SECOND) /
 444           ((gdouble) running));
 445     }
 446   }
 447 }
 448
 449 static void
 450 print_thread_stats (gpointer key, gpointer value, gpointer user_data)
 451 {
 452   GSList *list = user_data;
 453   GSList *node = g_slist_find_custom (list, key, find_pad_stats_for_thread);
 454   GstThreadStats *stats = (GstThreadStats *) value;
 455   guint cpuload = 0;
 456   guint time_percent;
 457
 458   /* skip stats if there are no pads for that thread (e.g. a pipeline) */
 459   if (!node)
 460     return;
 461
 462   time_percent =
 463       (guint) gst_util_uint64_scale (stats->treal, G_GINT64_CONSTANT (100),
 464       last_ts);
 465
 466   if (total_cpuload) {
 467     cpuload =
 468         (guint) gst_util_uint64_scale (total_cpuload, stats->treal, last_ts);
 469   }
 470
 471   printf ("Thread %p Statistics:\n", key);
 472   printf ("  Time: %" GST_TIME_FORMAT ", %u %%\n", GST_TIME_ARGS (stats->treal),
 473       (guint) time_percent);
 474   printf ("  Avg CPU load: %u %%\n", cpuload);
 475
 476   puts ("  Pad Statistics:");
 477   g_slist_foreach (node, print_pad_stats, key);
 478 }
 479
 480 static void
 481 print_element_stats (gpointer value, gpointer user_data)
 482 {
 483   GstElementStats *stats = (GstElementStats *) value;
 484
 485   /* skip temporary elements */
 486   if (stats->first_ts != GST_CLOCK_TIME_NONE) {
 487     gchar fullname[45 + 1];
 488
 489     g_snprintf (fullname, 45, "%s:%s", stats->type_name, stats->name);
 490
 491     printf ("  %-45s:", fullname);
 492     if (stats->recv_buffers)
 493       printf (" buffers in/out %7u", stats->recv_buffers);
 494     else
 495       printf (" buffers in/out %7s", "-");
 496     if (stats->sent_buffers)
 497       printf ("/%7u", stats->sent_buffers);
 498     else
 499       printf ("/%7s", "-");
 500     if (stats->recv_bytes)
 501       printf (" bytes in/out %12" G_GUINT64_FORMAT, stats->recv_bytes);
 502     else
 503       printf (" bytes in/out %12s", "-");
 504     if (stats->sent_bytes)
 505       printf ("/%12" G_GUINT64_FORMAT, stats->sent_bytes);
 506     else
 507       printf ("/%12s", "-");
 508     printf (" first activity %" GST_TIME_FORMAT ", "
 509         " ev/msg/qry sent %5u/%5u/%5u\n", GST_TIME_ARGS (stats->first_ts),
 510         stats->num_events, stats->num_messages, stats->num_queries);
 511   }
 512 }
 513
 514 static void
 515 accum_element_stats (gpointer value, gpointer user_data)
 516 {
 517   GstElementStats *stats = (GstElementStats *) value;
 518
 519   if (stats->parent_ix != G_MAXUINT) {
 520     GstElementStats *parent_stats = get_element_stats (stats->parent_ix);
 521
 522     parent_stats->num_events += stats->num_events;
 523     parent_stats->num_messages += stats->num_messages;
 524     parent_stats->num_queries += stats->num_queries;
 525     if (!GST_CLOCK_TIME_IS_VALID (parent_stats->first_ts)) {
 526       parent_stats->first_ts = stats->first_ts;
 527     } else if (GST_CLOCK_TIME_IS_VALID (stats->first_ts)) {
 528       parent_stats->first_ts = MIN (parent_stats->first_ts, stats->first_ts);
 529     }
 530     if (!GST_CLOCK_TIME_IS_VALID (parent_stats->last_ts)) {
 531       parent_stats->last_ts = stats->last_ts;
 532     } else if (GST_CLOCK_TIME_IS_VALID (stats->last_ts)) {
 533       parent_stats->last_ts = MAX (parent_stats->last_ts, stats->last_ts);
 534     }
 535   }
 536 }
 537
 538 /* sorting */
 539
 540 static gint
 541 sort_pad_stats_by_first_activity (gconstpointer ps1, gconstpointer ps2)
 542 {
 543   GstPadStats *s1 = (GstPadStats *) ps1;
 544   GstPadStats *s2 = (GstPadStats *) ps2;
 545
 546   gint order = GST_CLOCK_DIFF (s2->first_ts, s1->first_ts);
 547
 548   if (!order) {
 549     order = s1->dir - s2->dir;
 550   }
 551   return (order);
 552 }
 553
 554 static void
 555 sort_pad_stats (gpointer value, gpointer user_data)
 556 {
 557   GSList **list = user_data;
 558
 559   *list =
 560       g_slist_insert_sorted (*list, value, sort_pad_stats_by_first_activity);
 561 }
 562
 563 static gint
 564 sort_element_stats_by_first_activity (gconstpointer es1, gconstpointer es2)
 565 {
 566   return (GST_CLOCK_DIFF (((GstElementStats *) es2)->first_ts,
 567           ((GstElementStats *) es1)->first_ts));
 568 }
 569
 570 static void
 571 sort_bin_stats (gpointer value, gpointer user_data)
 572 {
 573   if (((GstElementStats *) value)->is_bin) {
 574     GSList **list = user_data;
 575
 576     *list =
 577         g_slist_insert_sorted (*list, value,
 578         sort_element_stats_by_first_activity);
 579   }
 580 }
 581
 582 static void
 583 sort_element_stats (gpointer value, gpointer user_data)
 584 {
 585   if (!(((GstElementStats *) value)->is_bin)) {
 586     GSList **list = user_data;
 587
 588     *list =
 589         g_slist_insert_sorted (*list, value,
 590         sort_element_stats_by_first_activity);
 591   }
 592 }
 593
 594 static gboolean
 595 check_bin_parent (gpointer key, gpointer value, gpointer user_data)
 596 {
 597   GstElementStats *stats = (GstElementStats *) value;
 598
 599   return (stats->parent_ix == GPOINTER_TO_UINT (user_data));
 600 }
 601
 602 static gboolean
 603 process_leaf_bins (gpointer key, gpointer value, gpointer user_data)
 604 {
 605   GHashTable *accum_bins = user_data;
 606
 607   /* if we find no bin that has this bin as a parent ... */
 608   if (!g_hash_table_find (accum_bins, check_bin_parent, key)) {
 609     /* accumulate stats to the parent and remove */
 610     accum_element_stats (value, NULL);
 611     return TRUE;
 612   }
 613   return FALSE;
 614 }
 615
 616 /* main */
 617
 618 static gboolean
 619 init (void)
 620 {
 621   /* compile the parser regexps */
 622   /* 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" */
 623   raw_log = g_regex_new (
 624       /* 1: ts */
 625       "^([0-9:.]+) +"
 626       /* 2: pid */
 627       "([0-9]+) +"
 628       /* 3: thread */
 629       "(0x[0-9a-fA-F]+) +"
 630       /* 4: level */
 631       "([A-Z]+) +"
 632       /* 5: category */
 633       "([a-zA-Z_-]+) +"
 634       /* 6: file:line:func: */
 635       "([^:]+:[0-9]+:[^:]+:)"
 636       /* 7: (obj)? log-text */
 637       "(.*)$", 0, 0, NULL);
 638   if (!raw_log) {
 639     GST_WARNING ("failed to compile the 'raw' parser");
 640     return FALSE;
 641   }
 642
 643   ansi_log = g_regex_new (
 644       /* 1: ts */
 645       "^([0-9:.]+) +"
 646       /* 2: pid */
 647       "\\\e\\\[[0-9;]+m *([0-9]+)\\\e\\\[00m +"
 648       /* 3: thread */
 649       "(0x[0-9a-fA-F]+) +"
 650       /* 4: level */
 651       "(?:\\\e\\\[[0-9;]+m)?([A-Z]+) +\\\e\\\[00m +"
 652       /* 5: category */
 653       "\\\e\\\[[0-9;]+m +([a-zA-Z_-]+) +"
 654       /* 6: file:line:func: */
 655       "([^:]+:[0-9]+:[^:]+:)(?:\\\e\\\[00m)?"
 656       /* 7: (obj)? log-text */
 657       "(.*)$", 0, 0, NULL);
 658   if (!raw_log) {
 659     GST_WARNING ("failed to compile the 'ansi' parser");
 660     return FALSE;
 661   }
 662
 663   elements = g_ptr_array_new_with_free_func (free_element_stats);
 664   pads = g_ptr_array_new_with_free_func (free_pad_stats);
 665   threads = g_hash_table_new_full (NULL, NULL, NULL, free_thread_stats);
 666
 667   return TRUE;
 668 }
 669
 670 static void
 671 done (void)
 672 {
 673   if (pads)
 674     g_ptr_array_free (pads, TRUE);
 675   if (elements)
 676     g_ptr_array_free (elements, TRUE);
 677   if (threads)
 678     g_hash_table_destroy (threads);
 679
 680   if (raw_log)
 681     g_regex_unref (raw_log);
 682   if (ansi_log)
 683     g_regex_unref (ansi_log);
 684 }
 685
 686 static void
 687 print_stats (void)
 688 {
 689   guint num_threads = g_hash_table_size (threads);
 690
 691   /* print overall stats */
 692   puts ("\nOverall Statistics:");
 693   printf ("Number of Threads: %u\n", num_threads);
 694   printf ("Number of Elements: %u\n", num_elements - num_bins);
 695   printf ("Number of Bins: %u\n", num_bins);
 696   printf ("Number of Pads: %u\n", num_pads - num_ghostpads);
 697   printf ("Number of GhostPads: %u\n", num_ghostpads);
 698   printf ("Number of Buffers passed: %" G_GUINT64_FORMAT "\n", num_buffers);
 699   printf ("Number of Events sent: %" G_GUINT64_FORMAT "\n", num_events);
 700   printf ("Number of Message sent: %" G_GUINT64_FORMAT "\n", num_messages);
 701   printf ("Number of Queries sent: %" G_GUINT64_FORMAT "\n", num_queries);
 702   printf ("Time: %" GST_TIME_FORMAT "\n", GST_TIME_ARGS (last_ts));
 703   if (tusersys) {
 704     total_cpuload = gst_util_uint64_scale (tusersys,
 705         G_GINT64_CONSTANT (100), last_ts);
 706     printf ("Avg CPU load: %u %%\n", (guint) total_cpuload);
 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                 // TODO(ensonic): add a function for each name-id quark
 797                 // these function will do the actual stats tracking
 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, "rusage")) {
 811                   do_rusage_stats (s);
 812                 } else {
 813                   GST_WARNING ("unknown log entry: '%s'", data);
 814                 }
 815                 gst_structure_free (s);
 816               } else {
 817                 GST_WARNING ("unknown log entry: '%s'", data);
 818               }
 819             }
 820           } else {
 821             if (*line) {
 822               GST_WARNING ("foreign log entry: %s:%d:'%s'", filename, lnr,
 823                   g_strchomp (line));
 824             }
 825           }
 826           g_match_info_free (match_info);
 827           match_info = NULL;
 828           lnr++;
 829         } else {
 830           if (!feof (log)) {
 831             // TODO(ensonic): run wc -L on the log file
 832             fprintf (stderr, "line too long");
 833           }
 834         }
 835       }
 836       fclose (log);
 837     } else {
 838       GST_WARNING ("empty log");
 839     }
 840   }
 841 }
 842
 843 gint
 844 main (gint argc, gchar * argv[])
 845 {
 846   gchar **filenames = NULL;
 847   guint num;
 848   GError *err = NULL;
 849   GOptionContext *ctx;
 850   GOptionEntry options[] = {
 851     GST_TOOLS_GOPTION_VERSION,
 852     // TODO(ensonic): add a summary flag, if set read the whole thing, print
 853     // stats once, and exit
 854     {G_OPTION_REMAINING, 0, 0, G_OPTION_ARG_FILENAME_ARRAY, &filenames, NULL}
 855     ,
 856     {NULL}
 857   };
 858
 859 #ifdef ENABLE_NLS
 860   bindtextdomain (GETTEXT_PACKAGE, LOCALEDIR);
 861   bind_textdomain_codeset (GETTEXT_PACKAGE, "UTF-8");
 862   textdomain (GETTEXT_PACKAGE);
 863 #endif
 864
 865   g_set_prgname ("gst-stats-" GST_API_VERSION);
 866
 867   ctx = g_option_context_new ("FILE");
 868   g_option_context_add_main_entries (ctx, options, GETTEXT_PACKAGE);
 869   g_option_context_add_group (ctx, gst_init_get_option_group ());
 870   if (!g_option_context_parse (ctx, &argc, &argv, &err)) {
 871     g_print ("Error initializing: %s\n", GST_STR_NULL (err->message));
 872     exit (1);
 873   }
 874   g_option_context_free (ctx);
 875
 876   gst_tools_print_version ();
 877
 878   if (filenames == NULL || *filenames == NULL) {
 879     g_print ("Please give one filename to %s\n\n", g_get_prgname ());
 880     return 1;
 881   }
 882   num = g_strv_length (filenames);
 883   if (num == 0 || num > 1) {
 884     g_print ("Please give exactly one filename to %s (%d given).\n\n",
 885         g_get_prgname (), num);
 886     return 1;
 887   }
 888
 889   if (init ()) {
 890     collect_stats (filenames[0]);
 891     print_stats ();
 892   }
 893   done ();
 894
 895   g_strfreev (filenames);
 896   return 0;
 897 }