Add debugging helpers

2005-02-07  Marco Pesenti Gritti  <marco@gnome.org>

        * Makefile.am:
        * configure.ac:
        * doc/debugging.txt:
        * lib/.cvsignore:
        * lib/Makefile.am:
        * lib/ev-debug.c: (log_module), (trap_handler), (ev_debug_init),
        (ev_profiler_new), (ev_should_profile), (ev_profiler_dump),
        (ev_profiler_free), (ev_profiler_start), (ev_profiler_stop):
        * lib/ev-debug.h:

        Add debugging helpers

        * ps/Makefile.am:
        * ps/ps-document.c: (set_up_page), (start_interpreter),
        (stop_interpreter), (document_load), (ps_document_next_page),
        (ps_document_goto_page), (ps_document_set_page_size),
        (ps_document_widget_event), (ps_document_render):
        * shell/Makefile.am:
        * shell/ev-view.c: (expose_bin_window):
        * shell/main.c: (main):

        Add some logs

13 files changed, 445 insertions, 1 deletions

diff --git a/ChangeLog b/ChangeLog
index 7dd0ac9..f789a60 100644
--- a/ChangeLog
+++ b/ChangeLog
@@ -1,5 +1,30 @@
 2005-02-07  Marco Pesenti Gritti  <marco@gnome.org>
 
+	* Makefile.am:
+	* configure.ac:
+	* doc/debugging.txt:
+	* lib/.cvsignore:
+	* lib/Makefile.am:
+	* lib/ev-debug.c: (log_module), (trap_handler), (ev_debug_init),
+	(ev_profiler_new), (ev_should_profile), (ev_profiler_dump),
+	(ev_profiler_free), (ev_profiler_start), (ev_profiler_stop):
+	* lib/ev-debug.h:
+
+	Add debugging helpers
+
+	* ps/Makefile.am:
+	* ps/ps-document.c: (set_up_page), (start_interpreter),
+	(stop_interpreter), (document_load), (ps_document_next_page),
+	(ps_document_goto_page), (ps_document_set_page_size),
+	(ps_document_widget_event), (ps_document_render):
+	* shell/Makefile.am:
+	* shell/ev-view.c: (expose_bin_window):
+	* shell/main.c: (main):
+
+	Add some logs
+	
+2005-02-07  Marco Pesenti Gritti  <marco@gnome.org>
+
 	* ps/ps-document.c: (ps_document_widget_event):
 
 	Initialize message_window, this should make ps
diff --git a/Makefile.am b/Makefile.am
index 65d886d..5abdb3d 100644
--- a/Makefile.am
+++ b/Makefile.am
@@ -1,4 +1,4 @@
-SUBDIRS = cut-n-paste data backend po pdf dvi ps pixbuf shell
+SUBDIRS = lib cut-n-paste data backend po pdf ps pixbuf shell
 
 intltool_extra = intltool-extract.in intltool-merge.in intltool-update.in
 
diff --git a/configure.ac b/configure.ac
index 5df83b9..226a3bb 100644
--- a/configure.ac
+++ b/configure.ac
@@ -21,6 +21,8 @@ AC_STDC_HEADERS
 AC_PROG_RANLIB
 AC_PROG_INTLTOOL
 
+GNOME_DEBUG_CHECK
+
 ALL_LINGUAS="ca cs da de en_CA ja no nb nl pt_BR sv zh_CN"
 
 AM_GLIB_GNU_GETTEXT
@@ -380,6 +382,7 @@ Makefile
 cut-n-paste/Makefile
 cut-n-paste/recent-files/Makefile
 data/Makefile
+lib/Makefile
 pdf/Makefile
 pdf/goo/Makefile
 pdf/fofi/Makefile
diff --git a/doc/debugging.txt b/doc/debugging.txt
new file mode 100644
index 0000000..11826db
--- /dev/null
+++ b/doc/debugging.txt
@@ -0,0 +1,51 @@
+To enable debugging use the configure option --enable-debug.
+
+LOGGING
+=======
+
+At execution time, you must enable the log service. To enable the
+log service, set the environment variable: EV_LOG_MODULES
+
+EV_LOG_MODULES variable has the form:
+
+	<moduleName>[:<moduleName>]*
+
+moduleName is a filename.
+ex: export EV_LOG_MODULES=ev-window.c:ev-view.c
+The special log module "all" enables all log modules.
+
+Use the LOG macro to put debug messages in the code.
+
+WARNINGS
+========
+
+At execution time, you must enable the service. To enable you to debug
+warnings, set the environment variable: EV_DEBUG_BREAK
+
+Possibe value for EV_DEBUG_BREAK variable:
+
+	stack		Prints a stack trace.
+
+	suspend		Use this to stop execution when a warning occurs.
+			You can then attach a debugger to the process.
+
+	trap		Use this while running epiphany in a debugger.
+			This makes execution stop and gives back control to
+			the debugger.
+
+
+PROFILING
+=========
+
+At execution time, you must enable the profiling service. To enable the
+profiling service, set the environment variable: EV_PROFILING_MODULES
+
+EV_PROFILE_MODULES variable has the form:
+
+	<moduleName>[:<moduleName>]*
+
+moduleName is a filename.
+ex: export EV_PROFILE_MODULES=ephy-window.c:ephy-autocompletion.c
+The special profiling module "all" enables all profiling modules.
+
+Use START_PROFILER STOP_PROFILER macros to profile pieces of code.
diff --git a/lib/.cvsignore b/lib/.cvsignore
new file mode 100644
index 0000000..70845e0
--- /dev/null
+++ b/lib/.cvsignore
@@ -0,0 +1 @@
+Makefile.in
diff --git a/lib/Makefile.am b/lib/Makefile.am
new file mode 100644
index 0000000..9a3bd51
--- /dev/null
+++ b/lib/Makefile.am
@@ -0,0 +1,15 @@
+NULL=
+
+INCLUDES=					\
+	-DEVINCE_UIDIR=\"$(pkgdatadir)\"	\
+	-DGNOMELOCALEDIR=\"$(datadir)/locale\"	\
+	$(SHELL_CFLAGS)				\
+	$(EVINCE_DISABLE_DEPRECATED)		\
+	$(NULL)
+
+noinst_LTLIBRARIES = libev.la
+
+libev_la_SOURCES=				\
+	ev-debug.c				\
+	ev-debug.h				\
+	$(NULL)
diff --git a/lib/ev-debug.c b/lib/ev-debug.c
new file mode 100644
index 0000000..8648e2d
--- /dev/null
+++ b/lib/ev-debug.c
@@ -0,0 +1,239 @@
+/*
+ *  Copyright (C) 2003 Marco Pesenti Gritti
+ *
+ *  This program is free software; you can redistribute it and/or modify
+ *  it under the terms of the GNU General Public License as published by
+ *  the Free Software Foundation; either version 2, or (at your option)
+ *  any later version.
+ *
+ *  This program 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 General Public License for more details.
+ *
+ *  You should have received a copy of the GNU General Public License
+ *  along with this program; if not, write to the Free Software
+ *  Foundation, Inc., 59 Temple Place - Suite 330, Boston, MA 02111-1307, USA.
+ *
+ *  $Id$
+ */
+
+#include "config.h"
+
+#include "ev-debug.h"
+
+#ifndef DISABLE_PROFILING
+
+#include <glib/gbacktrace.h>
+#include <string.h>
+#include <signal.h>
+#include <stdio.h>
+#include <stdlib.h>
+#include <execinfo.h>
+
+static GHashTable *ev_profilers_hash = NULL;
+static const char *ev_profile_modules = NULL;
+static const char *ev_debug_break = NULL;
+
+#endif
+
+#ifndef DISABLE_LOGGING
+
+static const char *ev_log_modules;
+
+static void
+log_module (const gchar *log_domain,
+	    GLogLevelFlags log_level,
+	    const gchar *message,
+	    gpointer user_data)
+{
+	gboolean should_log = FALSE;
+
+	if (!ev_log_modules) return;
+
+	if (strcmp (ev_log_modules, "all") != 0)
+	{
+		char **modules;
+		int i;
+
+		modules = g_strsplit (ev_log_modules, ":", 100);
+
+		for (i = 0; modules[i] != NULL; i++)
+		{
+			if (strstr (message, modules [i]) != NULL)
+			{
+				should_log = TRUE;
+				break;
+			}
+		}
+
+		g_strfreev (modules);
+	}
+	else
+	{
+		should_log = TRUE;
+	}
+
+	if (should_log)
+	{
+		g_print ("%s\n", message);
+	}
+}
+
+#define MAX_DEPTH 200
+
+static void 
+trap_handler (const char *log_domain,
+	      GLogLevelFlags log_level,
+	      const char *message,
+	      gpointer user_data)
+{
+	g_log_default_handler (log_domain, log_level, message, user_data);
+
+	if (ev_debug_break != NULL &&
+	    (log_level & (G_LOG_LEVEL_WARNING |
+			  G_LOG_LEVEL_ERROR |
+			  G_LOG_LEVEL_CRITICAL |
+			  G_LOG_FLAG_FATAL)))
+	{
+		if (strcmp (ev_debug_break, "stack") == 0)
+		{
+			void *array[MAX_DEPTH];
+			size_t size;
+			
+			size = backtrace (array, MAX_DEPTH);
+			backtrace_symbols_fd (array, size, 2);
+		}
+		else if (strcmp (ev_debug_break, "trap") == 0)
+		{
+			G_BREAKPOINT ();
+		}
+		else if (strcmp (ev_debug_break, "suspend") == 0)
+		{
+			g_print ("Suspending program; attach with the debugger.\n");
+
+			raise (SIGSTOP);
+		}
+	}
+}
+
+#endif
+
+void
+ev_debug_init (void)
+{
+#ifndef DISABLE_LOGGING
+	ev_log_modules = g_getenv ("EV_LOG_MODULES");
+	ev_debug_break = g_getenv ("EV_DEBUG_BREAK");
+
+	g_log_set_default_handler (trap_handler, NULL);
+
+	g_log_set_handler (G_LOG_DOMAIN, G_LOG_LEVEL_DEBUG, log_module, NULL);
+
+#endif
+#ifndef DISABLE_PROFILING
+	ev_profile_modules = g_getenv ("EV_PROFILE_MODULES");
+#endif
+}
+
+#ifndef DISABLE_PROFILING
+
+static EvProfiler *
+ev_profiler_new (const char *name, const char *module)
+{
+	EvProfiler *profiler;
+
+	profiler = g_new0 (EvProfiler, 1);
+	profiler->timer = g_timer_new ();
+	profiler->name  = g_strdup (name);
+	profiler->module  = g_strdup (module);
+
+	g_timer_start (profiler->timer);
+
+	return profiler;
+}
+
+static gboolean
+ev_should_profile (const char *module)
+{
+	char **modules;
+	int i;
+	gboolean res = FALSE;
+
+	if (!ev_profile_modules) return FALSE;
+	if (strcmp (ev_profile_modules, "all") == 0) return TRUE;
+
+	modules = g_strsplit (ev_profile_modules, ":", 100);
+
+	for (i = 0; modules[i] != NULL; i++)
+	{
+		if (strcmp (module, modules [i]) == 0)
+		{
+			res = TRUE;
+			break;
+		}
+	}
+
+	g_strfreev (modules);
+
+	return res;
+}
+
+static void
+ev_profiler_dump (EvProfiler *profiler)
+{
+	double seconds;
+
+	g_return_if_fail (profiler != NULL);
+
+	seconds = g_timer_elapsed (profiler->timer, NULL);
+
+	g_print ("[ %s ] %s %f s elapsed\n",
+		 profiler->module, profiler->name,
+		 seconds);
+}
+
+static void
+ev_profiler_free (EvProfiler *profiler)
+{
+	g_return_if_fail (profiler != NULL);
+
+	g_timer_destroy (profiler->timer);
+	g_free (profiler->name);
+	g_free (profiler->module);
+	g_free (profiler);
+}
+
+void
+ev_profiler_start (const char *name, const char *module)
+{
+	EvProfiler *profiler;
+
+	if (ev_profilers_hash == NULL)
+	{
+		ev_profilers_hash =
+			g_hash_table_new_full (g_str_hash, g_str_equal,
+					       g_free, NULL);
+	}
+
+	if (!ev_should_profile (module)) return;
+
+	profiler = ev_profiler_new (name, module);
+
+	g_hash_table_insert (ev_profilers_hash, g_strdup (name), profiler);
+}
+
+void
+ev_profiler_stop (const char *name)
+{
+	EvProfiler *profiler;
+
+	profiler = g_hash_table_lookup (ev_profilers_hash, name);
+	if (profiler == NULL) return;
+	g_hash_table_remove (ev_profilers_hash, name);
+
+	ev_profiler_dump (profiler);
+	ev_profiler_free (profiler);
+}
+
+#endif
diff --git a/lib/ev-debug.h b/lib/ev-debug.h
new file mode 100644
index 0000000..2c4c521
--- /dev/null
+++ b/lib/ev-debug.h
@@ -0,0 +1,74 @@
+/*
+ *  Copyright (C) 2003 Marco Pesenti Gritti
+ *
+ *  This program is free software; you can redistribute it and/or modify
+ *  it under the terms of the GNU General Public License as published by
+ *  the Free Software Foundation; either version 2, or (at your option)
+ *  any later version.
+ *
+ *  This program 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 General Public License for more details.
+ *
+ *  You should have received a copy of the GNU General Public License
+ *  along with this program; if not, write to the Free Software
+ *  Foundation, Inc., 59 Temple Place - Suite 330, Boston, MA 02111-1307, USA.
+ *
+ *  $Id$
+ */
+
+#ifndef EV_DEBUG_H
+#define EV_DEBUG_H
+
+#include "config.h"
+
+#include <glib.h>
+
+G_BEGIN_DECLS
+
+#ifndef GNOME_ENABLE_DEBUG
+#define DISABLE_LOGGING
+#define DISABLE_PROFILING
+#endif
+
+#ifdef DISABLE_LOGGING
+#define LOG(msg, args...)
+#else
+#define LOG(msg, args...)						\
+g_log (G_LOG_DOMAIN, G_LOG_LEVEL_DEBUG,				\
+       "[ %s ] " msg,						\
+       __FILE__ , ## args);
+#endif
+
+#ifdef DISABLE_PROFILING
+#define START_PROFILER(name)
+#define STOP_PROFILER(name)
+#else
+#define START_PROFILER(name)	\
+ev_profiler_start (name, __FILE__);
+#define STOP_PROFILER(name)	\
+ev_profiler_stop (name);
+#endif
+
+typedef struct
+{
+	GTimer *timer;
+	char *name;
+	char *module;
+} EvProfiler;
+
+void		ev_debug_init		(void);
+
+#ifndef DISABLE_PROFILING
+
+void		ev_profiler_start	(const char *name,
+					 const char *module);
+
+void		ev_profiler_stop	(const char *name);
+
+#endif
+
+G_END_DECLS
+
+#endif
diff --git a/ps/Makefile.am b/ps/Makefile.am
index 0752d2f..ca949d4 100644
--- a/ps/Makefile.am
+++ b/ps/Makefile.am
@@ -1,6 +1,7 @@
 INCLUDES = \
 	-I$(top_srcdir)						\
 	-I$(top_srcdir)/backend					\
+	-I$(top_srcdir)/lib					\
 	-DGNOMEICONDIR=\""${prefix}/${DATADIRNAME}/pixmaps"\" 	\
 	$(PS_CFLAGS)
 
diff --git a/ps/ps-document.c b/ps/ps-document.c
index 7573771..0e4f369 100644
--- a/ps/ps-document.c
+++ b/ps/ps-document.c
@@ -150,6 +150,7 @@ The DONE message indicates that ghostscript has finished processing.
 #include <math.h>
 
 #include "ps-document.h"
+#include "ev-debug.h"
 #include "gsdefaults.h"
 
 #ifdef HAVE_LOCALE_H
@@ -483,6 +484,8 @@ set_up_page(PSDocument * gs)
   GdkColor white = { 0, 0xFFFF, 0xFFFF, 0xFFFF };   /* pixel, r, g, b */
   GdkColormap *colormap;
 
+  LOG ("Setup the page")
+
 #ifdef HAVE_LOCALE_H
   char *savelocale;
 #endif
@@ -512,6 +515,7 @@ set_up_page(PSDocument * gs)
           gs->bpixmap = NULL;
         }
 
+        LOG ("Create our internal pixmap")
         gs->bpixmap = gdk_pixmap_new(gs->pstarget, gs->width, gs->height, -1);
 
         gdk_draw_rectangle(gs->bpixmap, fill, TRUE,
@@ -711,6 +715,8 @@ start_interpreter(PSDocument * gs)
   int std_out[2];               /* pipe from interp stdout */
   int std_err[2];               /* pipe from interp stderr */
 
+  LOG ("Start the interpreter")
+
 #define NUM_ARGS    100
 #define NUM_GS_ARGS (NUM_ARGS - 20)
 #define NUM_ALPHA_ARGS 10
@@ -815,6 +821,8 @@ start_interpreter(PSDocument * gs)
 			     gdk_x11_drawable_get_xid(gs->bpixmap));
     putenv(gv_env);
 
+    LOG ("Launching ghostview with env %s", gv_env)
+
     /* change to directory where the input file is. This helps
      * with postscript-files which include other files using
      * a relative path */
@@ -862,6 +870,7 @@ stop_interpreter(PSDocument * gs)
 {
   if(gs->interpreter_pid > 0) {
     int status = 0;
+    LOG ("Stop the interpreter")
     kill(gs->interpreter_pid, SIGTERM);
     while((wait(&status) == -1) && (errno == EINTR)) ;
     gs->interpreter_pid = -1;
@@ -1285,6 +1294,8 @@ document_load(PSDocument * gs, const gchar * fname)
   g_return_val_if_fail(gs != NULL, FALSE);
   g_return_val_if_fail(GTK_IS_GS(gs), FALSE);
 
+  LOG ("Load the document")
+
   /* clean up previous document */
   ps_document_cleanup(gs);
 
@@ -1391,6 +1402,8 @@ ps_document_next_page(PSDocument * gs)
 {
   XEvent event;
 
+  LOG ("Make ghostscript render next page")
+
   g_return_val_if_fail(gs != NULL, FALSE);
   g_return_val_if_fail(GTK_IS_GS(gs), FALSE);
 
@@ -1449,6 +1462,8 @@ ps_document_goto_page(PSDocument * gs, gint page)
   g_return_val_if_fail(gs != NULL, FALSE);
   g_return_val_if_fail(GTK_IS_GS(gs), FALSE);
 
+  LOG ("Go to page %d", page)
+
   if(!gs->gs_filename) {
     return FALSE;
   }
@@ -1458,6 +1473,9 @@ ps_document_goto_page(PSDocument * gs, gint page)
     page = 0;
 
   if(gs->structured_doc && gs->doc) {
+
+    LOG ("It's a structured document, let's send one page to gs")
+
     if(page >= gs->doc->numpages)
       page = gs->doc->numpages - 1;
 
@@ -1498,6 +1516,9 @@ ps_document_goto_page(PSDocument * gs, gint page)
        the last page of the file was displayed. In that
        case, ggv restarts GS again and the first page is displayed.
      */
+
+    LOG ("It's an unstructured document, gs will just read the file")
+
     if(page == gs->current_page && !gs->changed)
       return TRUE;
 
@@ -1530,6 +1551,8 @@ ps_document_set_page_size(PSDocument * gs, gint new_pagesize, gint pageid)
   gint new_ury = 0;
   GtkGSPaperSize *papersizes = gtk_gs_defaults_get_paper_sizes();
 
+  LOG ("Set the page size")
+
   g_return_val_if_fail(gs != NULL, FALSE);
   g_return_val_if_fail(GTK_IS_GS(gs), FALSE);
 
@@ -1736,6 +1759,7 @@ ps_document_widget_event (GtkWidget *widget, GdkEvent *event, gpointer data)
 	gs->message_window = event->client.data.l[0];
 
 	if (event->client.message_type == gs_class->page_atom) {
+		LOG ("GS rendered the document")
 		gs->busy = FALSE;
 		ev_document_changed (EV_DOCUMENT (gs));
 	}
@@ -1838,6 +1862,10 @@ ps_document_render (EvDocument  *document,
 			   draw.x, draw.y,
 			   draw.width, draw.height);
 
+	LOG ("Copy the internal pixmap: %d %d %d %d %d %d",
+             draw.x - page.x, draw.y - page.y,
+             draw.x, draw.y, draw.width, draw.height)
+
 	g_object_unref (gc);
 }
 
diff --git a/shell/Makefile.am b/shell/Makefile.am
index ad53afe..0d73ffe 100644
--- a/shell/Makefile.am
+++ b/shell/Makefile.am
@@ -52,6 +52,7 @@ evince_SOURCES=				\
 
 evince_LDADD=						\
 	$(SHELL_LIBS)					\
+	$(top_builddir)/lib/libev.la			\
 	$(top_builddir)/pdf/xpdf/libpdfdocument.la 	\
 	$(top_builddir)/pixbuf/libpixbufdocument.la	\
 	$(top_builddir)/ps/libgtkgs.la			\
diff --git a/shell/ev-view.c b/shell/ev-view.c
index 587b258..d4fa6a2 100644
--- a/shell/ev-view.c
+++ b/shell/ev-view.c
@@ -29,6 +29,7 @@
 #include "ev-marshal.h"
 #include "ev-view.h"
 #include "ev-document-find.h"
+#include "ev-debug.h"
 
 #define EV_VIEW_CLASS(klass)    (G_TYPE_CHECK_CLASS_CAST ((klass), EV_TYPE_VIEW, EvViewClass))
 #define EV_IS_VIEW_CLASS(klass) (G_TYPE_CHECK_CLASS_TYPE ((klass), EV_TYPE_VIEW))
@@ -408,6 +409,9 @@ expose_bin_window (GtkWidget      *widget,
 				     x_offset + 1,
 				     y_offset + 1);
 
+	LOG ("Render area %d %d %d %d", event->area.x, event->area.y,
+             event->area.width, event->area.height)
+
 	ev_document_render (view->document,
 			    event->area.x, event->area.y,
 			    event->area.width, event->area.height);
diff --git a/shell/main.c b/shell/main.c
index fcda1f1..c162935 100644
--- a/shell/main.c
+++ b/shell/main.c
@@ -29,6 +29,7 @@
 #include <libgnomevfs/gnome-vfs-utils.h>
 
 #include "ev-stock-icons.h"
+#include "ev-debug.h"
 
 static struct poptOption popt_options[] =
 {
@@ -83,6 +84,7 @@ main (int argc, char *argv[])
 
 	g_set_application_name (_("Evince Document Viewer"));
 
+	ev_debug_init ();
 	ev_stock_icons_init ();
 
 	g_object_get_property (G_OBJECT (program),