latency: Dot not override already stored events
[platform/upstream/gstreamer.git] / tools / gst-stats.c
index 2ab514c..065f8ca 100644 (file)
@@ -41,8 +41,8 @@ static guint64 num_buffers = 0, num_events = 0, num_messages = 0, num_queries =
     0;
 static guint num_elements = 0, num_bins = 0, num_pads = 0, num_ghostpads = 0;
 static GstClockTime last_ts = G_GUINT64_CONSTANT (0);
-static GstClockTime tusersys = G_GUINT64_CONSTANT (0);
-static guint64 total_cpuload = 0;
+static guint total_cpuload = 0;
+static gboolean have_cpuload = FALSE;
 
 typedef struct
 {
@@ -59,7 +59,7 @@ typedef struct
   /* first and last activity on the pad, expected next_ts */
   GstClockTime first_ts, last_ts, next_ts;
   /* in which thread does it operate */
-  guint thread_id;
+  gpointer thread_id;
   /* hierarchy */
   guint parent_ix;
 } GstPadStats;
@@ -77,8 +77,6 @@ typedef struct
   guint num_events, num_messages, num_queries;
   /* first activity on the element */
   GstClockTime first_ts, last_ts;
-  /* time spend in this element */
-  GstClockTime treal;
   /* hierarchy */
   guint parent_ix;
 } GstElementStats;
@@ -86,7 +84,8 @@ typedef struct
 typedef struct
 {
   /* time spend in this thread */
-  GstClockTime treal;
+  GstClockTime tthread;
+  guint cpuload;
 } GstThreadStats;
 
 /* stats helper */
@@ -100,13 +99,15 @@ free_element_stats (gpointer data)
 static inline GstElementStats *
 get_element_stats (guint ix)
 {
-  return (ix != G_MAXUINT) ? g_ptr_array_index (elements, ix) : NULL;
+  return (ix != G_MAXUINT && ix < elements->len) ?
+      g_ptr_array_index (elements, ix) : NULL;
 }
 
 static inline GstPadStats *
 get_pad_stats (guint ix)
 {
-  return (ix != G_MAXUINT) ? g_ptr_array_index (pads, ix) : NULL;
+  return (ix != G_MAXUINT && ix < pads->len) ?
+      g_ptr_array_index (pads, ix) : NULL;
 }
 
 static void
@@ -116,13 +117,14 @@ free_pad_stats (gpointer data)
 }
 
 static inline GstThreadStats *
-get_thread_stats (guint id)
+get_thread_stats (gpointer id)
 {
-  GstThreadStats *stats = g_hash_table_lookup (threads, GUINT_TO_POINTER (id));
+  GstThreadStats *stats = g_hash_table_lookup (threads, id);
 
   if (G_UNLIKELY (!stats)) {
     stats = g_slice_new0 (GstThreadStats);
-    g_hash_table_insert (threads, GUINT_TO_POINTER (id), stats);
+    stats->tthread = GST_CLOCK_TIME_NONE;
+    g_hash_table_insert (threads, id, stats);
   }
   return stats;
 }
@@ -135,7 +137,7 @@ new_pad_stats (GstStructure * s)
   gchar *type, *name;
   gboolean is_ghost_pad;
   GstPadDirection dir;
-  guint thread_id;
+  guint64 thread_id;
 
   gst_structure_get (s,
       "ix", G_TYPE_UINT, &ix,
@@ -144,7 +146,7 @@ new_pad_stats (GstStructure * s)
       "type", G_TYPE_STRING, &type,
       "is-ghostpad", G_TYPE_BOOLEAN, &is_ghost_pad,
       "pad-direction", GST_TYPE_PAD_DIRECTION, &dir,
-      "thread-id", G_TYPE_UINT, &thread_id, NULL);
+      "thread-id", G_TYPE_UINT64, &thread_id, NULL);
 
   stats = g_slice_new0 (GstPadStats);
   if (is_ghost_pad)
@@ -157,7 +159,7 @@ new_pad_stats (GstStructure * s)
   stats->dir = dir;
   stats->min_size = G_MAXUINT;
   stats->first_ts = stats->last_ts = stats->next_ts = GST_CLOCK_TIME_NONE;
-  stats->thread_id = thread_id;
+  stats->thread_id = (gpointer) (guintptr) thread_id;
   stats->parent_ix = parent_ix;
 
   if (pads->len <= ix)
@@ -278,7 +280,8 @@ do_element_stats (GstElementStats * stats, GstElementStats * peer_stats,
 static void
 do_buffer_stats (GstStructure * s)
 {
-  guint64 ts, buffer_ts, buffer_dur;
+  guint64 ts;
+  guint64 buffer_pts = GST_CLOCK_TIME_NONE, buffer_dur = GST_CLOCK_TIME_NONE;
   guint pad_ix, elem_ix, peer_elem_ix;
   guint size;
   GstBufferFlags buffer_flags;
@@ -288,13 +291,13 @@ do_buffer_stats (GstStructure * s)
   num_buffers++;
   gst_structure_get (s, "ts", G_TYPE_UINT64, &ts,
       "pad-ix", G_TYPE_UINT, &pad_ix,
-      "elem-ix", G_TYPE_UINT, &elem_ix,
-      "peer-elem-ix", G_TYPE_UINT, &peer_elem_ix,
+      "element-ix", G_TYPE_UINT, &elem_ix,
+      "peer-element-ix", G_TYPE_UINT, &peer_elem_ix,
       "buffer-size", G_TYPE_UINT, &size,
-      "buffer-ts", G_TYPE_UINT64, &buffer_ts,
-      "buffer-duration", G_TYPE_UINT64, &buffer_dur,
       "buffer-flags", GST_TYPE_BUFFER_FLAGS, &buffer_flags, NULL);
-  last_ts = ts;
+  gst_structure_get_uint64 (s, "buffer-pts", &buffer_pts);
+  gst_structure_get_uint64 (s, "buffer-duration", &buffer_dur);
+  last_ts = MAX (last_ts, ts);
   if (!(pad_stats = get_pad_stats (pad_ix))) {
     GST_WARNING ("no pad stats found for ix=%u", pad_ix);
     return;
@@ -307,7 +310,7 @@ do_buffer_stats (GstStructure * s)
     GST_WARNING ("no element stats found for ix=%u", peer_elem_ix);
     return;
   }
-  do_pad_stats (pad_stats, elem_ix, size, ts, buffer_ts, buffer_dur,
+  do_pad_stats (pad_stats, elem_ix, size, ts, buffer_pts, buffer_dur,
       buffer_flags);
   if (pad_stats->dir == GST_PAD_SRC) {
     /* push */
@@ -328,8 +331,9 @@ do_event_stats (GstStructure * s)
 
   num_events++;
   gst_structure_get (s, "ts", G_TYPE_UINT64, &ts,
-      "pad-ix", G_TYPE_UINT, &pad_ix, "elem-ix", G_TYPE_UINT, &elem_ix, NULL);
-  last_ts = ts;
+      "pad-ix", G_TYPE_UINT, &pad_ix, "element-ix", G_TYPE_UINT, &elem_ix,
+      NULL);
+  last_ts = MAX (last_ts, ts);
   if (!(pad_stats = get_pad_stats (pad_ix))) {
     GST_WARNING ("no pad stats found for ix=%u", pad_ix);
     return;
@@ -351,8 +355,8 @@ do_message_stats (GstStructure * s)
 
   num_messages++;
   gst_structure_get (s, "ts", G_TYPE_UINT64, &ts,
-      "elem-ix", G_TYPE_UINT, &elem_ix, NULL);
-  last_ts = ts;
+      "element-ix", G_TYPE_UINT, &elem_ix, NULL);
+  last_ts = MAX (last_ts, ts);
   if (!(elem_stats = get_element_stats (elem_ix))) {
     GST_WARNING ("no element stats found for ix=%u", elem_ix);
     return;
@@ -369,8 +373,8 @@ do_query_stats (GstStructure * s)
 
   num_queries++;
   gst_structure_get (s, "ts", G_TYPE_UINT64, &ts,
-      "elem-ix", G_TYPE_UINT, &elem_ix, NULL);
-  last_ts = ts;
+      "element-ix", G_TYPE_UINT, &elem_ix, NULL);
+  last_ts = MAX (last_ts, ts);
   if (!(elem_stats = get_element_stats (elem_ix))) {
     GST_WARNING ("no element stats found for ix=%u", elem_ix);
     return;
@@ -379,19 +383,31 @@ do_query_stats (GstStructure * s)
 }
 
 static void
-do_rusage_stats (GstStructure * s)
+do_thread_rusage_stats (GstStructure * s)
 {
-  guint64 ts, treal;
-  guint thread_id, cpuload;
+  guint64 ts, tthread, thread_id;
+  guint cpuload;
   GstThreadStats *thread_stats;
 
   gst_structure_get (s, "ts", G_TYPE_UINT64, &ts,
-      "thread-id", G_TYPE_UINT, &thread_id,
-      "cpuload", G_TYPE_UINT, &cpuload,
-      "treal", G_TYPE_UINT64, &treal, "tsum", G_TYPE_UINT64, &tusersys, NULL);
-  thread_stats = get_thread_stats (thread_id);
-  thread_stats->treal = treal;
-  last_ts = ts;
+      "thread-id", G_TYPE_UINT64, &thread_id,
+      "average-cpuload", G_TYPE_UINT, &cpuload, "time", G_TYPE_UINT64, &tthread,
+      NULL);
+  thread_stats = get_thread_stats ((gpointer) (guintptr) thread_id);
+  thread_stats->cpuload = cpuload;
+  thread_stats->tthread = tthread;
+  last_ts = MAX (last_ts, ts);
+}
+
+static void
+do_proc_rusage_stats (GstStructure * s)
+{
+  guint64 ts;
+
+  gst_structure_get (s, "ts", G_TYPE_UINT64, &ts,
+      "average-cpuload", G_TYPE_UINT, &total_cpuload, NULL);
+  last_ts = MAX (last_ts, ts);
+  have_cpuload = TRUE;
 }
 
 /* reporting */
@@ -401,8 +417,7 @@ find_pad_stats_for_thread (gconstpointer value, gconstpointer user_data)
 {
   const GstPadStats *stats = (const GstPadStats *) value;
 
-  if ((stats->thread_id == GPOINTER_TO_UINT (user_data)) &&
-      (stats->num_buffers)) {
+  if ((stats->thread_id == user_data) && (stats->num_buffers)) {
     return 0;
   }
   return 1;
@@ -413,7 +428,7 @@ print_pad_stats (gpointer value, gpointer user_data)
 {
   GstPadStats *stats = (GstPadStats *) value;
 
-  if (stats->thread_id == GPOINTER_TO_UINT (user_data)) {
+  if (stats->thread_id == user_data) {
     /* there seem to be some temporary pads */
     if (stats->num_buffers) {
       GstClockTimeDiff running =
@@ -452,26 +467,16 @@ print_thread_stats (gpointer key, gpointer value, gpointer user_data)
   GSList *list = user_data;
   GSList *node = g_slist_find_custom (list, key, find_pad_stats_for_thread);
   GstThreadStats *stats = (GstThreadStats *) value;
-  guint cpuload = 0;
-  guint time_percent;
 
   /* skip stats if there are no pads for that thread (e.g. a pipeline) */
   if (!node)
     return;
 
-  time_percent =
-      (guint) gst_util_uint64_scale (stats->treal, G_GINT64_CONSTANT (100),
-      last_ts);
-
-  if (total_cpuload) {
-    cpuload =
-        (guint) gst_util_uint64_scale (total_cpuload, stats->treal, last_ts);
-  }
-
   printf ("Thread %p Statistics:\n", key);
-  printf ("  Time: %" GST_TIME_FORMAT ", %u %%\n", GST_TIME_ARGS (stats->treal),
-      (guint) time_percent);
-  printf ("  Avg CPU load: %u %%\n", cpuload);
+  if (GST_CLOCK_TIME_IS_VALID (stats->tthread)) {
+    printf ("  Time: %" GST_TIME_FORMAT "\n", GST_TIME_ARGS (stats->tthread));
+    printf ("  Avg CPU load: %4.1f %%\n", (gfloat) stats->cpuload / 10.0);
+  }
 
   puts ("  Pad Statistics:");
   g_slist_foreach (node, print_pad_stats, key);
@@ -632,7 +637,7 @@ init (void)
       /* 5: category */
       "([a-zA-Z_-]+) +"
       /* 6: file:line:func: */
-      "([^:]+:[0-9]+:[^:]+:)"
+      "([^:]*:[0-9]+:[^:]*:) +"
       /* 7: (obj)? log-text */
       "(.*)$", 0, 0, NULL);
   if (!raw_log) {
@@ -644,15 +649,15 @@ init (void)
       /* 1: ts */
       "^([0-9:.]+) +"
       /* 2: pid */
-      "\\\e\\\[[0-9;]+m *([0-9]+)\\\e\\\[00m +"
+      "\\\x1b\\[[0-9;]+m *([0-9]+)\\\x1b\\[00m +"
       /* 3: thread */
       "(0x[0-9a-fA-F]+) +"
       /* 4: level */
-      "(?:\\\e\\\[[0-9;]+m)?([A-Z]+) +\\\e\\\[00m +"
+      "(?:\\\x1b\\[[0-9;]+m)?([A-Z]+) +\\\x1b\\[00m +"
       /* 5: category */
-      "\\\e\\\[[0-9;]+m +([a-zA-Z_-]+) +"
+      "\\\x1b\\[[0-9;]+m +([a-zA-Z_-]+) +"
       /* 6: file:line:func: */
-      "([^:]+:[0-9]+:[^:]+:)(?:\\\e\\\[00m)?"
+      "([^:]*:[0-9]+:[^:]*:)(?:\\\x1b\\[00m)? +"
       /* 7: (obj)? log-text */
       "(.*)$", 0, 0, NULL);
   if (!raw_log) {
@@ -700,10 +705,8 @@ print_stats (void)
   printf ("Number of Message sent: %" G_GUINT64_FORMAT "\n", num_messages);
   printf ("Number of Queries sent: %" G_GUINT64_FORMAT "\n", num_queries);
   printf ("Time: %" GST_TIME_FORMAT "\n", GST_TIME_ARGS (last_ts));
-  if (tusersys) {
-    total_cpuload = gst_util_uint64_scale (tusersys,
-        G_GINT64_CONSTANT (100), last_ts);
-    printf ("Avg CPU load: %u %%\n", (guint) total_cpuload);
+  if (have_cpuload) {
+    printf ("Avg CPU load: %4.1f %%\n", (gfloat) total_cpuload / 10.0);
   }
   puts ("");
 
@@ -793,8 +796,6 @@ collect_stats (const gchar * filename)
               if ((s = gst_structure_from_string (data, NULL))) {
                 const gchar *name = gst_structure_get_name (s);
 
-                // TODO(ensonic): add a function for each name-id quark
-                // these function will do the actual stats tracking
                 if (!strcmp (name, "new-pad")) {
                   new_pad_stats (s);
                 } else if (!strcmp (name, "new-element")) {
@@ -807,10 +808,15 @@ collect_stats (const gchar * filename)
                   do_message_stats (s);
                 } else if (!strcmp (name, "query")) {
                   do_query_stats (s);
-                } else if (!strcmp (name, "rusage")) {
-                  do_rusage_stats (s);
+                } else if (!strcmp (name, "thread-rusage")) {
+                  do_thread_rusage_stats (s);
+                } else if (!strcmp (name, "proc-rusage")) {
+                  do_proc_rusage_stats (s);
                 } else {
-                  GST_WARNING ("unknown log entry: '%s'", data);
+                  // TODO(ensonic): parse the xxx.class log lines
+                  if (!g_str_has_suffix (data, ".class")) {
+                    GST_WARNING ("unknown log entry: '%s'", data);
+                  }
                 }
                 gst_structure_free (s);
               } else {
@@ -833,10 +839,10 @@ collect_stats (const gchar * filename)
           }
         }
       }
-      fclose (log);
     } else {
       GST_WARNING ("empty log");
     }
+    fclose (log);
   }
 }