[libgdata] core: Filter sensitive details out of debug log output

[Philip Withnall <pwithnall src gnome org>]

commit fd2d8a5f14aece4b28b07d2bffeb766d77c972aa
Author: Philip Withnall <philip tecnocode co uk>
Date:   Mon Oct 10 09:38:19 2011 +0100

    core: Filter sensitive details out of debug log output
    
    Add a new log level, GDATA_LOG_FULL_UNREDACTED = 4, and redact usernames,
    passwords and auth. tokens from all log levels below it. Thus, taking a
    debug log with LIBGDATA_DEBUG=3 will no longer inadvertently reveal the
    user's password.
    
    Helps: bgo#656783

 README                |    5 ++-
 gdata/gdata-private.h |    8 +++-
 gdata/gdata-service.c |   96 +++++++++++++++++++++++++++++++++++++++++++++++-
 gdata/tests/common.c  |    2 +-
 4 files changed, 105 insertions(+), 6 deletions(-)
---
diff --git a/README b/README
index 2ef0388..82893ea 100644
--- a/README
+++ b/README
@@ -30,7 +30,10 @@ values, libgdata will give debug output (at various levels):
  0: Output no debug messages or network logs
  1: Output debug messages, but not network logs
  2: Output debug messages and network traffic headers
- 3: Output debug messages and full network traffic logs
+ 3: Output debug messages and full network traffic logs, redacting usernames,
+    passwords and auth. tokens
+ 4: Output debug messages and full network traffic logs, and don't redact
+    usernames, passwords and auth. tokens
 If LIBGDATA_DEBUG is unset, no debug output will be produced.
 
 Deprecation guards
diff --git a/gdata/gdata-private.h b/gdata/gdata-private.h
index 6e55451..95685a7 100644
--- a/gdata/gdata-private.h
+++ b/gdata/gdata-private.h
@@ -33,7 +33,10 @@ G_BEGIN_DECLS
  * @GDATA_LOG_NONE: Output no debug messages or network logs
  * @GDATA_LOG_MESSAGES: Output debug messages, but not network logs
  * @GDATA_LOG_HEADERS: Output debug messages and network traffic headers
- * @GDATA_LOG_FULL: Output debug messages and full network traffic logs
+ * @GDATA_LOG_FULL: Output debug messages and full network traffic logs,
+ * redacting usernames, passwords and auth. tokens
+ * @GDATA_LOG_FULL_UNREDACTED: Output debug messages and full network traffic
+ * logs, and don't redact usernames, passwords and auth. tokens
  *
  * Logging level.
  **/
@@ -41,7 +44,8 @@ typedef enum {
 	GDATA_LOG_NONE = 0,
 	GDATA_LOG_MESSAGES = 1,
 	GDATA_LOG_HEADERS = 2,
-	GDATA_LOG_FULL = 3
+	GDATA_LOG_FULL = 3,
+	GDATA_LOG_FULL_UNREDACTED = 4,
 } GDataLogLevel;
 
 #include "gdata-service.h"
diff --git a/gdata/gdata-service.c b/gdata/gdata-service.c
index f2a383f..cd98ae6 100644
--- a/gdata/gdata-service.c
+++ b/gdata/gdata-service.c
@@ -1975,7 +1975,98 @@ debug_handler (const char *log_domain, GLogLevelFlags log_level, const char *mes
 static void
 soup_log_printer (SoupLogger *logger, SoupLoggerLogLevel level, char direction, const char *data, gpointer user_data)
 {
-	g_debug ("%c %s", direction, data);
+	gboolean filter_data;
+	gchar *_data = NULL;
+
+	filter_data = (_gdata_service_get_log_level () > GDATA_LOG_NONE && _gdata_service_get_log_level () < GDATA_LOG_FULL_UNREDACTED) ? TRUE : FALSE;
+
+	if (filter_data == TRUE) {
+		/* Filter out lines which look like they might contain usernames, passwords or auth. tokens. */
+		if (direction == '>' && g_str_has_prefix (data, "Authorization: GoogleLogin ") == TRUE) {
+			_data = g_strdup ("Authorization: GoogleLogin <redacted>");
+		} else if (direction == '>' && g_str_has_prefix (data, "Authorization: OAuth ") == TRUE) {
+			_data = g_strdup ("Authorization: OAuth <redacted>");
+		} else if (direction == '<' && g_str_has_prefix (data, "Set-Cookie: ") == TRUE) {
+			_data = g_strdup ("Set-Cookie: <redacted>");
+		} else if (direction == '<' && g_str_has_prefix (data, "Location: ") == TRUE) {
+			/* Looks like:
+			 * "Location: https://www.google.com/calendar/feeds/default/owncalendars/full?gsessionid=sBjmp05m5i67exYA51XjDA";. */
+			SoupURI *uri;
+			gchar *_uri;
+			GHashTable *params;
+
+			uri = soup_uri_new (data + strlen ("Location: "));
+
+			if (uri->query != NULL) {
+				params = soup_form_decode (uri->query);
+
+				/* strdup()s are necessary because the hash table's set up to free keys. */
+				if (g_hash_table_lookup (params, "gsessionid") != NULL) {
+					g_hash_table_insert (params, (gpointer) g_strdup ("gsessionid"), (gpointer) "<redacted>");
+				}
+
+				soup_uri_set_query_from_form (uri, params);
+				g_hash_table_destroy (params);
+			}
+
+			_uri = soup_uri_to_string (uri, FALSE);
+			_data = g_strconcat ("Location: ", _uri, NULL);
+			g_free (_uri);
+
+			soup_uri_free (uri);
+		} else if (direction == '<' && g_str_has_prefix (data, "SID=") == TRUE) {
+			_data = g_strdup ("SID=<redacted>");
+		} else if (direction == '<' && g_str_has_prefix (data, "LSID=") == TRUE) {
+			_data = g_strdup ("LSID=<redacted>");
+		} else if (direction == '<' && g_str_has_prefix (data, "Auth=") == TRUE) {
+			_data = g_strdup ("Auth=<redacted>");
+		} else if (direction == '>' && g_str_has_prefix (data, "accountType=") == TRUE) {
+			/* Looks like: "> accountType=HOSTED%5FOR%5FGOOGLE&Email=[e-mail address]&Passwd=[plaintex password]"
+			               "&service=[service name]&source=ytapi%2DGNOME%2Dlibgdata%2D444fubtt%2D0". */
+			GHashTable *params = soup_form_decode (data);
+
+			/* strdup()s are necessary because the hash table's set up to free keys. */
+			if (g_hash_table_lookup (params, "Email") != NULL) {
+				g_hash_table_insert (params, (gpointer) g_strdup ("Email"), (gpointer) "<redacted>");
+			}
+			if (g_hash_table_lookup (params, "Passwd") != NULL) {
+				g_hash_table_insert (params, (gpointer) g_strdup ("Passwd"), (gpointer) "<redacted>");
+			}
+
+			_data = soup_form_encode_hash (params);
+
+			g_hash_table_destroy (params);
+		} else if (direction == '<' && g_str_has_prefix (data, "oauth_token=") == TRUE) {
+			/* Looks like: "< oauth_token=4%2FI-WU7sBzKk5GhGlQUF8a_TCZRnb7&oauth_token_secret=qTTTJg3no25auiiWFerzjW4I"
+			               "&oauth_callback_confirmed=true". */
+			GHashTable *params = soup_form_decode (data);
+
+			/* strdup()s are necessary because the hash table's set up to free keys. */
+			if (g_hash_table_lookup (params, "oauth_token") != NULL) {
+				g_hash_table_insert (params, (gpointer) g_strdup ("oauth_token"), (gpointer) "<redacted>");
+			}
+			if (g_hash_table_lookup (params, "oauth_token_secret") != NULL) {
+				g_hash_table_insert (params, (gpointer) g_strdup ("oauth_token_secret"), (gpointer) "<redacted>");
+			}
+
+			_data = soup_form_encode_hash (params);
+
+			g_hash_table_destroy (params);
+		} else {
+			/* Nothing to redact. */
+			_data = g_strdup (data);
+		}
+	} else {
+		/* Don't dupe the string. */
+		_data = (gchar*) data;
+	}
+
+	/* Log the data. */
+	g_debug ("%c %s", direction, _data);
+
+	if (filter_data == TRUE) {
+		g_free (_data);
+	}
 }
 
 /**
@@ -1996,7 +2087,7 @@ _gdata_service_get_log_level (void)
 		const gchar *envvar = g_getenv ("LIBGDATA_DEBUG");
 		if (envvar != NULL)
 			level = atoi (envvar);
-		level = MIN (MAX (level, 0), GDATA_LOG_FULL);
+		level = MIN (MAX (level, 0), GDATA_LOG_FULL_UNREDACTED);
 	}
 
 	return level;
@@ -2027,6 +2118,7 @@ _gdata_service_build_session (void)
 		SoupLogger *logger;
 
 		switch (_gdata_service_get_log_level ()) {
+			case GDATA_LOG_FULL_UNREDACTED:
 			case GDATA_LOG_FULL:
 				level = SOUP_LOGGER_LOG_BODY;
 				break;
diff --git a/gdata/tests/common.c b/gdata/tests/common.c
index a4b0573..feacd99 100644
--- a/gdata/tests/common.c
+++ b/gdata/tests/common.c
@@ -74,7 +74,7 @@ gdata_test_init (int argc, char **argv)
 	g_test_bug_base ("http://bugzilla.gnome.org/show_bug.cgi?id=";);
 
 	/* Enable full debugging */
-	g_setenv ("LIBGDATA_DEBUG", "3", FALSE);
+	g_setenv ("LIBGDATA_DEBUG", "3" /* GDATA_LOG_FULL */, FALSE);
 }
 
 /*