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