Run-time debugging printout change for gmain.c

[Tor Lillqvist <tml iki fi>]

Would it be OK to commit this? This does:

- Drop the compile-time G_MAIN_POLL_DEBUG setting from gmain.c.

- Instead, if G_EMABLE_DEBUG is on, you can turn on the debugging
printout at run-time through an environment variable called
(surprise...)  G_MAIN_POLL_DEBUG.

- Use g_printerr() and not g_print(). Debugging printout is more
suitable for stderr, isn't it?

- Change the output format in g_main_context_poll() a bit.

It's mostly the Win32 implementation of g_poll() that has much
debugging spew.

Actually, I would like to overhaul all of the debug printout stuff in
GLib and GTK+ (i.e. GDK_NOTE() and GTK_NOTE()). Especially on Win32
staring at debugging printouts is essential when hacking on new and
weird stuff (think gtkplug/socket, gconf, libbonoboui, etc). Required
features would be:

- Optional run-time redirection of debugging printout to per-process
files or syslog/OutputDebugString.

- If one file shared between several processes, maybe some locking not
to get output from different processes mixed on the same line, but one
output line from one process only.

- Timestamps?

etc. Comments, please?

--tml

Index: glib/gmain.c
===================================================================
RCS file: /cvs/gnome/glib/glib/gmain.c,v
retrieving revision 1.126
diff -u -2 -r1.126 gmain.c
--- glib/gmain.c	14 Mar 2005 04:26:57 -0000	1.126
+++ glib/gmain.c	24 Mar 2005 15:14:27 -0000
@@ -34,7 +34,4 @@
 #include "config.h"
 
-/* uncomment the next line to get poll() debugging info */
-/* #define G_MAIN_POLL_DEBUG */
-
 #include "glib.h"
 #include "gthreadinit.h"
@@ -79,4 +76,10 @@
 #include "galias.h"
 
+#ifdef G_OS_WIN32
+#define FD_FORMAT "%#x"
+#else
+#define FD_FORMAT "%d"
+#endif
+
 /* Types */
 
@@ -299,4 +302,10 @@
 };
 
+#ifdef G_ENABLE_DEBUG
+static gboolean g_main_poll_debug = FALSE;
+#else
+#define g_main_poll_debug 0
+#endif 
+
 #ifdef HAVE_POLL
 /* SunOS has poll, but doesn't provide a prototype. */
@@ -333,7 +342,7 @@
 	else
 	  {
-#ifdef G_MAIN_POLL_DEBUG
-	    g_print ("g_poll: waiting for %#x\n", f->fd);
-#endif
+	    if (g_main_poll_debug)
+	      g_printerr ("g_poll: waiting for %#x\n", f->fd);
+
 	    handles[nhandles++] = (HANDLE) f->fd;
 	  }
@@ -348,7 +357,7 @@
        * -> First PeekMessage
        */
-#ifdef G_MAIN_POLL_DEBUG
-      g_print ("PeekMessage\n");
-#endif
+      if (g_main_poll_debug)
+	g_printerr ("PeekMessage\n");
+
       if (PeekMessage (&msg, NULL, 0, 0, PM_NOREMOVE))
 	ready = WAIT_OBJECT_0 + nhandles;
@@ -363,7 +372,7 @@
 		   * -> WaitMessage
 		   */
-#ifdef G_MAIN_POLL_DEBUG
-		  g_print ("WaitMessage\n");
-#endif
+		  if (g_main_poll_debug)
+		    g_printerr ("WaitMessage\n");
+
 		  if (!WaitMessage ())
 		    {
@@ -397,12 +406,12 @@
 		  else
 		    {
-#ifdef G_MAIN_POLL_DEBUG
-		      g_print ("WaitMessage\n");
-#endif
+		      if (g_main_poll_debug)
+			g_printerr ("WaitMessage\n");
+
 		      WaitMessage ();
 		      KillTimer (NULL, timer);
-#ifdef G_MAIN_POLL_DEBUG
-		      g_print ("PeekMessage\n");
-#endif
+		      if (g_main_poll_debug)
+			g_printerr ("PeekMessage\n");
+
 		      if (PeekMessage (&msg, NULL, 0, 0, PM_NOREMOVE)
 			  && msg.message != WM_TIMER)
@@ -418,7 +427,7 @@
 	       * -> Use MsgWaitForMultipleObjects
 	       */
-#ifdef G_MAIN_POLL_DEBUG
-	      g_print ("MsgWaitForMultipleObjects(%d, %d)\n", nhandles, timeout);
-#endif
+	      if (g_main_poll_debug)
+		g_printerr ("MsgWaitForMultipleObjects(%d, %d)\n", nhandles, timeout);
+
 	      ready = MsgWaitForMultipleObjects (nhandles, handles, FALSE,
 						 timeout, QS_ALLINPUT);
@@ -443,7 +452,7 @@
        * -> Use WaitForMultipleObjects
        */
-#ifdef G_MAIN_POLL_DEBUG
-      g_print ("WaitForMultipleObjects(%d, %d)\n", nhandles, timeout);
-#endif
+      if (g_main_poll_debug)
+	g_printerr ("WaitForMultipleObjects(%d, %d)\n", nhandles, timeout);
+
       ready = WaitForMultipleObjects (nhandles, handles, FALSE, timeout);
       if (ready == WAIT_FAILED)
@@ -455,11 +464,11 @@
     }
 
-#ifdef G_MAIN_POLL_DEBUG
-  g_print ("wait returns %ld%s\n",
-	   ready,
-	   (ready == WAIT_FAILED ? " (WAIT_FAILED)" :
-	    (ready == WAIT_TIMEOUT ? " (WAIT_TIMEOUT)" :
-	     (poll_msgs && ready == WAIT_OBJECT_0 + nhandles ? " (msg)" : ""))));
-#endif
+  if (g_main_poll_debug)
+    g_printerr ("wait returns %ld%s\n",
+		ready,
+		(ready == WAIT_FAILED ? " (WAIT_FAILED)" :
+		 (ready == WAIT_TIMEOUT ? " (WAIT_TIMEOUT)" :
+		  (poll_msgs && ready == WAIT_OBJECT_0 + nhandles ? " (msg)" : ""))));
+
   for (f = fds; f < &fds[nfds]; ++f)
     f->revents = 0;
@@ -483,4 +492,5 @@
     for (f = fds; f < &fds[nfds]; ++f)
       {
+#if 0
 	if ((f->events & (G_IO_IN | G_IO_OUT))
 	    && f->fd == (gint) handles[ready - WAIT_OBJECT_0])
@@ -490,7 +500,12 @@
 	    else
 	      f->revents |= G_IO_OUT;
-#ifdef G_MAIN_POLL_DEBUG
-	    g_print ("g_poll: got event %#x\n", f->fd);
+#else
+	if (f->fd == (gint) handles[ready - WAIT_OBJECT_0])
+	  {
+	    f->revents = f->events;
 #endif
+	    if (g_main_poll_debug)
+	      g_printerr ("g_poll: got event %#x\n", f->fd);
+
 #if 0
 	    ResetEvent ((HANDLE) f->fd);
@@ -710,7 +725,6 @@
   context->wake_up_rec.fd = (gint) context->wake_up_semaphore;
   context->wake_up_rec.events = G_IO_IN;
-#  ifdef G_MAIN_POLL_DEBUG
-  g_print ("wake-up semaphore: %#x\n", (guint) context->wake_up_semaphore);
-#  endif
+  if (g_main_poll_debug)
+    g_printerr ("wake-up semaphore: %#x\n", (guint) context->wake_up_semaphore);
 # endif
   g_main_context_add_poll_unlocked (context, 0, &context->wake_up_rec);
@@ -803,8 +817,21 @@
 g_main_context_default (void)
 {
+#ifdef G_ENABLE_DEBUG
+  static gboolean beenhere = FALSE;
+#endif
+
   /* Slow, but safe */
   
   G_LOCK (main_loop);
 
+#ifdef G_ENABLE_DEBUG
+  if (!beenhere)
+    {
+      beenhere = TRUE;
+      if (getenv ("G_MAIN_POLL_DEBUG") != NULL)
+	g_main_poll_debug = TRUE;
+    }
+#endif
+
   if (!default_main_context)
     default_main_context = g_main_context_new ();
@@ -2860,5 +2887,5 @@
 		     gint          n_fds)
 {
-#ifdef  G_MAIN_POLL_DEBUG
+#ifdef  G_ENABLE_DEBUG
   GTimer *poll_timer;
   GPollRec *pollrec;
@@ -2870,8 +2897,9 @@
   if (n_fds || timeout != 0)
     {
-#ifdef	G_MAIN_POLL_DEBUG
-      g_print ("g_main_poll(%d) timeout: %d\n", n_fds, timeout);
-      poll_timer = g_timer_new ();
-#endif
+      if (g_main_poll_debug)
+	{
+	  g_printerr ("g_main_poll(%d) timeout: %d\n", n_fds, timeout);
+	  poll_timer = g_timer_new ();
+	}
 
       LOCK_CONTEXT (context);
@@ -2890,42 +2918,39 @@
 	}
       
-#ifdef	G_MAIN_POLL_DEBUG
-      LOCK_CONTEXT (context);
-
-      g_print ("g_main_poll(%d) timeout: %d - elapsed %12.10f seconds",
-	       n_fds,
-	       timeout,
-	       g_timer_elapsed (poll_timer, NULL));
-      g_timer_destroy (poll_timer);
-      pollrec = context->poll_records;
-      i = 0;
-      while (i < n_fds)
+#ifdef	G_ENABLE_DEBUG
+      if (g_main_poll_debug)
 	{
-	  if (pollrec->fd->events)
+	  LOCK_CONTEXT (context);
+
+	  g_printerr ("g_main_poll(%d) timeout: %d - elapsed %12.10f seconds",
+		      n_fds,
+		      timeout,
+		      g_timer_elapsed (poll_timer, NULL));
+	  g_timer_destroy (poll_timer);
+	  pollrec = context->poll_records;
+	  i = 0;
+	  while (i < n_fds)
 	    {
-	      if (fds[i].revents)
+	      if (pollrec->fd->events)
 		{
-		  g_print (" [%d:", fds[i].fd);
-		  if (fds[i].revents & G_IO_IN)
-		    g_print ("i");
-		  if (fds[i].revents & G_IO_OUT)
-		    g_print ("o");
-		  if (fds[i].revents & G_IO_PRI)
-		    g_print ("p");
-		  if (fds[i].revents & G_IO_ERR)
-		    g_print ("e");
-		  if (fds[i].revents & G_IO_HUP)
-		    g_print ("h");
-		  if (fds[i].revents & G_IO_NVAL)
-		    g_print ("n");
-		  g_print ("]");
+		  if (fds[i].revents)
+		    {
+		      g_printerr (" [" FD_FORMAT ":%c%c%c%c%c%c]",
+				  fds[i].fd,
+				  (fds[i].revents & G_IO_IN) ? 'i' : '-',
+				  (fds[i].revents & G_IO_OUT) ? 'o' : '-',
+				  (fds[i].revents & G_IO_PRI) ? 'p' : '-',
+				  (fds[i].revents & G_IO_ERR) ? 'e' : '-',
+				  (fds[i].revents & G_IO_HUP) ? 'h' : '-',
+				  (fds[i].revents & G_IO_NVAL) ? 'n' : '-');
+		    }
+		  i++;
 		}
-	      i++;
+	      pollrec = pollrec->next;
 	    }
-	  pollrec = pollrec->next;
+	  g_printerr ("\n");
+
+	  UNLOCK_CONTEXT (context);
 	}
-      g_print ("\n");
-      
-      UNLOCK_CONTEXT (context);
 #endif
     } /* if (n_fds || timeout != 0) */