plugins/tracers/gstrusage.c

   1 /* GStreamer
   2  * Copyright (C) 2013 Stefan Sauer <ensonic@users.sf.net>
   3  *
   4  * gstrusage.c: tracing module that logs resource usage stats
   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  * SECTION:gstrusage
  23  * @short_description: log resource usage stats
  24  *
  25  * A tracing module that take rusage() snapshots and logs them.
  26  */
  27
  28 #ifdef HAVE_CONFIG_H
  29 #  include "config.h"
  30 #endif
  31
  32 #include "gstrusage.h"
  33
  34 #ifdef HAVE_SYS_RESOURCE_H
  35 #include <sys/resource.h>
  36 #endif
  37
  38 GST_DEBUG_CATEGORY_STATIC (gst_rusage_debug);
  39 #define GST_CAT_DEFAULT gst_rusage_debug
  40
  41 #define _do_init \
  42     GST_DEBUG_CATEGORY_INIT (gst_rusage_debug, "rusage", 0, "rusage tracer");
  43 #define gst_rusage_tracer_parent_class parent_class
  44 G_DEFINE_TYPE_WITH_CODE (GstRUsageTracer, gst_rusage_tracer, GST_TYPE_TRACER,
  45     _do_init);
  46
  47 /* for ts calibration */
  48 static gpointer main_thread_id = NULL;
  49 static guint64 tproc_base = G_GINT64_CONSTANT (0);
  50
  51 typedef struct
  52 {
  53   /* time spend in this thread */
  54   GstClockTime tthread;
  55 } GstThreadStats;
  56
  57 static void gst_rusage_tracer_invoke (GstTracer * self, GstTracerHookId id,
  58     GstTracerMessageId mid, va_list var_args);
  59
  60 /* data helper */
  61
  62 static void
  63 free_thread_stats (gpointer data)
  64 {
  65   g_slice_free (GstThreadStats, data);
  66 }
  67
  68 static void
  69 gst_rusage_tracer_class_init (GstRUsageTracerClass * klass)
  70 {
  71   GstTracerClass *gst_tracer_class = GST_TRACER_CLASS (klass);
  72
  73   gst_tracer_class->invoke = gst_rusage_tracer_invoke;
  74 }
  75
  76 static void
  77 gst_rusage_tracer_init (GstRUsageTracer * self)
  78 {
  79   g_object_set (self, "mask", GST_TRACER_HOOK_ALL, NULL);
  80   self->threads = g_hash_table_new_full (NULL, NULL, NULL, free_thread_stats);
  81
  82   main_thread_id = g_thread_self ();
  83   GST_DEBUG ("rusage: main thread=%p", main_thread_id);
  84 }
  85
  86 static void
  87 gst_rusage_tracer_invoke (GstTracer * obj, GstTracerHookId hid,
  88     GstTracerMessageId mid, va_list var_args)
  89 {
  90   GstRUsageTracer *self = GST_RUSAGE_TRACER_CAST (obj);
  91   guint64 ts = va_arg (var_args, guint64);
  92   GstThreadStats *stats;
  93   gpointer thread_id = g_thread_self ();
  94   guint cpuload = 0;
  95   struct rusage ru;
  96   GstClockTime tproc = G_GUINT64_CONSTANT (0);
  97
  98   // FIXME(ensonic): not threadsafe
  99   static GstClockTime last_ts = G_GUINT64_CONSTANT (0);
 100
 101   getrusage (RUSAGE_SELF, &ru);
 102
 103   /* get stats record for current thread */
 104   if (!(stats = g_hash_table_lookup (self->threads, thread_id))) {
 105     stats = g_slice_new0 (GstThreadStats);
 106     g_hash_table_insert (self->threads, thread_id, stats);
 107   }
 108 #ifdef HAVE_CLOCK_GETTIME
 109   {
 110     struct timespec now;
 111
 112     if (!clock_gettime (CLOCK_PROCESS_CPUTIME_ID, &now)) {
 113       tproc = GST_TIMESPEC_TO_TIME (now);
 114     } else {
 115       GST_WARNING ("clock_gettime (CLOCK_PROCESS_CPUTIME_ID,...) failed.");
 116       tproc =
 117           GST_TIMEVAL_TO_TIME (ru.ru_utime) + GST_TIMEVAL_TO_TIME (ru.ru_stime);
 118     }
 119
 120     /* cpu time per thread */
 121     if (!clock_gettime (CLOCK_THREAD_CPUTIME_ID, &now)) {
 122       stats->tthread = GST_TIMESPEC_TO_TIME (now);
 123     } else {
 124       GST_WARNING ("clock_gettime (CLOCK_THREAD_CPUTIME_ID,...) failed.");
 125       stats->tthread += GST_CLOCK_DIFF (last_ts, ts);
 126     }
 127   }
 128 #else
 129   tproc = GST_TIMEVAL_TO_TIME (ru.ru_utime) + GST_TIMEVAL_TO_TIME (ru.ru_stime);
 130   /* crude way to meassure time spend in which thread */
 131   stats->tthread += GST_CLOCK_DIFF (last_ts, ts);
 132 #endif
 133
 134   /* remember last timestamp for fallback calculations */
 135   last_ts = ts;
 136
 137   /* Calibrate ts for the process and main thread. For tthread[main] and tproc
 138    * the time is larger than ts, as our base-ts is taken after the process has
 139    * started.
 140    */
 141   if (G_UNLIKELY (thread_id == main_thread_id)) {
 142     main_thread_id = NULL;
 143     /* when the registry gets updated, the tproc is less than the debug time ? */
 144     /* TODO(ensonic): we still see cases where tproc overtakes ts, especially
 145      * when with sync=false, can this be due to multiple cores in use? */
 146     if (tproc > ts) {
 147       tproc_base = tproc - ts;
 148       GST_DEBUG ("rusage: calibrating by %" G_GUINT64_FORMAT ", thread: %"
 149           G_GUINT64_FORMAT ", proc: %" G_GUINT64_FORMAT,
 150           tproc_base, stats->tthread, tproc);
 151       stats->tthread -= tproc_base;
 152     }
 153   }
 154   /* we always need to corect proc time */
 155   tproc -= tproc_base;
 156
 157   /* FIXME: how can we take cpu-frequency scaling into account?
 158    * - looking at /sys/devices/system/cpu/cpu0/cpufreq/
 159    *   scale_factor=scaling_max_freq/scaling_cur_freq
 160    * - as a workaround we can switch it via /sys/devices/system/cpu/cpu0/cpufreq/scaling_governor
 161    *   cpufreq-selector -g performance
 162    *   cpufreq-selector -g ondemand
 163    */
 164   cpuload = (guint) gst_util_uint64_scale (tproc, G_GINT64_CONSTANT (100), ts);
 165   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 */
 166           "thread-time", G_TYPE_UINT64, stats->tthread, /* time spent in thread */
 167           "proc-time", G_TYPE_UINT64, tproc,    /* time spent in process */
 168           NULL));
 169 }