Add a profile mode available when debug is enabled. Add profilers in

2008-07-27  Carlos Garcia Campos  <carlosgc@gnome.org>

	* libdocument/ev-debug.[ch]: (ev_profiler_start),
	(ev_profiler_stop):
	* shell/ev-jobs.c: (ev_job_finished), (ev_job_links_run),
	(notify_page_ready), (ev_job_render_run), (ev_job_thumbnail_run),
	(ev_job_fonts_run), (ev_job_load_run), (ev_job_save_run),
	(ev_job_print_run):
	* shell/main.c: (main):

	Add a profile mode available when debug is enabled. Add profilers
	in ev-jobs.

svn path=/trunk/; revision=3086

2 files changed, 136 insertions, 13 deletions

diff --git a/libdocument/ev-debug.c b/libdocument/ev-debug.c
index 3806fd4..911521b 100644
--- a/libdocument/ev-debug.c
+++ b/libdocument/ev-debug.c
@@ -42,9 +42,12 @@
 
 #ifdef EV_ENABLE_DEBUG
 static EvDebugSection ev_debug = EV_NO_DEBUG;
+static EvProfileSection ev_profile = EV_NO_PROFILE;
 
-void
-ev_debug_init ()
+static GHashTable *timers = NULL;
+
+static void
+debug_init ()
 {
 	if (g_getenv ("EV_DEBUG") != NULL) {
 		/* enable all debugging */
@@ -56,6 +59,42 @@ ev_debug_init ()
 		ev_debug |= EV_DEBUG_JOBS;
 }
 
+static void
+profile_init ()
+{
+	if (g_getenv ("EV_PROFILE") != NULL) {
+		/* enable all profiling */
+		ev_profile = ~EV_NO_PROFILE;
+		return;
+	}	
+
+	if (g_getenv ("EV_PROFILE_JOBS") != NULL)
+		ev_profile |= EV_PROFILE_JOBS;
+
+	if (ev_profile) {
+		timers = g_hash_table_new_full (g_str_hash,
+						g_str_equal,
+						(GDestroyNotify) g_free,
+						(GDestroyNotify) g_timer_destroy);
+	}
+}
+
+void
+ev_debug_init ()
+{
+	debug_init ();
+	profile_init ();
+}
+
+void
+ev_debug_shutdown ()
+{
+	if (timers) {
+		g_hash_table_destroy (timers);
+		timers = NULL;
+	}
+}
+
 void
 ev_debug_message (EvDebugSection  section,
 		  const gchar    *file,
@@ -82,4 +121,58 @@ ev_debug_message (EvDebugSection  section,
 	}
 }
 
+void
+ev_profiler_start (EvProfileSection section,
+		   const gchar     *format, ...)
+{
+	if (G_UNLIKELY (ev_profile & section)) {
+		GTimer *timer;
+		gchar  *name;
+		va_list args;
+
+		if (!format)
+			return;
+
+		va_start (args, format);
+		name = g_strdup_vprintf (format, args);
+		va_end (args);
+
+		timer = g_hash_table_lookup (timers, name);
+		if (!timer) {
+			timer = g_timer_new ();
+			g_hash_table_insert (timers, g_strdup (name), timer);
+		} else {
+			g_timer_start (timer);
+		}
+	}
+}
+
+void
+ev_profiler_stop (EvProfileSection section,
+		  const gchar     *format, ...)
+{
+	if (G_UNLIKELY (ev_profile & section)) {
+		GTimer *timer;
+		gchar  *name;
+		va_list args;
+		gdouble seconds;
+
+		if (!format)
+			return;
+
+		va_start (args, format);
+		name = g_strdup_vprintf (format, args);
+		va_end (args);
+		
+		timer = g_hash_table_lookup (timers, name);
+		if (!timer)
+			return;
+		
+		g_timer_stop (timer);
+		seconds = g_timer_elapsed (timer, NULL);
+		g_print ("[ %s ] %f s elapsed\n", name, seconds);
+		fflush (stdout);
+	}
+}
+
 #endif /* EV_ENABLE_DEBUG */
diff --git a/libdocument/ev-debug.h b/libdocument/ev-debug.h
index b025597..c8b8a34 100644
--- a/libdocument/ev-debug.h
+++ b/libdocument/ev-debug.h
@@ -35,12 +35,29 @@
 #ifndef __EV_DEBUG_H__
 #define __EV_DEBUG_H__
 
-#include <glib.h>
+#include <glib-object.h>
+
+#define EV_GET_TYPE_NAME(instance) g_type_name_from_instance ((gpointer)instance)
 
 #ifndef EV_ENABLE_DEBUG
+
 #define ev_debug_init()
-#define ev_debug_message(...)
-#else
+#define ev_debug_shutdown()
+#if defined(G_HAVE_GNUC_VARARGS)
+#define ev_debug_message(section, format, args...) G_STMT_START { } G_STMT_END
+#define ev_profiler_start(format, args...) G_STMT_START { } G_STMT_END
+#define ev_profiler_stop(format, args...) G_STMT_START { } G_STMT_END
+#elif defined(G_HAVE_ISO_VARARGS)
+#define ev_debug_message(...) G_STMT_START { } G_STMT_END
+#define ev_profiler_start(...) G_STMT_START { } G_STMT_END
+#define ev_profiler_stop(...) G_STMT_START { } G_STMT_END
+#else /* no varargs macros */
+static void ev_debug_message(EvDebugSection section, const gchar *file, gint line, const gchar *function, const gchar *format, ...) {}
+static void ev_profiler_start(EvProfileSection section,	const gchar *format, ...) {}
+static void ev_profiler_stop(EvProfileSection section, const gchar *format, ...) {}
+#endif
+
+#else /* ENABLE_DEBUG */
 
 G_BEGIN_DECLS
 
@@ -54,17 +71,30 @@ typedef enum {
 	EV_DEBUG_JOBS        = 1 << 0
 } EvDebugSection;
 
+#define DEBUG_JOBS      EV_DEBUG_JOBS,    __FILE__, __LINE__, G_STRFUNC
 
-#define	DEBUG_JOBS	EV_DEBUG_JOBS,    __FILE__, __LINE__, G_STRFUNC
-
-void ev_debug_init (void);
+/*
+ * Set an environmental var of the same name to turn on
+ * profiling. Setting EV_PROFILE will turn on all
+ * sections.
+ */
+typedef enum {
+	EV_NO_PROFILE   = 0,
+	EV_PROFILE_JOBS = 1 << 0
+} EvProfileSection;
 
-void ev_debug_message (EvDebugSection  section,
-		       const gchar    *file,
-		       gint            line,
-		       const gchar    *function,
-		       const gchar    *format, ...) G_GNUC_PRINTF(5, 6);
+void ev_debug_init     (void);
+void ev_debug_shutdown (void);
 
+void ev_debug_message  (EvDebugSection   section,
+			const gchar     *file,
+			gint             line,
+			const gchar     *function,
+			const gchar     *format, ...) G_GNUC_PRINTF(5, 6);
+void ev_profiler_start (EvProfileSection section,
+			const gchar     *format, ...) G_GNUC_PRINTF(2, 3);
+void ev_profiler_stop  (EvProfileSection section,
+			const gchar     *format, ...) G_GNUC_PRINTF(2, 3);
 
 G_END_DECLS