"Fossies" - the Fresh Open Source Software Archive

Member "gstreamer-1.16.1/tools/gst-stats.c" (19 Apr 2019, 32244 Bytes) of package /linux/misc/gstreamer-1.16.1.tar.xz:


As a special service "Fossies" has tried to format the requested source page into HTML format using (guessed) C and C++ source code syntax highlighting (style: standard) with prefixed line numbers and code folding option. Alternatively you can here view or download the uninterpreted source code file. For more information about "gst-stats.c" see the Fossies "Dox" file reference documentation and the last Fossies "Diffs" side-by-side code changes report: 1.14.4_vs_1.16.0.

    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 GHashTable *latencies = NULL;
   41 static GHashTable *element_latencies = NULL;
   42 static GQueue *element_reported_latencies = NULL;
   43 static guint64 num_buffers = 0, num_events = 0, num_messages = 0, num_queries =
   44     0;
   45 static guint num_elements = 0, num_bins = 0, num_pads = 0, num_ghostpads = 0;
   46 static GstClockTime last_ts = G_GUINT64_CONSTANT (0);
   47 static guint total_cpuload = 0;
   48 static gboolean have_cpuload = FALSE;
   49 
   50 static gboolean have_latency = FALSE;
   51 static gboolean have_element_latency = FALSE;
   52 static gboolean have_element_reported_latency = FALSE;
   53 
   54 typedef struct
   55 {
   56   /* the number of latencies counted  */
   57   guint64 count;
   58   /* the total of all latencies */
   59   guint64 total;
   60   /* the min of all latencies */
   61   guint64 min;
   62   /* the max of all latencies */
   63   guint64 max;
   64 } GstLatencyStats;
   65 
   66 typedef struct
   67 {
   68   /* The element name */
   69   gchar *element;
   70   /* The timestamp of the reported latency */
   71   guint64 ts;
   72   /* the min reported latency */
   73   guint64 min;
   74   /* the max reported latency */
   75   guint64 max;
   76 } GstReportedLatency;
   77 
   78 typedef struct
   79 {
   80   /* human readable pad name and details */
   81   gchar *name, *type_name;
   82   guint index;
   83   gboolean is_ghost_pad;
   84   GstPadDirection dir;
   85   /* buffer statistics */
   86   guint num_buffers;
   87   guint num_live, num_decode_only, num_discont, num_resync, num_corrupted,
   88       num_marker, num_header, num_gap, num_droppable, num_delta;
   89   guint min_size, max_size, avg_size;
   90   /* first and last activity on the pad, expected next_ts */
   91   GstClockTime first_ts, last_ts, next_ts;
   92   /* in which thread does it operate */
   93   gpointer thread_id;
   94   /* hierarchy */
   95   guint parent_ix;
   96 } GstPadStats;
   97 
   98 typedef struct
   99 {
  100   /* human readable element name */
  101   gchar *name, *type_name;
  102   guint index;
  103   gboolean is_bin;
  104   /* buffer statistics */
  105   guint recv_buffers, sent_buffers;
  106   guint64 recv_bytes, sent_bytes;
  107   /* event, message statistics */
  108   guint num_events, num_messages, num_queries;
  109   /* first activity on the element */
  110   GstClockTime first_ts, last_ts;
  111   /* hierarchy */
  112   guint parent_ix;
  113 } GstElementStats;
  114 
  115 typedef struct
  116 {
  117   /* time spend in this thread */
  118   GstClockTime tthread;
  119   guint cpuload;
  120 } GstThreadStats;
  121 
  122 /* stats helper */
  123 
  124 static void
  125 latencies_foreach_print_stats (gchar * key, GstLatencyStats * ls, gpointer data)
  126 {
  127   printf ("\t%s: mean=%" G_GUINT64_FORMAT " min=%" G_GUINT64_FORMAT " max=%"
  128       G_GUINT64_FORMAT "\n", key, ls->total / ls->count, ls->min, ls->max);
  129 }
  130 
  131 static void
  132 reported_latencies_foreach_print_stats (GstReportedLatency * rl, gpointer data)
  133 {
  134   printf ("\t%s: min=%" G_GUINT64_FORMAT " max=%" G_GUINT64_FORMAT " ts=%"
  135       GST_TIME_FORMAT "\n", rl->element, rl->min,
  136       rl->max, GST_TIME_ARGS (rl->ts));
  137 }
  138 
  139 static void
  140 free_latency_stats (gpointer data)
  141 {
  142   g_slice_free (GstLatencyStats, data);
  143 }
  144 
  145 static void
  146 free_reported_latency (gpointer data)
  147 {
  148   GstReportedLatency *rl = data;
  149 
  150   if (rl->element)
  151     g_free (rl->element);
  152 
  153   g_free (data);
  154 }
  155 
  156 static void
  157 free_element_stats (gpointer data)
  158 {
  159   g_slice_free (GstElementStats, data);
  160 }
  161 
  162 static inline GstElementStats *
  163 get_element_stats (guint ix)
  164 {
  165   return (ix != G_MAXUINT && ix < elements->len) ?
  166       g_ptr_array_index (elements, ix) : NULL;
  167 }
  168 
  169 static inline GstPadStats *
  170 get_pad_stats (guint ix)
  171 {
  172   return (ix != G_MAXUINT && ix < pads->len) ?
  173       g_ptr_array_index (pads, ix) : NULL;
  174 }
  175 
  176 static void
  177 free_pad_stats (gpointer data)
  178 {
  179   g_slice_free (GstPadStats, data);
  180 }
  181 
  182 static inline GstThreadStats *
  183 get_thread_stats (gpointer id)
  184 {
  185   GstThreadStats *stats = g_hash_table_lookup (threads, id);
  186 
  187   if (G_UNLIKELY (!stats)) {
  188     stats = g_slice_new0 (GstThreadStats);
  189     stats->tthread = GST_CLOCK_TIME_NONE;
  190     g_hash_table_insert (threads, id, stats);
  191   }
  192   return stats;
  193 }
  194 
  195 static void
  196 new_pad_stats (GstStructure * s)
  197 {
  198   GstPadStats *stats;
  199   guint ix, parent_ix;
  200   gchar *type, *name;
  201   gboolean is_ghost_pad;
  202   GstPadDirection dir;
  203   guint64 thread_id;
  204 
  205   gst_structure_get (s,
  206       "ix", G_TYPE_UINT, &ix,
  207       "parent-ix", G_TYPE_UINT, &parent_ix,
  208       "name", G_TYPE_STRING, &name,
  209       "type", G_TYPE_STRING, &type,
  210       "is-ghostpad", G_TYPE_BOOLEAN, &is_ghost_pad,
  211       "pad-direction", GST_TYPE_PAD_DIRECTION, &dir,
  212       "thread-id", G_TYPE_UINT64, &thread_id, NULL);
  213 
  214   stats = g_slice_new0 (GstPadStats);
  215   if (is_ghost_pad)
  216     num_ghostpads++;
  217   num_pads++;
  218   stats->name = name;
  219   stats->type_name = type;
  220   stats->index = ix;
  221   stats->is_ghost_pad = is_ghost_pad;
  222   stats->dir = dir;
  223   stats->min_size = G_MAXUINT;
  224   stats->first_ts = stats->last_ts = stats->next_ts = GST_CLOCK_TIME_NONE;
  225   stats->thread_id = (gpointer) (guintptr) thread_id;
  226   stats->parent_ix = parent_ix;
  227 
  228   if (pads->len <= ix)
  229     g_ptr_array_set_size (pads, ix + 1);
  230   g_ptr_array_index (pads, ix) = stats;
  231 }
  232 
  233 static void
  234 new_element_stats (GstStructure * s)
  235 {
  236   GstElementStats *stats;
  237   guint ix, parent_ix;
  238   gchar *type, *name;
  239   gboolean is_bin;
  240 
  241   gst_structure_get (s,
  242       "ix", G_TYPE_UINT, &ix,
  243       "parent-ix", G_TYPE_UINT, &parent_ix,
  244       "name", G_TYPE_STRING, &name,
  245       "type", G_TYPE_STRING, &type, "is-bin", G_TYPE_BOOLEAN, &is_bin, NULL);
  246 
  247   stats = g_slice_new0 (GstElementStats);
  248   if (is_bin)
  249     num_bins++;
  250   num_elements++;
  251   stats->index = ix;
  252   stats->name = name;
  253   stats->type_name = type;
  254   stats->is_bin = is_bin;
  255   stats->first_ts = GST_CLOCK_TIME_NONE;
  256   stats->parent_ix = parent_ix;
  257 
  258   if (elements->len <= ix)
  259     g_ptr_array_set_size (elements, ix + 1);
  260   g_ptr_array_index (elements, ix) = stats;
  261 }
  262 
  263 static void
  264 free_thread_stats (gpointer data)
  265 {
  266   g_slice_free (GstThreadStats, data);
  267 }
  268 
  269 static void
  270 do_pad_stats (GstPadStats * stats, guint elem_ix, guint size, guint64 ts,
  271     guint64 buffer_ts, guint64 buffer_dur, GstBufferFlags buffer_flags)
  272 {
  273   gulong avg_size;
  274 
  275   /* parentage */
  276   if (stats->parent_ix == G_MAXUINT) {
  277     stats->parent_ix = elem_ix;
  278   }
  279 
  280   if (stats->thread_id) {
  281     get_thread_stats (stats->thread_id);
  282   }
  283 
  284   /* size stats */
  285   avg_size = (((gulong) stats->avg_size * (gulong) stats->num_buffers) + size);
  286   stats->num_buffers++;
  287   stats->avg_size = (guint) (avg_size / stats->num_buffers);
  288   if (size < stats->min_size)
  289     stats->min_size = size;
  290   else if (size > stats->max_size)
  291     stats->max_size = size;
  292   /* time stats */
  293   if (!GST_CLOCK_TIME_IS_VALID (stats->last_ts))
  294     stats->first_ts = ts;
  295   stats->last_ts = ts;
  296   /* flag stats */
  297   if (buffer_flags & GST_BUFFER_FLAG_LIVE)
  298     stats->num_live++;
  299   if (buffer_flags & GST_BUFFER_FLAG_DECODE_ONLY)
  300     stats->num_decode_only++;
  301   if (buffer_flags & GST_BUFFER_FLAG_DISCONT)
  302     stats->num_discont++;
  303   if (buffer_flags & GST_BUFFER_FLAG_RESYNC)
  304     stats->num_resync++;
  305   if (buffer_flags & GST_BUFFER_FLAG_CORRUPTED)
  306     stats->num_corrupted++;
  307   if (buffer_flags & GST_BUFFER_FLAG_MARKER)
  308     stats->num_marker++;
  309   if (buffer_flags & GST_BUFFER_FLAG_HEADER)
  310     stats->num_header++;
  311   if (buffer_flags & GST_BUFFER_FLAG_GAP)
  312     stats->num_gap++;
  313   if (buffer_flags & GST_BUFFER_FLAG_DROPPABLE)
  314     stats->num_droppable++;
  315   if (buffer_flags & GST_BUFFER_FLAG_DELTA_UNIT)
  316     stats->num_delta++;
  317   /* update timestamps */
  318   if (GST_CLOCK_TIME_IS_VALID (buffer_ts) &&
  319       GST_CLOCK_TIME_IS_VALID (buffer_dur)) {
  320     stats->next_ts = buffer_ts + buffer_dur;
  321   } else {
  322     stats->next_ts = GST_CLOCK_TIME_NONE;
  323   }
  324 }
  325 
  326 static void
  327 do_element_stats (GstElementStats * stats, GstElementStats * peer_stats,
  328     guint size, guint64 ts)
  329 {
  330   stats->sent_buffers++;
  331   peer_stats->recv_buffers++;
  332   stats->sent_bytes += size;
  333   peer_stats->recv_bytes += size;
  334   /* time stats */
  335   if (G_UNLIKELY (!GST_CLOCK_TIME_IS_VALID (stats->first_ts))) {
  336     stats->first_ts = ts;
  337   }
  338   if (G_UNLIKELY (!GST_CLOCK_TIME_IS_VALID (peer_stats->first_ts))) {
  339     peer_stats->first_ts = ts + 1;
  340   }
  341 }
  342 
  343 static void
  344 do_buffer_stats (GstStructure * s)
  345 {
  346   guint64 ts;
  347   guint64 buffer_pts = GST_CLOCK_TIME_NONE, buffer_dur = GST_CLOCK_TIME_NONE;
  348   guint pad_ix, elem_ix, peer_elem_ix;
  349   guint size;
  350   GstBufferFlags buffer_flags;
  351   GstPadStats *pad_stats;
  352   GstElementStats *elem_stats, *peer_elem_stats;
  353 
  354   num_buffers++;
  355   gst_structure_get (s, "ts", G_TYPE_UINT64, &ts,
  356       "pad-ix", G_TYPE_UINT, &pad_ix,
  357       "element-ix", G_TYPE_UINT, &elem_ix,
  358       "peer-element-ix", G_TYPE_UINT, &peer_elem_ix,
  359       "buffer-size", G_TYPE_UINT, &size,
  360       "buffer-flags", GST_TYPE_BUFFER_FLAGS, &buffer_flags, NULL);
  361   gst_structure_get_uint64 (s, "buffer-pts", &buffer_pts);
  362   gst_structure_get_uint64 (s, "buffer-duration", &buffer_dur);
  363   last_ts = MAX (last_ts, ts);
  364   if (!(pad_stats = get_pad_stats (pad_ix))) {
  365     GST_WARNING ("no pad stats found for ix=%u", pad_ix);
  366     return;
  367   }
  368   if (!(elem_stats = get_element_stats (elem_ix))) {
  369     GST_WARNING ("no element stats found for ix=%u", elem_ix);
  370     return;
  371   }
  372   if (!(peer_elem_stats = get_element_stats (peer_elem_ix))) {
  373     GST_WARNING ("no element stats found for ix=%u", peer_elem_ix);
  374     return;
  375   }
  376   do_pad_stats (pad_stats, elem_ix, size, ts, buffer_pts, buffer_dur,
  377       buffer_flags);
  378   if (pad_stats->dir == GST_PAD_SRC) {
  379     /* push */
  380     do_element_stats (elem_stats, peer_elem_stats, size, ts);
  381   } else {
  382     /* pull */
  383     do_element_stats (peer_elem_stats, elem_stats, size, ts);
  384   }
  385 }
  386 
  387 static void
  388 do_event_stats (GstStructure * s)
  389 {
  390   guint64 ts;
  391   guint pad_ix, elem_ix;
  392   GstPadStats *pad_stats;
  393   GstElementStats *elem_stats;
  394 
  395   num_events++;
  396   gst_structure_get (s, "ts", G_TYPE_UINT64, &ts,
  397       "pad-ix", G_TYPE_UINT, &pad_ix, "element-ix", G_TYPE_UINT, &elem_ix,
  398       NULL);
  399   last_ts = MAX (last_ts, ts);
  400   if (!(pad_stats = get_pad_stats (pad_ix))) {
  401     GST_WARNING ("no pad stats found for ix=%u", pad_ix);
  402     return;
  403   }
  404   if (!(elem_stats = get_element_stats (elem_ix))) {
  405     // e.g. reconfigure events are send over unparented pads
  406     GST_INFO ("no element stats found for ix=%u", elem_ix);
  407     return;
  408   }
  409   elem_stats->num_events++;
  410 }
  411 
  412 static void
  413 do_message_stats (GstStructure * s)
  414 {
  415   guint64 ts;
  416   guint elem_ix;
  417   GstElementStats *elem_stats;
  418 
  419   num_messages++;
  420   gst_structure_get (s, "ts", G_TYPE_UINT64, &ts,
  421       "element-ix", G_TYPE_UINT, &elem_ix, NULL);
  422   last_ts = MAX (last_ts, ts);
  423   if (!(elem_stats = get_element_stats (elem_ix))) {
  424     GST_WARNING ("no element stats found for ix=%u", elem_ix);
  425     return;
  426   }
  427   elem_stats->num_messages++;
  428 }
  429 
  430 static void
  431 do_query_stats (GstStructure * s)
  432 {
  433   guint64 ts;
  434   guint elem_ix;
  435   GstElementStats *elem_stats;
  436 
  437   num_queries++;
  438   gst_structure_get (s, "ts", G_TYPE_UINT64, &ts,
  439       "element-ix", G_TYPE_UINT, &elem_ix, NULL);
  440   last_ts = MAX (last_ts, ts);
  441   if (!(elem_stats = get_element_stats (elem_ix))) {
  442     GST_WARNING ("no element stats found for ix=%u", elem_ix);
  443     return;
  444   }
  445   elem_stats->num_queries++;
  446 }
  447 
  448 static void
  449 do_thread_rusage_stats (GstStructure * s)
  450 {
  451   guint64 ts, tthread, thread_id;
  452   guint cpuload;
  453   GstThreadStats *thread_stats;
  454 
  455   gst_structure_get (s, "ts", G_TYPE_UINT64, &ts,
  456       "thread-id", G_TYPE_UINT64, &thread_id,
  457       "average-cpuload", G_TYPE_UINT, &cpuload, "time", G_TYPE_UINT64, &tthread,
  458       NULL);
  459   thread_stats = get_thread_stats ((gpointer) (guintptr) thread_id);
  460   thread_stats->cpuload = cpuload;
  461   thread_stats->tthread = tthread;
  462   last_ts = MAX (last_ts, ts);
  463 }
  464 
  465 static void
  466 do_proc_rusage_stats (GstStructure * s)
  467 {
  468   guint64 ts;
  469 
  470   gst_structure_get (s, "ts", G_TYPE_UINT64, &ts,
  471       "average-cpuload", G_TYPE_UINT, &total_cpuload, NULL);
  472   last_ts = MAX (last_ts, ts);
  473   have_cpuload = TRUE;
  474 }
  475 
  476 static void
  477 update_latency_table (GHashTable * table, const gchar * key, guint64 time)
  478 {
  479   /* Find the values in the hash table */
  480   GstLatencyStats *ls = g_hash_table_lookup (table, key);
  481   if (!ls) {
  482     /* Insert the new key if the value does not exist */
  483     ls = g_new0 (GstLatencyStats, 1);
  484     ls->count = 1;
  485     ls->total = time;
  486     ls->min = time;
  487     ls->max = time;
  488     g_hash_table_insert (table, g_strdup (key), ls);
  489   } else {
  490     /* Otherwise update the existing value */
  491     ls->count++;
  492     ls->total += time;
  493     if (ls->min > time)
  494       ls->min = time;
  495     if (ls->max < time)
  496       ls->max = time;
  497   }
  498 }
  499 
  500 static void
  501 do_latency_stats (GstStructure * s)
  502 {
  503   gchar *key = NULL;
  504   const gchar *src = NULL, *sink = NULL, *src_element = NULL,
  505       *sink_element = NULL, *src_element_id = NULL, *sink_element_id = NULL;
  506   guint64 ts = 0, time = 0;
  507 
  508   /* Get the values from the structure */
  509   src = gst_structure_get_string (s, "src");
  510   sink = gst_structure_get_string (s, "sink");
  511   src_element = gst_structure_get_string (s, "src-element");
  512   sink_element = gst_structure_get_string (s, "sink-element");
  513   src_element_id = gst_structure_get_string (s, "src-element-id");
  514   sink_element_id = gst_structure_get_string (s, "sink-element-id");
  515   gst_structure_get (s, "time", G_TYPE_UINT64, &time, NULL);
  516   gst_structure_get (s, "ts", G_TYPE_UINT64, &ts, NULL);
  517 
  518   /* Update last_ts */
  519   last_ts = MAX (last_ts, ts);
  520 
  521   /* Get the key */
  522   key = g_strdup_printf ("%s.%s.%s|%s.%s.%s", src_element_id, src_element,
  523       src, sink_element_id, sink_element, sink);
  524 
  525   /* Update the latency in the table */
  526   update_latency_table (latencies, key, time);
  527 
  528   /* Clean up */
  529   g_free (key);
  530 
  531   have_latency = TRUE;
  532 }
  533 
  534 static void
  535 do_element_latency_stats (GstStructure * s)
  536 {
  537   gchar *key = NULL;
  538   const gchar *src = NULL, *element = NULL, *element_id = NULL;
  539   guint64 ts = 0, time = 0;
  540 
  541   /* Get the values from the structure */
  542   src = gst_structure_get_string (s, "src");
  543   element = gst_structure_get_string (s, "element");
  544   element_id = gst_structure_get_string (s, "element-id");
  545   gst_structure_get (s, "time", G_TYPE_UINT64, &time, NULL);
  546   gst_structure_get (s, "ts", G_TYPE_UINT64, &ts, NULL);
  547 
  548   /* Update last_ts */
  549   last_ts = MAX (last_ts, ts);
  550 
  551   /* Get the key */
  552   key = g_strdup_printf ("%s.%s.%s", element_id, element, src);
  553 
  554   /* Update the latency in the table */
  555   update_latency_table (element_latencies, key, time);
  556 
  557   /* Clean up */
  558   g_free (key);
  559 
  560   have_element_latency = TRUE;
  561 }
  562 
  563 static void
  564 do_element_reported_latency (GstStructure * s)
  565 {
  566   const gchar *element = NULL, *element_id = NULL;
  567   guint64 ts = 0, min = 0, max = 0;
  568   GstReportedLatency *rl = NULL;
  569 
  570   /* Get the values from the structure */
  571   element_id = gst_structure_get_string (s, "element-id");
  572   element = gst_structure_get_string (s, "element");
  573   gst_structure_get (s, "min", G_TYPE_UINT64, &min, NULL);
  574   gst_structure_get (s, "max", G_TYPE_UINT64, &max, NULL);
  575   gst_structure_get (s, "ts", G_TYPE_UINT64, &ts, NULL);
  576 
  577   /* Update last_ts */
  578   last_ts = MAX (last_ts, ts);
  579 
  580   /* Insert/Update the key in the table */
  581   rl = g_new0 (GstReportedLatency, 1);
  582   rl->element = g_strdup_printf ("%s.%s", element_id, element);
  583   rl->ts = ts;
  584   rl->min = min;
  585   rl->max = max;
  586   g_queue_push_tail (element_reported_latencies, rl);
  587 
  588   have_element_reported_latency = TRUE;
  589 }
  590 
  591 /* reporting */
  592 
  593 static gint
  594 find_pad_stats_for_thread (gconstpointer value, gconstpointer user_data)
  595 {
  596   const GstPadStats *stats = (const GstPadStats *) value;
  597 
  598   if ((stats->thread_id == user_data) && (stats->num_buffers)) {
  599     return 0;
  600   }
  601   return 1;
  602 }
  603 
  604 static void
  605 print_pad_stats (gpointer value, gpointer user_data)
  606 {
  607   GstPadStats *stats = (GstPadStats *) value;
  608 
  609   if (stats->thread_id == user_data) {
  610     /* there seem to be some temporary pads */
  611     if (stats->num_buffers) {
  612       GstClockTimeDiff running =
  613           GST_CLOCK_DIFF (stats->first_ts, stats->last_ts);
  614       GstElementStats *elem_stats = get_element_stats (stats->parent_ix);
  615       gchar fullname[30 + 1];
  616 
  617       g_snprintf (fullname, 30, "%s.%s", elem_stats->name, stats->name);
  618 
  619       printf
  620           ("    %c %-30.30s: buffers %7u (live %5u,dec %5u,dis %5u,res %5u,"
  621           "cor %5u,mar %5u,hdr %5u,gap %5u,drop %5u,dlt %5u),",
  622           (stats->dir == GST_PAD_SRC) ? '>' : '<', fullname, stats->num_buffers,
  623           stats->num_live, stats->num_decode_only, stats->num_discont,
  624           stats->num_resync, stats->num_corrupted, stats->num_marker,
  625           stats->num_header, stats->num_gap, stats->num_droppable,
  626           stats->num_delta);
  627       if (stats->min_size == stats->max_size) {
  628         printf (" size (min/avg/max) ......./%7u/.......,", stats->avg_size);
  629       } else {
  630         printf (" size (min/avg/max) %7u/%7u/%7u,",
  631             stats->min_size, stats->avg_size, stats->max_size);
  632       }
  633       printf (" time %" GST_TIME_FORMAT ","
  634           " bytes/sec %lf\n",
  635           GST_TIME_ARGS (running),
  636           ((gdouble) (stats->num_buffers * stats->avg_size) * GST_SECOND) /
  637           ((gdouble) running));
  638     }
  639   }
  640 }
  641 
  642 static void
  643 print_thread_stats (gpointer key, gpointer value, gpointer user_data)
  644 {
  645   GSList *list = user_data;
  646   GSList *node = g_slist_find_custom (list, key, find_pad_stats_for_thread);
  647   GstThreadStats *stats = (GstThreadStats *) value;
  648 
  649   /* skip stats if there are no pads for that thread (e.g. a pipeline) */
  650   if (!node)
  651     return;
  652 
  653   printf ("Thread %p Statistics:\n", key);
  654   if (GST_CLOCK_TIME_IS_VALID (stats->tthread)) {
  655     printf ("  Time: %" GST_TIME_FORMAT "\n", GST_TIME_ARGS (stats->tthread));
  656     printf ("  Avg CPU load: %4.1f %%\n", (gfloat) stats->cpuload / 10.0);
  657   }
  658 
  659   puts ("  Pad Statistics:");
  660   g_slist_foreach (node, print_pad_stats, key);
  661 }
  662 
  663 static void
  664 print_element_stats (gpointer value, gpointer user_data)
  665 {
  666   GstElementStats *stats = (GstElementStats *) value;
  667 
  668   /* skip temporary elements */
  669   if (stats->first_ts != GST_CLOCK_TIME_NONE) {
  670     gchar fullname[45 + 1];
  671 
  672     g_snprintf (fullname, 45, "%s:%s", stats->type_name, stats->name);
  673 
  674     printf ("  %-45s:", fullname);
  675     if (stats->recv_buffers)
  676       printf (" buffers in/out %7u", stats->recv_buffers);
  677     else
  678       printf (" buffers in/out %7s", "-");
  679     if (stats->sent_buffers)
  680       printf ("/%7u", stats->sent_buffers);
  681     else
  682       printf ("/%7s", "-");
  683     if (stats->recv_bytes)
  684       printf (" bytes in/out %12" G_GUINT64_FORMAT, stats->recv_bytes);
  685     else
  686       printf (" bytes in/out %12s", "-");
  687     if (stats->sent_bytes)
  688       printf ("/%12" G_GUINT64_FORMAT, stats->sent_bytes);
  689     else
  690       printf ("/%12s", "-");
  691     printf (" first activity %" GST_TIME_FORMAT ", "
  692         " ev/msg/qry sent %5u/%5u/%5u\n", GST_TIME_ARGS (stats->first_ts),
  693         stats->num_events, stats->num_messages, stats->num_queries);
  694   }
  695 }
  696 
  697 static void
  698 accum_element_stats (gpointer value, gpointer user_data)
  699 {
  700   GstElementStats *stats = (GstElementStats *) value;
  701 
  702   if (stats->parent_ix != G_MAXUINT) {
  703     GstElementStats *parent_stats = get_element_stats (stats->parent_ix);
  704 
  705     parent_stats->num_events += stats->num_events;
  706     parent_stats->num_messages += stats->num_messages;
  707     parent_stats->num_queries += stats->num_queries;
  708     if (!GST_CLOCK_TIME_IS_VALID (parent_stats->first_ts)) {
  709       parent_stats->first_ts = stats->first_ts;
  710     } else if (GST_CLOCK_TIME_IS_VALID (stats->first_ts)) {
  711       parent_stats->first_ts = MIN (parent_stats->first_ts, stats->first_ts);
  712     }
  713     if (!GST_CLOCK_TIME_IS_VALID (parent_stats->last_ts)) {
  714       parent_stats->last_ts = stats->last_ts;
  715     } else if (GST_CLOCK_TIME_IS_VALID (stats->last_ts)) {
  716       parent_stats->last_ts = MAX (parent_stats->last_ts, stats->last_ts);
  717     }
  718   }
  719 }
  720 
  721 /* sorting */
  722 
  723 static gint
  724 sort_pad_stats_by_first_activity (gconstpointer ps1, gconstpointer ps2)
  725 {
  726   GstPadStats *s1 = (GstPadStats *) ps1;
  727   GstPadStats *s2 = (GstPadStats *) ps2;
  728 
  729   gint order = GST_CLOCK_DIFF (s2->first_ts, s1->first_ts);
  730 
  731   if (!order) {
  732     order = s1->dir - s2->dir;
  733   }
  734   return (order);
  735 }
  736 
  737 static void
  738 sort_pad_stats (gpointer value, gpointer user_data)
  739 {
  740   GSList **list = user_data;
  741 
  742   *list =
  743       g_slist_insert_sorted (*list, value, sort_pad_stats_by_first_activity);
  744 }
  745 
  746 static gint
  747 sort_element_stats_by_first_activity (gconstpointer es1, gconstpointer es2)
  748 {
  749   return (GST_CLOCK_DIFF (((GstElementStats *) es2)->first_ts,
  750           ((GstElementStats *) es1)->first_ts));
  751 }
  752 
  753 static void
  754 sort_bin_stats (gpointer value, gpointer user_data)
  755 {
  756   if (((GstElementStats *) value)->is_bin) {
  757     GSList **list = user_data;
  758 
  759     *list =
  760         g_slist_insert_sorted (*list, value,
  761         sort_element_stats_by_first_activity);
  762   }
  763 }
  764 
  765 static void
  766 sort_element_stats (gpointer value, gpointer user_data)
  767 {
  768   if (!(((GstElementStats *) value)->is_bin)) {
  769     GSList **list = user_data;
  770 
  771     *list =
  772         g_slist_insert_sorted (*list, value,
  773         sort_element_stats_by_first_activity);
  774   }
  775 }
  776 
  777 static gboolean
  778 check_bin_parent (gpointer key, gpointer value, gpointer user_data)
  779 {
  780   GstElementStats *stats = (GstElementStats *) value;
  781 
  782   return (stats->parent_ix == GPOINTER_TO_UINT (user_data));
  783 }
  784 
  785 static gboolean
  786 process_leaf_bins (gpointer key, gpointer value, gpointer user_data)
  787 {
  788   GHashTable *accum_bins = user_data;
  789 
  790   /* if we find no bin that has this bin as a parent ... */
  791   if (!g_hash_table_find (accum_bins, check_bin_parent, key)) {
  792     /* accumulate stats to the parent and remove */
  793     accum_element_stats (value, NULL);
  794     return TRUE;
  795   }
  796   return FALSE;
  797 }
  798 
  799 /* main */
  800 
  801 static gboolean
  802 init (void)
  803 {
  804   /* compile the parser regexps */
  805   /* 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" */
  806   raw_log = g_regex_new (
  807       /* 1: ts */
  808       "^([0-9:.]+) +"
  809       /* 2: pid */
  810       "([0-9]+) +"
  811       /* 3: thread */
  812       "(0x[0-9a-fA-F]+) +"
  813       /* 4: level */
  814       "([A-Z]+) +"
  815       /* 5: category */
  816       "([a-zA-Z_-]+) +"
  817       /* 6: file:line:func: */
  818       "([^:]*:[0-9]+:[^:]*:) +"
  819       /* 7: (obj)? log-text */
  820       "(.*)$", 0, 0, NULL);
  821   if (!raw_log) {
  822     GST_WARNING ("failed to compile the 'raw' parser");
  823     return FALSE;
  824   }
  825 
  826   ansi_log = g_regex_new (
  827       /* 1: ts */
  828       "^([0-9:.]+) +"
  829       /* 2: pid */
  830       "\\\x1b\\[[0-9;]+m *([0-9]+)\\\x1b\\[00m +"
  831       /* 3: thread */
  832       "(0x[0-9a-fA-F]+) +"
  833       /* 4: level */
  834       "(?:\\\x1b\\[[0-9;]+m)?([A-Z]+) +\\\x1b\\[00m +"
  835       /* 5: category */
  836       "\\\x1b\\[[0-9;]+m +([a-zA-Z_-]+) +"
  837       /* 6: file:line:func: */
  838       "([^:]*:[0-9]+:[^:]*:)(?:\\\x1b\\[00m)? +"
  839       /* 7: (obj)? log-text */
  840       "(.*)$", 0, 0, NULL);
  841   if (!raw_log) {
  842     GST_WARNING ("failed to compile the 'ansi' parser");
  843     return FALSE;
  844   }
  845 
  846   elements = g_ptr_array_new_with_free_func (free_element_stats);
  847   pads = g_ptr_array_new_with_free_func (free_pad_stats);
  848   threads = g_hash_table_new_full (NULL, NULL, NULL, free_thread_stats);
  849   latencies = g_hash_table_new_full (g_str_hash, g_str_equal, g_free,
  850       free_latency_stats);
  851   element_latencies = g_hash_table_new_full (g_str_hash, g_str_equal, g_free,
  852       free_latency_stats);
  853   element_reported_latencies = g_queue_new ();
  854 
  855   return TRUE;
  856 }
  857 
  858 static void
  859 done (void)
  860 {
  861   if (pads)
  862     g_ptr_array_free (pads, TRUE);
  863   if (elements)
  864     g_ptr_array_free (elements, TRUE);
  865   if (threads)
  866     g_hash_table_destroy (threads);
  867 
  868   if (latencies) {
  869     g_hash_table_remove_all (latencies);
  870     g_hash_table_destroy (latencies);
  871     latencies = NULL;
  872   }
  873   if (element_latencies) {
  874     g_hash_table_remove_all (element_latencies);
  875     g_hash_table_destroy (element_latencies);
  876     element_latencies = NULL;
  877   }
  878   if (element_reported_latencies) {
  879     g_queue_free_full (element_reported_latencies, free_reported_latency);
  880     element_reported_latencies = NULL;
  881   }
  882 
  883   if (raw_log)
  884     g_regex_unref (raw_log);
  885   if (ansi_log)
  886     g_regex_unref (ansi_log);
  887 }
  888 
  889 static void
  890 print_stats (void)
  891 {
  892   guint num_threads = g_hash_table_size (threads);
  893 
  894   /* print overall stats */
  895   puts ("\nOverall Statistics:");
  896   printf ("Number of Threads: %u\n", num_threads);
  897   printf ("Number of Elements: %u\n", num_elements - num_bins);
  898   printf ("Number of Bins: %u\n", num_bins);
  899   printf ("Number of Pads: %u\n", num_pads - num_ghostpads);
  900   printf ("Number of GhostPads: %u\n", num_ghostpads);
  901   printf ("Number of Buffers passed: %" G_GUINT64_FORMAT "\n", num_buffers);
  902   printf ("Number of Events sent: %" G_GUINT64_FORMAT "\n", num_events);
  903   printf ("Number of Message sent: %" G_GUINT64_FORMAT "\n", num_messages);
  904   printf ("Number of Queries sent: %" G_GUINT64_FORMAT "\n", num_queries);
  905   printf ("Time: %" GST_TIME_FORMAT "\n", GST_TIME_ARGS (last_ts));
  906   if (have_cpuload) {
  907     printf ("Avg CPU load: %4.1f %%\n", (gfloat) total_cpuload / 10.0);
  908   }
  909   puts ("");
  910 
  911   /* thread stats */
  912   if (num_threads) {
  913     GSList *list = NULL;
  914 
  915     g_ptr_array_foreach (pads, sort_pad_stats, &list);
  916     g_hash_table_foreach (threads, print_thread_stats, list);
  917     puts ("");
  918     g_slist_free (list);
  919   }
  920 
  921   /* element stats */
  922   if (num_elements) {
  923     GSList *list = NULL;
  924 
  925     puts ("Element Statistics:");
  926     /* sort by first_activity */
  927     g_ptr_array_foreach (elements, sort_element_stats, &list);
  928     /* attribute element stats to bins */
  929     g_slist_foreach (list, accum_element_stats, NULL);
  930     g_slist_foreach (list, print_element_stats, NULL);
  931     puts ("");
  932     g_slist_free (list);
  933   }
  934 
  935   /* bin stats */
  936   if (num_bins) {
  937     GSList *list = NULL;
  938     guint i;
  939     GHashTable *accum_bins = g_hash_table_new_full (NULL, NULL, NULL, NULL);
  940 
  941     puts ("Bin Statistics:");
  942     /* attribute bin stats to parent-bins */
  943     for (i = 0; i < num_elements; i++) {
  944       GstElementStats *stats = g_ptr_array_index (elements, i);
  945       if (stats->is_bin) {
  946         g_hash_table_insert (accum_bins, GUINT_TO_POINTER (i), stats);
  947       }
  948     }
  949     while (g_hash_table_size (accum_bins)) {
  950       g_hash_table_foreach_remove (accum_bins, process_leaf_bins, accum_bins);
  951     }
  952     g_hash_table_destroy (accum_bins);
  953     /* sort by first_activity */
  954     g_ptr_array_foreach (elements, sort_bin_stats, &list);
  955     g_slist_foreach (list, print_element_stats, NULL);
  956     puts ("");
  957     g_slist_free (list);
  958   }
  959 
  960   /* latency stats */
  961   if (have_latency) {
  962     puts ("Latency Statistics:");
  963     g_hash_table_foreach (latencies, (GHFunc) latencies_foreach_print_stats,
  964         NULL);
  965     puts ("");
  966   }
  967 
  968   /* element latency stats */
  969   if (have_element_latency) {
  970     puts ("Element Latency Statistics:");
  971     g_hash_table_foreach (element_latencies,
  972         (GHFunc) latencies_foreach_print_stats, NULL);
  973     puts ("");
  974   }
  975 
  976   /* element reported latency stats */
  977   if (have_element_reported_latency) {
  978     puts ("Element Reported Latency:");
  979     g_queue_foreach (element_reported_latencies,
  980         (GFunc) reported_latencies_foreach_print_stats, NULL);
  981     puts ("");
  982   }
  983 }
  984 
  985 static void
  986 collect_stats (const gchar * filename)
  987 {
  988   FILE *log;
  989 
  990   if ((log = fopen (filename, "rt"))) {
  991     gchar line[5001];
  992 
  993     /* probe format */
  994     if (fgets (line, 5000, log)) {
  995       GMatchInfo *match_info;
  996       GRegex *parser;
  997       GstStructure *s;
  998       guint lnr = 0;
  999       gchar *level, *data;
 1000 
 1001       if (strchr (line, 27)) {
 1002         parser = ansi_log;
 1003         GST_INFO ("format is 'ansi'");
 1004       } else {
 1005         parser = raw_log;
 1006         GST_INFO ("format is 'raw'");
 1007       }
 1008       rewind (log);
 1009 
 1010       /* parse the log */
 1011       while (!feof (log)) {
 1012         if (fgets (line, 5000, log)) {
 1013           if (g_regex_match (parser, line, 0, &match_info)) {
 1014             /* filter by level */
 1015             level = g_match_info_fetch (match_info, 4);
 1016             if (!strcmp (level, "TRACE")) {
 1017               data = g_match_info_fetch (match_info, 7);
 1018               if ((s = gst_structure_from_string (data, NULL))) {
 1019                 const gchar *name = gst_structure_get_name (s);
 1020 
 1021                 if (!strcmp (name, "new-pad")) {
 1022                   new_pad_stats (s);
 1023                 } else if (!strcmp (name, "new-element")) {
 1024                   new_element_stats (s);
 1025                 } else if (!strcmp (name, "buffer")) {
 1026                   do_buffer_stats (s);
 1027                 } else if (!strcmp (name, "event")) {
 1028                   do_event_stats (s);
 1029                 } else if (!strcmp (name, "message")) {
 1030                   do_message_stats (s);
 1031                 } else if (!strcmp (name, "query")) {
 1032                   do_query_stats (s);
 1033                 } else if (!strcmp (name, "thread-rusage")) {
 1034                   do_thread_rusage_stats (s);
 1035                 } else if (!strcmp (name, "proc-rusage")) {
 1036                   do_proc_rusage_stats (s);
 1037                 } else if (!strcmp (name, "latency")) {
 1038                   do_latency_stats (s);
 1039                 } else if (!strcmp (name, "element-latency")) {
 1040                   do_element_latency_stats (s);
 1041                 } else if (!strcmp (name, "element-reported-latency")) {
 1042                   do_element_reported_latency (s);
 1043                 } else {
 1044                   // TODO(ensonic): parse the xxx.class log lines
 1045                   if (!g_str_has_suffix (data, ".class")) {
 1046                     GST_WARNING ("unknown log entry: '%s'", data);
 1047                   }
 1048                 }
 1049                 gst_structure_free (s);
 1050               } else {
 1051                 GST_WARNING ("unknown log entry: '%s'", data);
 1052               }
 1053             }
 1054           } else {
 1055             if (*line) {
 1056               GST_WARNING ("foreign log entry: %s:%d:'%s'", filename, lnr,
 1057                   g_strchomp (line));
 1058             }
 1059           }
 1060           g_match_info_free (match_info);
 1061           match_info = NULL;
 1062           lnr++;
 1063         } else {
 1064           if (!feof (log)) {
 1065             // TODO(ensonic): run wc -L on the log file
 1066             fprintf (stderr, "line too long");
 1067           }
 1068         }
 1069       }
 1070     } else {
 1071       GST_WARNING ("empty log");
 1072     }
 1073     fclose (log);
 1074   }
 1075 }
 1076 
 1077 gint
 1078 main (gint argc, gchar * argv[])
 1079 {
 1080   gchar **filenames = NULL;
 1081   guint num;
 1082   GError *err = NULL;
 1083   GOptionContext *ctx;
 1084   GOptionEntry options[] = {
 1085     GST_TOOLS_GOPTION_VERSION,
 1086     // TODO(ensonic): add a summary flag, if set read the whole thing, print
 1087     // stats once, and exit
 1088     {G_OPTION_REMAINING, 0, 0, G_OPTION_ARG_FILENAME_ARRAY, &filenames, NULL}
 1089     ,
 1090     {NULL}
 1091   };
 1092 
 1093 #ifdef ENABLE_NLS
 1094   bindtextdomain (GETTEXT_PACKAGE, LOCALEDIR);
 1095   bind_textdomain_codeset (GETTEXT_PACKAGE, "UTF-8");
 1096   textdomain (GETTEXT_PACKAGE);
 1097 #endif
 1098 
 1099   g_set_prgname ("gst-stats-" GST_API_VERSION);
 1100 
 1101   ctx = g_option_context_new ("FILE");
 1102   g_option_context_add_main_entries (ctx, options, GETTEXT_PACKAGE);
 1103   g_option_context_add_group (ctx, gst_init_get_option_group ());
 1104   if (!g_option_context_parse (ctx, &argc, &argv, &err)) {
 1105     g_print ("Error initializing: %s\n", GST_STR_NULL (err->message));
 1106     exit (1);
 1107   }
 1108   g_option_context_free (ctx);
 1109 
 1110   gst_tools_print_version ();
 1111 
 1112   if (filenames == NULL || *filenames == NULL) {
 1113     g_print ("Please give one filename to %s\n\n", g_get_prgname ());
 1114     return 1;
 1115   }
 1116   num = g_strv_length (filenames);
 1117   if (num == 0 || num > 1) {
 1118     g_print ("Please give exactly one filename to %s (%d given).\n\n",
 1119         g_get_prgname (), num);
 1120     return 1;
 1121   }
 1122 
 1123   if (init ()) {
 1124     collect_stats (filenames[0]);
 1125     print_stats ();
 1126   }
 1127   done ();
 1128 
 1129   g_strfreev (filenames);
 1130   return 0;
 1131 }