rusage: announce the data format

Rusage will now announce what is meassures and how it is logged. Use the new format in stats.
Cleanup the the code and naming.

diff --git a/plugins/tracers/gstrusage.c b/plugins/tracers/gstrusage.c
index f54f53a..71d6e4d 100644 (file)
--- a/plugins/tracers/gstrusage.c
+++ b/plugins/tracers/gstrusage.c
@@ -24,6 +24,10 @@
  *
  * A tracing module that take rusage() snapshots and logs them. 
  */
+/* TODO: log more items, cpuload is calculated as an aggregated value
+ * - in many cases a windowed value would be more interesting to see local
+ *   cpu-load spikes
+ */
 
 #ifdef HAVE_CONFIG_H
 #  include "config.h"
@@ -81,6 +85,46 @@ gst_rusage_tracer_init (GstRUsageTracer * self)
 
   main_thread_id = g_thread_self ();
   GST_DEBUG ("rusage: main thread=%p", main_thread_id);
+
+  /* announce trace formats */
+  /* *INDENT-OFF* */
+  gst_tracer_log_trace (gst_structure_new ("thread-rusage.class",
+      "thread-id", GST_TYPE_STRUCTURE, gst_structure_new ("scope",
+          "related-to", G_TYPE_STRING, "thread",  // use genum
+          NULL),
+      "cpuload", GST_TYPE_STRUCTURE, gst_structure_new ("value",
+          "type", G_TYPE_GTYPE, G_TYPE_UINT,
+          "description", G_TYPE_STRING, "cpu usage per thread",
+          "flags", G_TYPE_STRING, "aggregated",  // use gflags 
+          "min", G_TYPE_UINT, 0, "max", G_TYPE_UINT, 100,
+          NULL),
+      "time", GST_TYPE_STRUCTURE, gst_structure_new ("value",
+          "type", G_TYPE_GTYPE, G_TYPE_UINT64,
+          "description", G_TYPE_STRING, "time spent in thread",
+          "flags", G_TYPE_STRING, "aggregated",  // use gflags 
+          "min", G_TYPE_UINT64, G_GUINT64_CONSTANT (0),
+          "max", G_TYPE_UINT64, G_MAXUINT64,
+          NULL),
+      NULL));
+  gst_tracer_log_trace (gst_structure_new ("proc-rusage.class",
+      "thread-id", GST_TYPE_STRUCTURE, gst_structure_new ("scope",
+          "related-to", G_TYPE_STRING, "process",  // use genum
+          NULL),
+      "cpuload", GST_TYPE_STRUCTURE, gst_structure_new ("value",
+          "type", G_TYPE_GTYPE, G_TYPE_UINT,
+          "description", G_TYPE_STRING, "cpu usage per process",
+          "flags", G_TYPE_STRING, "aggregated",  // use gflags 
+          "min", G_TYPE_UINT, 0, "max", G_TYPE_UINT, 100,
+          NULL),
+      "time", GST_TYPE_STRUCTURE, gst_structure_new ("value",
+          "type", G_TYPE_GTYPE, G_TYPE_UINT64,
+          "description", G_TYPE_STRING, "time spent in process",
+          "flags", G_TYPE_STRING, "aggregated",  // use gflags 
+          "min", G_TYPE_UINT64, G_GUINT64_CONSTANT (0),
+          "max", G_TYPE_UINT64, G_MAXUINT64,
+          NULL),
+      NULL));
+  /* *INDENT-ON* */
 }
 
 static void
@@ -161,9 +205,20 @@ gst_rusage_tracer_invoke (GstTracer * obj, GstTracerHookId hid,
    *   cpufreq-selector -g performance
    *   cpufreq-selector -g ondemand
    */
+  /* *INDENT-OFF* */
+  cpuload = (guint) gst_util_uint64_scale (stats->tthread,
+      G_GINT64_CONSTANT (100), ts);
+  gst_tracer_log_trace (gst_structure_new ("thread-rusage", 
+      "ts", G_TYPE_UINT64, ts, 
+      "thread-id", G_TYPE_UINT, GPOINTER_TO_UINT (thread_id), 
+      "cpuload", G_TYPE_UINT, cpuload,
+      "time", G_TYPE_UINT64, stats->tthread,
+      NULL));
   cpuload = (guint) gst_util_uint64_scale (tproc, G_GINT64_CONSTANT (100), ts);
-  gst_tracer_log_trace (gst_structure_new ("rusage", "ts", G_TYPE_UINT64, ts, "thread-id", G_TYPE_UINT, GPOINTER_TO_UINT (thread_id), "cpuload", G_TYPE_UINT, cpuload,  /* cpu usage per thread - FIXME: not used in gst-stats */
-          "thread-time", G_TYPE_UINT64, stats->tthread, /* time spent in thread */
-          "proc-time", G_TYPE_UINT64, tproc,    /* time spent in process */
-          NULL));
+  gst_tracer_log_trace (gst_structure_new ("proc-rusage", 
+      "ts", G_TYPE_UINT64, ts, 
+      "cpuload", G_TYPE_UINT, cpuload,
+      "time", G_TYPE_UINT64, tproc,
+      NULL));
+  /* *INDENT-ON* */
 }

diff --git a/tools/gst-stats.c b/tools/gst-stats.c
index b2a6f32..bc65cbd 100644 (file)
--- a/tools/gst-stats.c
+++ b/tools/gst-stats.c
@@ -41,7 +41,7 @@ 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 tproc = G_GUINT64_CONSTANT (0);
+static guint total_cpuload = 0;
 
 typedef struct
 {
@@ -76,8 +76,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 tthread;
   /* hierarchy */
   guint parent_ix;
 } GstElementStats;
@@ -86,6 +84,7 @@ typedef struct
 {
   /* time spend in this thread */
   GstClockTime tthread;
+  guint cpuload;
 } GstThreadStats;
 
 /* stats helper */
@@ -378,21 +377,31 @@ do_query_stats (GstStructure * s)
 }
 
 static void
-do_rusage_stats (GstStructure * s)
+do_thread_rusage_stats (GstStructure * s)
 {
   guint64 ts, tthread;
-  guint thread_id;
+  guint thread_id, cpuload;
   GstThreadStats *thread_stats;
 
   gst_structure_get (s, "ts", G_TYPE_UINT64, &ts,
       "thread-id", G_TYPE_UINT, &thread_id,
-      "thread-time", G_TYPE_UINT64, &tthread,
-      "proc-time", G_TYPE_UINT64, &tproc, NULL);
+      "cpuload", G_TYPE_UINT, &cpuload, "time", G_TYPE_UINT64, &tthread, NULL);
   thread_stats = get_thread_stats (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,
+      "cpuload", G_TYPE_UINT, &total_cpuload, NULL);
+  last_ts = MAX (last_ts, ts);
+}
+
 /* reporting */
 
 static gint
@@ -451,19 +460,14 @@ 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;
 
   /* skip stats if there are no pads for that thread (e.g. a pipeline) */
   if (!node)
     return;
 
-  cpuload =
-      (guint) gst_util_uint64_scale (stats->tthread, G_GINT64_CONSTANT (100),
-      last_ts);
-
   printf ("Thread %p Statistics:\n", key);
   printf ("  Time: %" GST_TIME_FORMAT "\n", GST_TIME_ARGS (stats->tthread));
-  printf ("  Avg CPU load: %u %%\n", cpuload);
+  printf ("  Avg CPU load: %u %%\n", stats->cpuload);
 
   puts ("  Pad Statistics:");
   g_slist_foreach (node, print_pad_stats, key);
@@ -679,7 +683,6 @@ static void
 print_stats (void)
 {
   guint num_threads = g_hash_table_size (threads);
-  guint64 total_cpuload = 0;
 
   /* print overall stats */
   puts ("\nOverall Statistics:");
@@ -693,11 +696,7 @@ 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 (tproc) {
-    total_cpuload = gst_util_uint64_scale (tproc,
-        G_GINT64_CONSTANT (100), last_ts);
-    printf ("Avg CPU load: %u %%\n", (guint) total_cpuload);
-  }
+  printf ("Avg CPU load: %u %%\n", (guint) total_cpuload);
   puts ("");
 
   /* thread stats */
@@ -800,8 +799,10 @@ 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);
                 }