From 8016ad1cecd14c85b1ecbd93180ab48f739360ad Mon Sep 17 00:00:00 2001
From: Pauli Virtanen <pav@iki.fi>
Date: Sun, 28 Apr 2024 14:13:38 +0300
Subject: [PATCH] log: prepend topic to journald logs & add locations on debug
 levels

Logging messages are usually developed based on the stderr logging,
which shows code location and log topics as context, and especially
higher log level messages can be cryptic or useless without that
context.

This context is not shown in journalctl by default, and so usually is
missing from logs submitted by users. In principle it is available in
journalctl but requires extra work to show it.

Fix by prepending the log topic to the messages, like Pipewire logging
does. Also show code locations if log level is high enough.
---
 lib/wp/log.c | 56 +++++++++++++++++++++++++++++++++++++++++++---------
 1 file changed, 47 insertions(+), 9 deletions(-)

diff --git a/lib/wp/log.c b/lib/wp/log.c
index 3e5b9a29..131e6d52 100644
--- a/lib/wp/log.c
+++ b/lib/wp/log.c
@@ -670,6 +670,7 @@ struct _WpLogFields
   const gchar *func;
   const gchar *message;
   gint log_level;
+  gboolean debug;
   GType object_type;
   gconstpointer object;
 };
@@ -678,6 +679,7 @@ static void
 wp_log_fields_init (WpLogFields *lf,
     const gchar *log_topic,
     gint log_level,
+    gboolean debug,
     const gchar *file,
     const gchar *line,
     const gchar *func,
@@ -687,6 +689,7 @@ wp_log_fields_init (WpLogFields *lf,
 {
   lf->log_topic = log_topic ? log_topic : "default";
   lf->log_level = log_level;
+  lf->debug = debug;
   lf->file = file;
   lf->line = line;
   lf->func = func;
@@ -695,11 +698,18 @@ wp_log_fields_init (WpLogFields *lf,
   lf->message = message ? message : "(null)";
 }
 
+static gboolean
+wp_want_debug_log (const struct spa_log_topic *topic)
+{
+  return spa_log_level_topic_enabled (wp_spa_log_get_instance(), topic, SPA_LOG_LEVEL_DEBUG);
+}
+
 static void
 wp_log_fields_init_from_glib (WpLogFields *lf, GLogLevelFlags log_level_flags,
     const GLogField *fields, gsize n_fields)
 {
   wp_log_fields_init (lf, NULL, level_index_from_flags (log_level_flags),
+      wp_want_debug_log (NULL),
       NULL, NULL, NULL, 0, NULL, NULL);
 
   for (guint i = 0; i < n_fields; i++) {
@@ -758,15 +768,41 @@ wp_log_fields_write_to_stream (WpLogFields *lf, FILE *s)
 static gboolean
 wp_log_fields_write_to_journal (WpLogFields *lf)
 {
-  gsize n_fields = 6;
-  GLogField fields[6] = {
-    { "PRIORITY", log_level_info[lf->log_level].priority, -1 },
-    { "CODE_FILE", lf->file ? lf->file : "", -1 },
-    { "CODE_LINE", lf->line ? lf->line : "", -1 },
-    { "CODE_FUNC", lf->func ? lf->func : "", -1 },
-    { "TOPIC", lf->log_topic ? lf->log_topic : "", -1 },
-    { "MESSAGE", lf->message ? lf->message : "", -1 },
-  };
+  GLogField fields[6];
+  gsize n_fields = 0;
+  g_autofree gchar *full_message = NULL;
+  const gchar *message = lf->message ? lf->message : "";
+
+  if (lf->debug) {
+    if (lf->file && lf->line && lf->func) {
+      g_autofree gchar *file = g_path_get_basename(lf->file);
+
+      message = full_message = g_strdup_printf("%c %s%s[%s:%s:%s]: %s",
+          log_level_info[lf->log_level].name,
+          lf->log_topic ? lf->log_topic : "",
+          lf->log_topic ? " " : "",
+          file, lf->line, lf->func, message);
+    } else {
+      message = full_message = g_strdup_printf("%c %s%s%s",
+          log_level_info[lf->log_level].name,
+          lf->log_topic ? lf->log_topic : "",
+          lf->log_topic ? ": " : "",
+          message);
+    }
+  } else if (lf->log_topic) {
+    message = full_message = g_strdup_printf("%s: %s", lf->log_topic, message);
+  }
+
+  fields[n_fields++] = (GLogField) { "PRIORITY", log_level_info[lf->log_level].priority, -1 };
+  if (lf->file)
+    fields[n_fields++] = (GLogField) { "CODE_FILE", lf->file, -1 };
+  if (lf->line)
+    fields[n_fields++] = (GLogField) { "CODE_LINE", lf->line, -1 };
+  if (lf->func)
+    fields[n_fields++] = (GLogField) { "CODE_FUNC", lf->func, -1 };
+  if (lf->log_topic)
+    fields[n_fields++] = (GLogField) { "TOPIC", lf->log_topic, -1 };
+  fields[n_fields++] = (GLogField) { "MESSAGE", message, -1 };
 
   /* the log level flags are not used in this function, so we can pass 0 */
   return (g_log_writer_journald (0, fields, n_fields, NULL) == G_LOG_WRITER_HANDLED);
@@ -881,6 +917,7 @@ wp_log_checked (
   va_end (args);
 
   wp_log_fields_init (&lf, log_topic, level_index_from_flags (log_level_flags),
+      wp_want_debug_log (NULL),
       file, line, func, object_type, object, message);
   wp_log_fields_log (&lf);
 }
@@ -904,6 +941,7 @@ wp_spa_log_logtv (void *object,
   message = g_strdup_vprintf (fmt, args);
 
   wp_log_fields_init (&lf, topic ? topic->topic : NULL, log_level,
+      wp_want_debug_log (topic),
       file, line_str, func, 0, NULL, message);
   wp_log_fields_log (&lf);
 }