[gcr] Fix up GCR_DEBUG and GCK_DEBUG environment variables

[Stefan Walter <stefw src gnome org>]

commit 60bcb157893ac25069353fc18f0885bc6b55a2b7
Author: Stef Walter <stefw gnome org>
Date:   Tue Apr 3 11:02:00 2012 +0200

    Fix up GCR_DEBUG and GCK_DEBUG environment variables
    
     * This is due to the G_MESSAGES_DEBUG change in glib
     * We manage our own debug categories, so if G_MESSAGES_DEBUG
       is not being used but GCR_DEBUG or GCK_DEBUG are set
       we unconditionally print the debug messages.
     * If G_MESSAGES_DEBUG is being used, then make all the
       debug messages available to Glib.
     * Can build with -DGCR_DEBUG=category flags to permanently
       enable certain categories.

 README          |   37 ++++++++++++++++++++++++++++++
 gck/gck-debug.c |   66 ++++++++++++++++++++++++++++++++++++++++++++++--------
 gcr/gcr-debug.c |   65 +++++++++++++++++++++++++++++++++++++++++++++--------
 3 files changed, 148 insertions(+), 20 deletions(-)
---
diff --git a/README b/README
index 98aba68..77993d6 100644
--- a/README
+++ b/README
@@ -4,3 +4,40 @@ desktop.
 
 GCK is a library for accessing PKCS#11 modules like smart cards, in a
 (G)object oriented way.
+
+
+DEBUG TRACING
+==============
+
+The Gcr and Gck libraries contain statements which help debug flow
+and logic. In many cases these help you track down problems.
+
+Use the environment variable GCR_DEBUG='all' or GCR_HELP='xxx' to
+display either all messages or a specific category of debug messages.
+To figure out what you can use in place of the 'xxx' category above,
+use GCR_DEBUG='help' and you'll see a list of all the messages.
+
+Example to display all debug messages:
+
+ $ GCR_DEBUG=all gcr-viewer /path/to/certificate.crt
+ (gcr-viewer:9418): Gcr-DEBUG: gcr_pkcs11_initialize_async: starting initialize of registered modules
+ ...
+
+Example to display the various debug categories:
+
+ $ GCR_DEBUG=help gcr-viewer /path/to/certificate.crt
+ Supported debug values: library certificate-chain parse gnupg trust import key prompt all help
+
+Example to display debug messages for a specific category:
+
+ $ GCR_DEBUG=library gcr-viewer /path/to/certificate.crt
+ (gcr-viewer:9503): Gcr-DEBUG: gcr_pkcs11_initialize_async: starting initialize of registered modules
+ ...
+
+If you wish to permanently enable certain debug messages, include compiler
+directives like this when configuring this library:
+
+ $ CFLAGS='-DGCR_DEBUG=library' ./configure ...
+
+For the Gck debug messages simply replace 'GCR_DEBUG' with 'GCK_DEBUG'
+in the above examples.
diff --git a/gck/gck-debug.c b/gck/gck-debug.c
index c30da4d..073a6b9 100644
--- a/gck/gck-debug.c
+++ b/gck/gck-debug.c
@@ -58,10 +58,60 @@ _gck_debug_set_flags (const gchar *flags_string)
 }
 
 static void
+on_gck_log_debug (const gchar *log_domain,
+                  GLogLevelFlags log_level,
+                  const gchar *message,
+                  gpointer user_data)
+{
+	GString *gstring;
+	const gchar *progname;
+
+	gstring = g_string_new (NULL);
+
+	progname = g_get_prgname ();
+	g_string_append_printf (gstring, "(%s:%lu): %s-DEBUG: %s\n",
+	                        progname ? progname : "process",
+	                        (gulong)getpid (), log_domain,
+	                        message ? message : "(NULL) message");
+
+	write (1, gstring->str, gstring->len);
+	g_string_free (gstring, TRUE);
+}
+
+static void
 initialize_debug_flags (void)
 {
+	const gchar *messages_env;
+	const gchar *debug_env;
+
 	if (g_once_init_enter (&initialized_flags)) {
-		_gck_debug_set_flags (g_getenv ("GCK_DEBUG"));
+		messages_env = g_getenv ("G_MESSAGES_DEBUG");
+		debug_env = g_getenv ("GCK_DEBUG");
+#ifdef GCK_DEBUG
+		if (debug_env == NULL)
+			debug_env = G_STRINGIFY (GCK_DEBUG);
+#endif
+
+		/*
+		 * If the caller is selectively asking for certain debug
+		 * messages with the GCK_DEBUG environment variable, then
+		 * we install our own output handler and only print those
+		 * messages. This happens irrespective of G_MESSAGES_DEBUG
+		 */
+		if (messages_env == NULL && debug_env != NULL)
+			g_log_set_handler (G_LOG_DOMAIN, G_LOG_LEVEL_DEBUG,
+			                   on_gck_log_debug, NULL);
+
+		/*
+		 * If the caller is using G_MESSAGES_DEBUG then we enable
+		 * all our debug messages, and let Glib filter which ones
+		 * to display.
+		 */
+		if (messages_env != NULL && debug_env == NULL)
+			debug_env = "all";
+
+		_gck_debug_set_flags (debug_env);
+
 		g_once_init_leave (&initialized_flags, 1);
 	}
 }
@@ -79,20 +129,16 @@ _gck_debug_message (GckDebugFlags flag,
                     const gchar *format,
                     ...)
 {
-	gchar *message;
 	va_list args;
 
 	if G_UNLIKELY (!initialized_flags)
 		initialize_debug_flags ();
 
-	va_start (args, format);
-	message = g_strdup_vprintf (format, args);
-	va_end (args);
-
-	if (flag & current_flags)
-		g_log (G_LOG_DOMAIN, G_LOG_LEVEL_DEBUG, "%s", message);
-
-	g_free (message);
+	if (flag & current_flags) {
+		va_start (args, format);
+		g_logv (G_LOG_DOMAIN, G_LOG_LEVEL_DEBUG, format, args);
+		va_end (args);
+	}
 }
 
 #else /* !WITH_DEBUG */
diff --git a/gcr/gcr-debug.c b/gcr/gcr-debug.c
index 1f74250..c80ceac 100644
--- a/gcr/gcr-debug.c
+++ b/gcr/gcr-debug.c
@@ -70,26 +70,71 @@ _gcr_debug_flag_is_set (GcrDebugFlags flag)
 	return (flag & current_flags) != 0;
 }
 
+static void
+on_gcr_log_debug (const gchar *log_domain,
+                  GLogLevelFlags log_level,
+                  const gchar *message,
+                  gpointer user_data)
+{
+	GString *gstring;
+	const gchar *progname;
+
+	gstring = g_string_new (NULL);
+
+	progname = g_get_prgname ();
+	g_string_append_printf (gstring, "(%s:%lu): %s-DEBUG: %s\n",
+	                        progname ? progname : "process",
+	                        (gulong)getpid (), log_domain,
+	                        message ? message : "(NULL) message");
+
+	write (1, gstring->str, gstring->len);
+	g_string_free (gstring, TRUE);
+}
+
 void
 _gcr_debug_message (GcrDebugFlags flag, const gchar *format, ...)
 {
 	static gsize initialized_flags = 0;
-	gchar *message;
+	const gchar *messages_env;
+	const gchar *debug_env;
 	va_list args;
 
 	if (g_once_init_enter (&initialized_flags)) {
-		_gcr_debug_set_flags (g_getenv ("GCR_DEBUG"));
+		messages_env = g_getenv ("G_MESSAGES_DEBUG");
+		debug_env = g_getenv ("GCR_DEBUG");
+#ifdef GCR_DEBUG
+		if (debug_env == NULL)
+			debug_env = G_STRINGIFY (GCR_DEBUG);
+#endif
+
+		/*
+		 * If the caller is selectively asking for certain debug
+		 * messages with the GCR_DEBUG environment variable, then
+		 * we install our own output handler and only print those
+		 * messages. This happens irrespective of G_MESSAGES_DEBUG
+		 */
+		if (messages_env == NULL && debug_env != NULL)
+			g_log_set_handler (G_LOG_DOMAIN, G_LOG_LEVEL_DEBUG,
+			                   on_gcr_log_debug, NULL);
+
+		/*
+		 * If the caller is using G_MESSAGES_DEBUG then we enable
+		 * all our debug messages, and let Glib filter which ones
+		 * to display.
+		 */
+		if (messages_env != NULL && debug_env == NULL)
+			debug_env = "all";
+
+		_gcr_debug_set_flags (debug_env);
+
 		g_once_init_leave (&initialized_flags, 1);
 	}
 
-	va_start (args, format);
-	message = g_strdup_vprintf (format, args);
-	va_end (args);
-
-	if (flag & current_flags)
-		g_log (G_LOG_DOMAIN, G_LOG_LEVEL_DEBUG, "%s", message);
-
-	g_free (message);
+	if (flag & current_flags) {
+		va_start (args, format);
+		g_logv (G_LOG_DOMAIN, G_LOG_LEVEL_DEBUG, format, args);
+		va_end (args);
+	}
 }
 
 #else /* !WITH_DEBUG */