Gather profiling information in caca_refresh_display() and caca_get_event().

bootstrap

@@ -12,7 +12,7 @@
 #    http://sam.zoy.org/wtfpl/COPYING for more details.
 #
 # The latest version of this script can be found at the following place:
-#   http://sam.zoy.org/autotools/
+#   http://caca.zoy.org/wiki/build
 
 # Die if an error occurs
 set -e

caca/Makefile.am

@@ -45,6 +45,7 @@ libcaca_la_SOURCES = \
 	graphics.c \
 	event.c \
 	time.c \
+	prof.c \
 	$(codec_source) \
 	$(driver_source) \
 	$(NULL)

caca/caca.c

@@ -1,6 +1,6 @@
 /*
  *  libcaca       Colour ASCII-Art library
- *  Copyright (c) 2006 Sam Hocevar <sam@zoy.org>
+ *  Copyright (c) 2006-2009 Sam Hocevar <sam@hocevar.net>
  *                All Rights Reserved
  *
  *  $Id$
@@ -327,6 +327,12 @@ static int caca_install_driver(caca_display_t *dp, char const *driver)
 
     dp->timer.last_sec = 0;
     dp->timer.last_usec = 0;
+#if defined PROF
+    _caca_init_stat(&dp->display_stat, "dp[%p] disp_sys time", dp);
+    _caca_init_stat(&dp->wait_stat, "dp[%p] disp_wait time", dp);
+    _caca_init_stat(&dp->ev_sys_stat, "dp[%p] ev_sys time", dp);
+    _caca_init_stat(&dp->ev_wait_stat, "dp[%p] ev_wait time", dp);
+#endif
     dp->lastticks = 0;
 
     /* Mouse position */
@@ -347,6 +353,12 @@ static int caca_uninstall_driver(caca_display_t *dp)
     if(dp->plugin)
         dlclose(dp->plugin);
 #endif
+#if defined PROF
+    _caca_fini_stat(&dp->display_stat);
+    _caca_fini_stat(&dp->wait_stat);
+    _caca_fini_stat(&dp->ev_wait_stat);
+    _caca_fini_stat(&dp->ev_sys_stat);
+#endif
 
     return 0;
 }

caca/caca_internals.h

@@ -1,6 +1,6 @@
 /*
  *  libcaca       Colour ASCII-Art library
- *  Copyright (c) 2002-2006 Sam Hocevar <sam@hocevar.net>
+ *  Copyright (c) 2002-2009 Sam Hocevar <sam@hocevar.net>
  *                All Rights Reserved
  *
  *  $Id$
@@ -24,6 +24,7 @@ typedef struct caca_privevent caca_privevent_t;
 typedef struct caca_figfont caca_figfont_t;
 
 #if !defined(_DOXYGEN_SKIP_ME)
+#   define STAT_VALUES 20
 #   define EVENTBUF_LEN 10
 #   define MAX_DIRTY_COUNT 8
 #endif
@@ -144,6 +145,13 @@ struct caca_timer
     int last_sec, last_usec;
 };
 
+/* Statistic structure for profiling */
+struct caca_stat
+{
+    char *name;
+    int imean, itable[STAT_VALUES];
+};
+
 /* Private event structure */
 struct caca_privevent
 {
@@ -204,6 +212,10 @@ struct caca_display
     /* Framerate handling */
     int delay, rendertime;
     caca_timer_t timer;
+#if defined PROF
+    struct caca_stat display_stat, wait_stat;
+    struct caca_stat ev_sys_stat, ev_wait_stat;
+#endif
     int lastticks;
 
     struct events
@@ -249,4 +261,11 @@ extern int _pop_event(caca_display_t *, caca_privevent_t *);
 /* Internal window functions */
 extern void _caca_set_term_title(char const *);
 
+/* Profiling functions */
+#if defined PROF
+extern void _caca_dump_stats(void);
+extern void _caca_init_stat(struct caca_stat *, char const *, ...);
+extern void _caca_fini_stat(struct caca_stat *);
+#endif
+
 #endif /* __CACA_INTERNALS_H__ */

caca/caca_prof.h

@@ -20,11 +20,25 @@
 
 #if defined PROF && !defined __KERNEL__
 #   define PROFILING_VARS
+
+#   define STAT_IADD(s, n) \
+      do \
+      { \
+        struct caca_stat *ss = s; \
+        int ii, nn = n; \
+        for (ii = STAT_VALUES - 1; ii > 0; ii--) \
+            ss->itable[ii] = ss->itable[ii - 1]; \
+        ss->itable[0] = nn; \
+        ss->imean = ((int64_t)ss->imean * 15 + nn) / 16; \
+      } \
+      while(0)
+
 #   define START_PROF(obj, fn)
 #   define STOP_PROF(obj, fn)
 
 #else
 #   define PROFILING_VARS
+#   define STAT_IADD(s) do { } while(0)
 #   define START_PROF(obj, fn) do { } while(0)
 #   define STOP_PROF(obj, fn) do { } while(0)
 #endif

caca/event.c

@@ -1,6 +1,6 @@
 /*
  *  libcaca       Colour ASCII-Art library
- *  Copyright (c) 2002-2006 Sam Hocevar <sam@zoy.org>
+ *  Copyright (c) 2002-2009 Sam Hocevar <sam@hocevar.net>
  *                All Rights Reserved
  *
  *  $Id$
@@ -67,24 +67,38 @@ int caca_get_event(caca_display_t *dp, int event_mask,
 {
     caca_privevent_t privevent;
     caca_timer_t timer = {0, 0};
-    int usec = 0;
+#if defined PROF
+    caca_timer_t proftimer = {0, 0};
+    int profsys = 0, profwait = 0;
+#endif
+    int ret = 0, usec = 0;
+
+#if defined PROF
+    _caca_getticks(&proftimer);
+#endif
 
     if(!event_mask)
-        return 0;
+        goto end;
 
     if(timeout > 0)
         _caca_getticks(&timer);
 
     for( ; ; )
     {
-        int ret = _get_next_event(dp, &privevent);
+#if defined PROF
+        profwait += _caca_getticks(&proftimer);
+#endif
+        ret = _get_next_event(dp, &privevent);
+#if defined PROF
+        profsys += _caca_getticks(&proftimer);
+#endif
 
         /* If we got the event we wanted, return */
         if(privevent.type & event_mask)
         {
             if(ev)
                 memcpy(ev, &privevent, sizeof(privevent));
-            return ret;
+            goto end;
         }
 
         /* If there is no timeout, sleep and try again. */
@@ -100,18 +114,25 @@ int caca_get_event(caca_display_t *dp, int event_mask,
             privevent.type = CACA_EVENT_NONE;
             if(ev)
                 memcpy(ev, &privevent, sizeof(privevent));
-            return 0;
+            ret = 0;
+            goto end;
         }
 
         /* Otherwise sleep a bit. Our granularity is far too high for values
          * below 10000 microseconds so we cheat a bit. */
-        if(usec > 10000)
-            _caca_sleep(10000);
-        else
-            _caca_sleep(1000);
+        _caca_sleep(usec > 10000 ? 10000 : 1000);
 
         usec += _caca_getticks(&timer);
     }
+
+end:
+#if defined PROF
+    profwait += _caca_getticks(&proftimer);
+    STAT_IADD(&dp->ev_sys_stat, profsys);
+    STAT_IADD(&dp->ev_wait_stat, profwait);
+#endif
+
+    return ret;
 }
 
 /** \brief Return the X mouse coordinate.

caca/graphics.c

@@ -147,12 +147,21 @@ int caca_get_display_time(caca_display_t const *dp)
  */
 int caca_refresh_display(caca_display_t *dp)
 {
+#if defined PROF
+    caca_timer_t proftimer = { 0, 0 };
+#endif
 #if !defined(_DOXYGEN_SKIP_ME)
-#define IDLE_USEC 5000
+#   define IDLE_USEC 5000
 #endif
     int ticks = dp->lastticks + _caca_getticks(&dp->timer);
 
+#if defined PROF
+    _caca_getticks(&proftimer);
+#endif
     dp->drv.display(dp);
+#if defined PROF
+    STAT_IADD(&dp->display_stat, _caca_getticks(&proftimer));
+#endif
 
     /* Invalidate the dirty rectangle */
     caca_clear_dirty_rect_list(dp->cv);
@@ -164,6 +173,9 @@ int caca_refresh_display(caca_display_t *dp)
         _caca_handle_resize(dp);
     }
 
+#if defined PROF
+    _caca_getticks(&proftimer);
+#endif
     /* Wait until dp->delay + time of last call */
     ticks += _caca_getticks(&dp->timer);
     for(ticks += _caca_getticks(&dp->timer);
@@ -172,6 +184,9 @@ int caca_refresh_display(caca_display_t *dp)
     {
         _caca_sleep(IDLE_USEC);
     }
+#if defined PROF
+    STAT_IADD(&dp->wait_stat, _caca_getticks(&proftimer));
+#endif
 
     /* Update the render time */
     dp->rendertime = ticks;
@@ -182,6 +197,10 @@ int caca_refresh_display(caca_display_t *dp)
     if(dp->lastticks > (int)dp->delay)
         dp->lastticks = 0;
 
+#if defined PROF
+    _caca_dump_stats();
+#endif
+
     return 0;
 }
 

caca/libcaca.vcproj

@@ -484,6 +484,10 @@
 			RelativePath="line.c"
 			>
 		</File>
+		<File
+			RelativePath="prof.c"
+			>
+		</File>
 		<File
 			RelativePath="string.c"
 			>

caca/prof.c

@@ -0,0 +1,106 @@
+/*
+ *  libcaca       Colour ASCII-Art library
+ *  Copyright (c) 2009 Sam Hocevar <sam@hocevar.net>
+ *                All Rights Reserved
+ *
+ *  $Id$
+ *
+ *  This library is free software. It comes without any warranty, to
+ *  the extent permitted by applicable law. You can redistribute it
+ *  and/or modify it under the terms of the Do What The Fuck You Want
+ *  To Public License, Version 2, as published by Sam Hocevar. See
+ *  http://sam.zoy.org/wtfpl/COPYING for more details.
+ */
+
+/*
+ *  This file contains profiling functions. They are not supposed to be
+ *  built with release versions.
+ */
+
+#include "config.h"
+
+#if !defined(__KERNEL__)
+#   include <stdio.h>
+#   include <stdarg.h>
+#   include <stdlib.h>
+#endif
+
+#include "caca.h"
+#include "caca_internals.h"
+
+#if defined PROF
+static struct caca_stat **stats = NULL;
+static int nstats = 0;
+
+void _caca_dump_stats(void)
+{
+    int i, j;
+
+    fprintf(stderr, "** libcaca profiling stats **\n");
+
+    for (i = 0; i < nstats; i++)
+    {
+         int64_t total = 0;
+
+         for (j = 0; j < STAT_VALUES; j++)
+             total += stats[i]->itable[j];
+
+         fprintf(stderr, " %s: last %i mean %i sliding mean %i\n",
+                 stats[i]->name, stats[i]->itable[0],
+                 (int)((total + STAT_VALUES / 2) / STAT_VALUES),
+                 stats[i]->imean);
+/*fprintf(stderr, "%i %i %i %i %i %i %i %i %i %i %i %i %i %i %i %i %i %i %i %i\n",
+stats[i]->itable[0], stats[i]->itable[1], stats[i]->itable[2],
+stats[i]->itable[3], stats[i]->itable[4], stats[i]->itable[5],
+stats[i]->itable[6], stats[i]->itable[7], stats[i]->itable[8],
+stats[i]->itable[9], stats[i]->itable[10], stats[i]->itable[11],
+stats[i]->itable[12], stats[i]->itable[13], stats[i]->itable[14],
+stats[i]->itable[15], stats[i]->itable[16], stats[i]->itable[17],
+stats[i]->itable[18], stats[i]->itable[19]);*/
+    }
+
+    fprintf(stderr, "** %i counters dumped **\n", nstats);
+}
+
+void _caca_init_stat(struct caca_stat *s, const char *format, ...)
+{
+    int i;
+
+    s->name = malloc(128 * sizeof(char));
+    va_list args;
+    va_start(args, format);
+    vsnprintf(s->name, 128, format, args);
+    s->name[127] = '\0';
+    va_end(args);
+
+    nstats++;
+    stats = realloc(stats, nstats * sizeof(struct caca_stat *));
+    stats[nstats - 1] = s;
+
+    for (i = 0; i < STAT_VALUES; i++)
+        s->itable[i] = 0;
+    s->imean = 0;
+}
+
+void _caca_fini_stat(struct caca_stat *s)
+{
+    int i, j;
+
+    for (i = 0; i < nstats; i++)
+    {
+        if (stats[i] == s)
+        {
+            free(stats[i]->name);
+
+            for (j = i + 1; j < nstats; j++)
+                stats[j - 1] = stats[j];
+            nstats--;
+            stats = realloc(stats, nstats * sizeof(struct caca_stats *));
+
+            return;
+        }
+    }
+}
+
+#endif
+

configure.ac

@@ -90,8 +90,8 @@ AC_ARG_ENABLE(imlib2,
 dnl conditional builds
 AC_ARG_ENABLE(debug,
   [  --enable-debug          build debug versions of the library (default no)])
-AC_ARG_ENABLE(prof,
-  [  --enable-prof           activate built-in profiling (default no)])
+AC_ARG_ENABLE(profiling,
+  [  --enable-profiling      activate built-in profiling (default no)])
 AC_ARG_ENABLE(plugins,
   [  --enable-plugins        make X11 and GL drivers plugins (default disabled)])
 AC_ARG_ENABLE(doc,
@@ -321,7 +321,7 @@ if test "${enable_debug}" = "yes"; then
   AC_DEFINE(DEBUG, 1, Define to 1 to activate debug)
 fi
 
-if test "${enable_prof}" = "yes"; then
+if test "${enable_profiling}" = "yes"; then
   AC_DEFINE(PROF, 1, Define to 1 to activate profiling)
 fi