gmessages: Add API to move info and debug messages to stderr

GLib code normally prints info and debug messages to stdout,
but that interferes with programs that are documented to produce
machine-readable output such as JSON or XML on stdout. In particular,
if such a program uses a GLib-based library, setting G_MESSAGES_DEBUG
will typically result in that library's debug messages going to the
program's stdout and corrupting the machine-readable output.

Unix programs can avoid this by using dup2() to move the original stdout
to another fd, then dup2() again to make the new stdout a copy of stderr,
but it's easier if we provide a way to not write debug messages to
stdout in the first place. Calling
g_log_writer_default_set_use_stderr (TRUE) results in behaviour
resembling Python's logging.basicConfig(), with all diagnostics going
to stderr.

Suggested by Allison Karlitskaya on glib#2087.

Signed-off-by: Simon McVittie <smcv@collabora.com>

4 files changed, 65 insertions, 3 deletions

diff --git a/docs/reference/glib/glib-sections.txt b/docs/reference/glib/glib-sections.txt
index 598b0366b..30e58de0c 100644
--- a/docs/reference/glib/glib-sections.txt
+++ b/docs/reference/glib/glib-sections.txt
@@ -1484,6 +1484,7 @@ g_log_writer_format_fields
 g_log_writer_journald
 g_log_writer_standard_streams
 g_log_writer_default
+g_log_writer_default_set_use_stderr
 
 <SUBSECTION Private>
 g_log_structured_standard
diff --git a/glib/gmessages.c b/glib/gmessages.c
index 0fde49f44..440abd507 100644
--- a/glib/gmessages.c
+++ b/glib/gmessages.c
@@ -197,6 +197,7 @@
 #include "gstrfuncs.h"
 #include "gstring.h"
 #include "gpattern.h"
+#include "gthreadprivate.h"
 
 #ifdef G_OS_UNIX
 #include <unistd.h>
@@ -1160,12 +1161,42 @@ static const gchar *log_level_to_color (GLogLevelFlags log_level,
                                         gboolean       use_color);
 static const gchar *color_reset        (gboolean       use_color);
 
+static gboolean gmessages_use_stderr = FALSE;
+
+/**
+ * g_log_writer_default_set_use_stderr:
+ * @use_stderr: If %TRUE, use `stderr` for log messages that would
+ *  normally have appeared on `stdout`
+ *
+ * Configure whether the built-in log functions
+ * (g_log_default_handler() for the old-style API, and both
+ * g_log_writer_default() and g_log_writer_standard_streams() for the
+ * structured API) will output all log messages to `stderr`.
+ *
+ * By default, log messages of levels %G_LOG_LEVEL_INFO and
+ * %G_LOG_LEVEL_DEBUG are sent to `stdout`, and other log messages are
+ * sent to `stderr`. This is problematic for applications that intend
+ * to reserve `stdout` for structured output such as JSON or XML.
+ *
+ * This function sets global state. It is not thread-aware, and should be
+ * called at the very start of a program, before creating any other threads
+ * or creating objects that could create worker threads of their own.
+ *
+ * Since: 2.68
+ */
+void
+g_log_writer_default_set_use_stderr (gboolean use_stderr)
+{
+  g_return_if_fail (g_thread_n_created () == 0);
+  gmessages_use_stderr = use_stderr;
+}
+
 static FILE *
 mklevel_prefix (gchar          level_prefix[STRING_BUFFER_SIZE],
                 GLogLevelFlags log_level,
                 gboolean       use_color)
 {
-  gboolean to_stdout = TRUE;
+  gboolean to_stdout = !gmessages_use_stderr;
 
   /* we may not call _any_ GLib functions here */
 
@@ -1442,6 +1473,9 @@ log_level_to_priority (GLogLevelFlags log_level)
 static FILE *
 log_level_to_file (GLogLevelFlags log_level)
 {
+  if (gmessages_use_stderr)
+    return stderr;
+
   if (log_level & (G_LOG_LEVEL_ERROR | G_LOG_LEVEL_CRITICAL |
                    G_LOG_LEVEL_WARNING | G_LOG_LEVEL_MESSAGE))
     return stderr;
@@ -2524,7 +2558,9 @@ g_log_writer_journald (GLogLevelFlags   log_level,
  *
  * Format a structured log message and print it to either `stdout` or `stderr`,
  * depending on its log level. %G_LOG_LEVEL_INFO and %G_LOG_LEVEL_DEBUG messages
- * are sent to `stdout`; all other log levels are sent to `stderr`. Only fields
+ * are sent to `stdout`, or to `stderr` if requested by
+ * g_log_writer_default_set_use_stderr();
+ * all other log levels are sent to `stderr`. Only fields
  * which are understood by this function are included in the formatted string
  * which is printed.
  *
@@ -3075,7 +3111,8 @@ escape_string (GString *string)
  *
  * stderr is used for levels %G_LOG_LEVEL_ERROR, %G_LOG_LEVEL_CRITICAL,
  * %G_LOG_LEVEL_WARNING and %G_LOG_LEVEL_MESSAGE. stdout is used for
- * the rest.
+ * the rest, unless stderr was requested by
+ * g_log_writer_default_set_use_stderr().
  *
  * This has no effect if structured logging is enabled; see
  * [Using Structured Logging][using-structured-logging].
diff --git a/glib/gmessages.h b/glib/gmessages.h
index e910f7b73..29bc1736e 100644
--- a/glib/gmessages.h
+++ b/glib/gmessages.h
@@ -242,6 +242,9 @@ GLogWriterOutput g_log_writer_default          (GLogLevelFlags   log_level,
                                                 gsize            n_fields,
                                                 gpointer         user_data);
 
+GLIB_AVAILABLE_IN_2_68
+void            g_log_writer_default_set_use_stderr (gboolean use_stderr);
+
 /**
  * G_DEBUG_HERE:
  *
diff --git a/glib/tests/logging.c b/glib/tests/logging.c
index 3ab34f58e..1e9192bef 100644
--- a/glib/tests/logging.c
+++ b/glib/tests/logging.c
@@ -124,6 +124,21 @@ test_default_handler_debug (void)
   g_log ("foo", G_LOG_LEVEL_DEBUG, "6");
   g_log ("bar", G_LOG_LEVEL_DEBUG, "6");
   g_log ("baz", G_LOG_LEVEL_DEBUG, "6");
+
+  exit (0);
+}
+
+static void
+test_default_handler_debug_stderr (void)
+{
+  g_log_writer_default_set_use_stderr (TRUE);
+  g_log_set_default_handler (g_log_default_handler, NULL);
+
+  g_setenv ("G_MESSAGES_DEBUG", "all", TRUE);
+
+  g_log ("foo", G_LOG_LEVEL_DEBUG, "6");
+  g_log ("bar", G_LOG_LEVEL_DEBUG, "6");
+  g_log ("baz", G_LOG_LEVEL_DEBUG, "6");
   exit (0);
 }
 
@@ -170,6 +185,11 @@ test_default_handler (void)
   g_test_trap_assert_passed ();
   g_test_trap_assert_stdout ("*DEBUG*6*6*6*");
 
+  g_test_trap_subprocess ("/logging/default-handler/subprocess/debug-stderr", 0, 0);
+  g_test_trap_assert_passed ();
+  g_test_trap_assert_stdout_unmatched ("DEBUG");
+  g_test_trap_assert_stderr ("*DEBUG*6*6*6*");
+
   g_test_trap_subprocess ("/logging/default-handler/subprocess/0x400", 0, 0);
   g_test_trap_assert_passed ();
   g_test_trap_assert_stdout ("*LOG-0x400*message7*");
@@ -578,6 +598,7 @@ main (int argc, char *argv[])
   g_test_add_func ("/logging/default-handler/subprocess/bar-info", test_default_handler_bar_info);
   g_test_add_func ("/logging/default-handler/subprocess/baz-debug", test_default_handler_baz_debug);
   g_test_add_func ("/logging/default-handler/subprocess/debug", test_default_handler_debug);
+  g_test_add_func ("/logging/default-handler/subprocess/debug-stderr", test_default_handler_debug_stderr);
   g_test_add_func ("/logging/default-handler/subprocess/0x400", test_default_handler_0x400);
   g_test_add_func ("/logging/warnings", test_warnings);
   g_test_add_func ("/logging/fatal-log-mask", test_fatal_log_mask);