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