commit 230f9f94b8d6e37c4c1fb65bfd9dab76851a8d71
author Josh Lehan <krellan@google.com> Thu Jul 20 22:21:06 2023 +0000
committer Josh Lehan <krellan@google.com> Mon Jul 24 23:43:30 2023 +0000
tree c2e55770942b4d3a70a91e3307f6ca238617bdc8
parent 1cb59f70f1fa1caa10c700ba954e9b5fd85afed5

lg2: Add mutex to avoid stderr line corruption

Use of a mutex, along with flushing after every line, prevents threads
in multithreaded programs from corrupting each other's stderr logging
lines. As for the D-Bus journal messages, they are already atomic, not
needing this fix.

Tested: The corruption appears fixed
https://gist.github.com/Krellan/d5d9942cb5ab405c9689e4eb4bb75cf0

Change-Id: I1db88139406eb617aa713740d5ccb6c9420ca773
Signed-off-by: Josh Lehan <krellan@google.com>

lib/lg2_logger.cpp

diff --git a/lib/lg2_logger.cpp b/lib/lg2_logger.cpp
index 81f085d..fcf129f 100644
--- a/lib/lg2_logger.cpp
+++ b/lib/lg2_logger.cpp
@@ -10,7 +10,9 @@
 #include <cstdarg>
 #include <cstdio>
 #include <iostream>
+#include <mutex>
 #include <source_location>
+#include <sstream>
 #include <vector>
 
 namespace lg2::details
@@ -146,11 +148,13 @@
 
     const char* format = defaultFormat;
 
+    std::stringstream stream;
+
     while (*format)
     {
         if (*format != '%')
         {
-            std::cerr << *format;
+            stream << *format;
             ++format;
             continue;
         }
@@ -160,31 +164,31 @@
         {
             case '%':
             case '\0':
-                std::cerr << '%';
+                stream << '%';
                 break;
 
             case 'f':
-                std::cerr << s.function_name();
+                stream << s.function_name();
                 break;
 
             case 'F':
-                std::cerr << s.file_name();
+                stream << s.file_name();
                 break;
 
             case 'l':
-                std::cerr << static_cast<uint64_t>(l);
+                stream << static_cast<uint64_t>(l);
                 break;
 
             case 'L':
-                std::cerr << s.line();
+                stream << s.line();
                 break;
 
             case 'm':
-                std::cerr << m;
+                stream << m;
                 break;
 
             default:
-                std::cerr << '%' << *format;
+                stream << '%' << *format;
                 break;
         }
 
@@ -194,7 +198,13 @@
         }
     }
 
-    std::cerr << std::endl;
+    static std::mutex mutex;
+
+    // Prevent multiple threads from clobbering the stderr lines of each other
+    std::scoped_lock lock(mutex);
+
+    // Ensure this line makes it out before releasing mutex for next line
+    std::cerr << stream.str() << std::endl;
 }
 
 // Use the cerr output method if we are on a TTY or if explicitly set via

lib/meson.build

diff --git a/lib/meson.build b/lib/meson.build
index 1de91ec..9c65652 100644
--- a/lib/meson.build
+++ b/lib/meson.build
@@ -4,10 +4,13 @@
 
 subdir('include/phosphor-logging')
 
+threads_dep = dependency('threads')
+
 phosphor_logging_deps = [
     pdi_dep,
     sdbusplus_dep,
     systemd_dep,
+    threads_dep
 ]
 
 phosphor_logging_lib = library(