* AUTHORS:

	* Makefile.am:
	* NEWS:
	* README:
	* configure.ac:
	* src/Makefile.am:
	* src/gstpreload.c:
	* src/plot.sh:
	* src/splitlog.py:
	  Initial commit of gstreamer meassurment preload library.

10 files changed, 440 insertions, 0 deletions

diff --git a/AUTHORS b/AUTHORS
new file mode 100644
index 0000000..c0e8b01
--- /dev/null
+++ b/AUTHORS
@@ -0,0 +1,3 @@
+Original Authors
+----------------
+Stefan Kost              <ensonic@users.sourceforge.net>
diff --git a/ChangeLog b/ChangeLog
new file mode 100644
index 0000000..cade12e
--- /dev/null
+++ b/ChangeLog
@@ -0,0 +1,13 @@
+2008-03-17  Stefan Kost  <ensonic@users.sf.net>
+
+	* AUTHORS:
+	* Makefile.am:
+	* NEWS:
+	* README:
+	* configure.ac:
+	* src/Makefile.am:
+	* src/gstpreload.c:
+	* src/plot.sh:
+	* src/splitlog.py:
+	  Initial commit of gstreamer meassurment preload library.
+
diff --git a/Makefile.am b/Makefile.am
new file mode 100644
index 0000000..f268924
--- /dev/null
+++ b/Makefile.am
@@ -0,0 +1,2 @@
+SUBDIRS = src
+
diff --git a/NEWS b/NEWS
new file mode 100644
index 0000000..2933206
--- /dev/null
+++ b/NEWS
@@ -0,0 +1,3 @@
+0.1 initial release (xx.xxx.2008)
+================================================================================
+Boilerplate code.
diff --git a/README b/README
new file mode 100644
index 0000000..c127afc
--- /dev/null
+++ b/README
@@ -0,0 +1,44 @@
+= PerformanceMonitor =
+Write a ld-preload lib that can gather data from gstreamer and logs it to files.
+The idea is not avoid adding API for performance meassurement to gstreamer.
+
+== Services ==
+library provides some common services used by the sensor modules.
+* logging
+* timestamps
+
+== Sensors ==
+Sensors do meassurements and deliver timestampe performance data.
+* bitrates and latency via gst_pad_push/pull_range per link
+* qos ratio via gst_event_new_qos(), gst_pad_send_event()
+* cpu/mem via get_rusage
+  * when (gst_clock_get_time) ?
+  * we want it per thread
+* queue fill levels
+* tasks
+
+== Wanted Sensors ==
+* dropped buffers
+
+== Log Format ==
+* we have global data, data per {link,element,thread}
+* we log into one file for performance reasons and split later
+
+== Running ==
+LD_PRELOAD=src/.libs/libgstpreload.so gst-launch-0.10 fakesrc num-buffers=10 ! fakesink
+LD_PRELOAD=src/.libs/libgstpreload.so gst-launch-0.10 videotestsrc num-buffers=50 ! xvimagesink
+
+There are some additional env vars to influence the behaviour:
+GSTPL_LOG_NAME
+ "/tmp/gstpl.log" if empty
+GSTPL_DETAILS (not yet done)
+ "*" if empty
+ "qos-ratio,cpu-load=all"
+ "qos-ratio,cpu-load=sum"
+
+== Exploration
+pygtk ui, mathplotlib, gst-debug-viewer
+
+== Ideas ==
+* can be used in media test suite as a monitor
+
diff --git a/configure.ac b/configure.ac
new file mode 100644
index 0000000..cd1884e
--- /dev/null
+++ b/configure.ac
@@ -0,0 +1,44 @@
+#                                               -*- Autoconf -*-
+# Process this file with autoconf to produce a configure script.
+
+AC_PREREQ(2.61)
+AC_INIT([gst-preload], [0.1], [ensonic@users.sf.net])
+AC_CONFIG_SRCDIR([ChangeLog])
+AC_CONFIG_HEADER([config.h])
+
+dnl Initialise the automake tool
+AM_INIT_AUTOMAKE([check-news])
+
+# Checks for programs.
+AC_PROG_CC
+AC_PROG_INSTALL
+AC_PROG_LIBTOOL
+PKG_PROG_PKG_CONFIG
+
+# Checks for libraries.
+# FIXME: Replace `main' with a function in `-lrt':
+AC_CHECK_LIB([rt], [main])
+
+# Checks for header files.
+AC_HEADER_STDC
+AC_CHECK_HEADERS([stdlib.h string.h sys/time.h unistd.h])
+
+# Checks for typedefs, structures, and compiler characteristics.
+AC_C_CONST
+
+# Checks for library functions.
+AC_FUNC_VPRINTF
+AC_CHECK_FUNCS([clock_gettime strerror])
+
+dnl Checks for libraries.
+PKG_CHECK_MODULES(BASE_DEPS, \
+  glib-2.0 >= 2.2.0 gstreamer-0.10 >= 0.10.0 \
+)
+AC_SUBST(BASE_DEPS_LIBS)
+AC_SUBST(BASE_DEPS_CFLAGS)
+
+AC_CONFIG_FILES(
+  Makefile \
+  src/Makefile \
+)
+AC_OUTPUT
diff --git a/src/Makefile.am b/src/Makefile.am
new file mode 100644
index 0000000..9724dd4
--- /dev/null
+++ b/src/Makefile.am
@@ -0,0 +1,8 @@
+lib_LTLIBRARIES = libgstpreload.la
+
+libgstpreload_la_SOURCES = gstpreload.c
+libgstpreload_la_LIBADD = $(BASE_DEPS_LIBS)
+libgstpreload_la_CFLAGS = $(BASE_DEPS_CFLAGS)
+
+EXTRA_DIST =splitlog.py plot.sh
+
diff --git a/src/gstpreload.c b/src/gstpreload.c
new file mode 100644
index 0000000..0352dbd
--- /dev/null
+++ b/src/gstpreload.c
@@ -0,0 +1,273 @@
+/* GStreamer preload library
+ * Copyright (C) <2008> Stefan Kost <ensonic@users.sf.net>
+ *
+ * This library is free software; you can redistribute it and/or
+ * modify it under the terms of the GNU Library General Public
+ * License as published by the Free Software Foundation; either
+ * version 2 of the License, or (at your option) any later version.
+ *
+ * This library is distributed in the hope that it will be useful,
+ * but WITHOUT ANY WARRANTY; without even the implied warranty of
+ * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the GNU
+ * Library General Public License for more details.
+ *
+ * You should have received a copy of the GNU Library General Public
+ * License along with this library; if not, write to the
+ * Free Software Foundation, Inc., 59 Temple Place - Suite 330,
+ * Boston, MA 02111-1307, USA.
+ */
+/* TODO:
+ *
+ */
+
+#include <stdio.h>
+#include <stdlib.h>
+#include <string.h>
+#include <dlfcn.h>
+#include <unistd.h>
+#include <sys/time.h>
+#include <sys/times.h>
+#include <sys/resource.h>
+
+#include <glib.h>
+#include <gst/gst.h>
+
+/* log variables */
+static gchar *gstpl_log_name;
+
+/* global statistics */
+
+#if 0
+GHashTable *buffers_per_pad = NULL;
+#endif
+GHashTable *threads = NULL;
+guint num_threads = 0;
+guint max_cpuload = 0;
+guint max_qos = 0;
+gboolean log_cpu = FALSE;
+
+/* utillity stuff */
+
+GstClockTime _priv_start_time=G_GUINT64_CONSTANT(0);
+
+static GstClockTime
+_get_timestamp (void)
+{
+  struct timespec now;
+
+  clock_gettime (CLOCK_MONOTONIC, &now);
+  return GST_TIMESPEC_TO_TIME (now);
+/*
+  GTimeVal now;
+
+  g_get_current_time (&now);
+  return GST_TIMEVAL_TO_TIME (now);
+*/
+}
+
+FILE *lf = NULL;
+
+static void
+_log_entry (const gchar *fmt, ...)
+{
+  va_list ap;
+  
+  if (G_UNLIKELY(!lf)) {
+    if(!(lf = fopen (gstpl_log_name, "w"))) {
+      fprintf (stderr, "Can't open log file %s : %s", gstpl_log_name, strerror (errno));
+      return;
+    }
+  }
+
+  va_start(ap, fmt);
+  vfprintf (lf, fmt, ap);
+  va_end(ap);
+}
+
+static void
+_log_common (GstClockTimeDiff treal)
+{
+  guint cpuload;
+  struct rusage ru;
+  GstClockTimeDiff tuser, tsys;
+
+  // self is PID, so this is for all threads
+  getrusage (RUSAGE_SELF,&ru);
+  tuser = GST_TIMEVAL_TO_TIME (ru.ru_utime);
+  tsys = GST_TIMEVAL_TO_TIME (ru.ru_stime);
+  if (log_cpu) {
+    // we only want cpu-load in playing
+    cpuload = (guint) gst_util_uint64_scale (tuser+tsys, G_GINT64_CONSTANT(100), treal);
+    if (cpuload <= 100) {
+      if (cpuload > max_cpuload) max_cpuload = cpuload;
+    }
+    else {
+      // this happens during prerolling
+      printf("%" GST_TIME_FORMAT " %u\n", GST_TIME_ARGS (treal), cpuload);
+    }
+  
+    _log_entry(
+      "rusage %" GST_TIME_FORMAT " %" G_GINT64_FORMAT " %u\n",
+      GST_TIME_ARGS (treal), treal, cpuload);
+  }
+
+  gpointer thread_id = g_thread_self();
+  if (!g_hash_table_lookup (threads, thread_id)) {
+    /* FIXME: store some stats for each thread later */
+    g_hash_table_insert (threads, thread_id, (gpointer)1);
+    num_threads++;
+  }
+}
+
+static const gchar*
+_get_pad_name (GstPad *pad)
+{
+  static GHashTable *pad_names = NULL;
+  gchar *pad_name;
+  
+  if (G_UNLIKELY(!pad_names)) {
+    pad_names = g_hash_table_new (NULL,NULL);
+  }
+  if( !(pad_name = g_hash_table_lookup (pad_names, pad))) {
+    // yes we leak thoses ...
+    pad_name = g_strdup_printf ("%s_%s", GST_DEBUG_PAD_NAME (pad));
+    g_hash_table_insert (pad_names, pad, (gpointer)pad_name);
+    //printf ("new pad_name : %p -> %s\n",pad,pad_name);
+  }
+  return pad_name;
+}
+
+/* wrapped api */
+
+static GstFlowReturn (*orig_pad_push) (GstPad *,GstBuffer *) = NULL;
+
+GstFlowReturn
+gst_pad_push (GstPad *pad, GstBuffer *buffer)
+{
+  GstClockTimeDiff elapsed = GST_CLOCK_DIFF (_priv_start_time, _get_timestamp ());
+  const gchar *pad_name = _get_pad_name (pad);
+
+  _log_entry(
+     "pad_%s %" GST_TIME_FORMAT " %" G_GINT64_FORMAT " %u\n",
+     pad_name, GST_TIME_ARGS (elapsed), elapsed, GST_BUFFER_SIZE(buffer));
+  _log_common (elapsed);
+
+  return orig_pad_push (pad, buffer);
+}
+
+static gboolean (*orig_pad_get_range) (GstPad *, guint64, guint, GstBuffer **) = NULL;
+
+GstFlowReturn
+gst_pad_get_range (GstPad * pad, guint64 offset, guint size, GstBuffer ** buffer)
+{
+  GstClockTimeDiff elapsed = GST_CLOCK_DIFF (_priv_start_time, _get_timestamp ());
+
+  _log_entry(
+    "pad_%s %" GST_TIME_FORMAT " %" G_GINT64_FORMAT " %u %"G_GUINT64_FORMAT"\n",
+    _get_pad_name (pad), GST_TIME_ARGS (elapsed), elapsed, size, offset);
+  _log_common (elapsed);
+
+  return orig_pad_get_range (pad, offset, size, buffer);
+}
+
+static gboolean (*orig_pad_send_event) (GstPad *, GstEvent *);
+
+gboolean
+gst_pad_send_event (GstPad *pad, GstEvent *event)
+{
+  GstClockTimeDiff elapsed = GST_CLOCK_DIFF (_priv_start_time, _get_timestamp ());
+
+  switch (GST_EVENT_TYPE (event)) {
+    case GST_EVENT_QOS: {
+      gdouble proportion;
+      guint qos;
+
+      gst_event_parse_qos (event, &proportion, NULL, NULL);
+      qos = (guint)(proportion * 100);
+      if (qos > max_qos) max_qos = qos;
+
+      _log_entry(
+        "qos %" GST_TIME_FORMAT " %" G_GINT64_FORMAT " %u\n",
+        GST_TIME_ARGS (elapsed), elapsed, qos);
+    } break;
+  }
+
+  log_cpu = (GST_STATE (GST_PAD_PARENT (pad)) == GST_STATE_PLAYING);
+
+  _log_common(elapsed);
+  return orig_pad_send_event (pad, event);
+}
+
+/* init/free */
+
+static void
+#if __GNUC__ > 2 || (__GNUC__ == 2 && __GNUC_MINOR__ > 4)
+__attribute__ ((constructor))
+#endif /* !__GNUC__ */
+gst_preload_init (void)
+{
+  void *lib_gstreamer;
+  gchar *errstr;
+
+  if (!g_thread_supported ())
+    g_thread_init (NULL);
+  g_type_init ();
+
+  gst_init(NULL,NULL);
+  
+  /* get configuration */
+  if(!(gstpl_log_name = getenv ("GSTPL_LOG_NAME"))) {
+    gstpl_log_name = "/tmp/gstpl.log";
+  }
+
+  /* init structures to gather stats */
+  threads = g_hash_table_new (NULL,NULL);
+
+  /* load library (abort if not found) */
+  lib_gstreamer = dlopen ("libgstreamer-0.10.so", RTLD_LAZY);
+  if (!lib_gstreamer) {
+    errstr = dlerror ();
+    g_critical ("Failed to load gstreamer library: %s, aborting..",
+      errstr ? errstr : "<No error details>");
+    exit (1);
+  }
+
+  /* get pointer to original functions to chain up */
+  if (!(orig_pad_push = dlsym (lib_gstreamer, "gst_pad_push"))) {
+    errstr = dlerror ();
+    g_critical ("Failed to find gst_pad_push() in gstreamer library: %s, aborting..",
+      errstr ? errstr : "<Symbol is NULL>");
+    exit (1);
+  }
+  if (!(orig_pad_get_range = dlsym (lib_gstreamer, "gst_pad_get_range"))) {
+    errstr = dlerror ();
+    g_critical ("Failed to find gst_pad_get_range() in gstreamer library: %s, aborting..",
+      errstr ? errstr : "<Symbol is NULL>");
+    exit (1);
+  }
+  if (!(orig_pad_send_event = dlsym (lib_gstreamer, "gst_pad_send_event"))) {
+    errstr = dlerror ();
+    g_critical ("Failed to find gst_pad_send_event() in gstreamer library: %s, aborting..",
+      errstr ? errstr : "<Symbol is NULL>");
+    exit (1);
+  }
+
+  _priv_start_time = _get_timestamp ();
+}
+
+static void
+#if __GNUC__ > 2 || (__GNUC__ == 2 && __GNUC_MINOR__ > 4)
+__attribute__ ((destructor))
+#endif /* !__GNUC__ */
+gst_preload_done (void)
+{
+  /* print overall stats */
+  puts("Statistics:");
+  printf("Number of threads : %u\n", num_threads);
+  printf("Max CPU load : %u %%\n", max_cpuload);
+  printf("Max QOS load : %u %%\n", max_qos);
+  
+  /* free ressources */
+  if(lf) fclose(lf);
+  g_hash_table_destroy (threads);
+}
diff --git a/src/plot.sh b/src/plot.sh
new file mode 100644
index 0000000..60accd9
--- /dev/null
+++ b/src/plot.sh
@@ -0,0 +1,9 @@
+#!/bin/sh
+ 
+echo "set term png size 1600, 1200"
+echo "set output 'gstpl.png'"
+echo "plot \\"
+for file in /tmp/gstpl_pad_*.log ; do echo "  '$file' using 2:3 with points, \\"; done
+echo "  '/tmp/gstpl_rusage.log' using 2:3 with lines"
+echo "pause -1"
+
diff --git a/src/splitlog.py b/src/splitlog.py
new file mode 100755
index 0000000..2a006d0
--- /dev/null
+++ b/src/splitlog.py
@@ -0,0 +1,41 @@
+#!/usr/bin/python
+
+import sys, os, os.path
+
+# parse args
+if len(sys.argv) > 1:
+  file_name=sys.argv[1]
+else:
+  file_name='/tmp/gstpl.log'
+
+# get directory name and create dir for results
+(dir_name,ext)=os.path.splitext(file_name)
+if not os.path.exists(dir_name):
+  os.mkdir(dir_name)
+
+
+try:
+  f=open(file_name, 'r')
+except IOError, e:              # catch IOErrors, e is the instance
+  print "Can't open file %s: " % file_name, e # print exception info if thrown
+  exit(1);
+
+
+# iterate over log and split
+fds = {};
+for line in f:
+  (key,sep,data)=line.partition(' ');
+
+  fd=fds.get(key)
+  if fd == None:
+    fd=open("%s/%s.log" % (dir_name,key), 'w')
+    fds[key]=fd
+
+  fd.write(data)
+
+print "spitted %s into %d logs into %s" % (file_name, len(fds), dir_name)
+# close all files
+f.close()
+for fd in fds.values():
+  fd.close()
+