fix(logger): decide colors without a static guard a fork child inherits

CHANGELOG.md

@@ -5,6 +5,11 @@ Notable changes are grouped by release. See [all releases](https://github.com/Co
 ## Unreleased
 
 - Added repository contribution, conduct and security documentation.
+- A child of `fork()` no longer hangs on its first line when another thread of the parent was
+  deciding whether stderr takes colors, writing a line or initializing the logger at the time of
+  the fork: `fork()` waits for the line and the initialization.
+- A child of `fork()` logs its own pid instead of the parent's.
+- An empty `NO_COLOR` no longer disables colors, as no-color.org specifies.
 
 ## v1.1.0
 

README.md

@@ -218,7 +218,9 @@ coretrace::set_thread_safe(true);   // Default: mutex-protected output
 coretrace::set_thread_safe(false);  // Disable for single-threaded hot paths
 ```
 
-In thread-safe mode, each line reaches the sink in a single call and never concurrently with another line. The mutex is recursive, so a sink may itself call `log()`, for example to report a write error. With `set_thread_safe(false)`, the sink can be called from several threads at once, and `set_sink()` no longer waits.
+In thread-safe mode, each line reaches the sink in a single call and never concurrently with another line. The lock is reentrant, so a sink may itself call `log()`, for example to report a write error. With `set_thread_safe(false)`, the sink can be called from several threads at once, and `set_sink()` no longer waits.
+
+On POSIX, `fork()` waits for a line another thread is writing, so the child can log, even when the parent's threads were logging at the time of the fork.
 
 ### Colors
 
@@ -230,7 +232,7 @@ coretrace::log(Level::Info, "{}bold{} and {}red{}\n",
     coretrace::color(Color::Reset));
 ```
 
-Colors are automatically disabled when stderr is not a terminal or when `NO_COLOR` is set.
+Colors are automatically disabled when stderr is not a terminal or when `NO_COLOR` is set to a non-empty value.
 
 ### Low-level API
 
@@ -240,7 +242,7 @@ coretrace::write_str("hello");             // Write string
 coretrace::write_dec(42);                  // Write decimal (no heap)
 coretrace::write_hex(0xDEAD);             // Write hex with 0x prefix
 coretrace::write_raw(buf, len);            // Write raw bytes
-coretrace::pid();                          // Cached PID
+coretrace::pid();                          // Process ID
 coretrace::thread_id();                    // Platform-specific TID
 ```
 
@@ -252,7 +254,9 @@ These functions write straight to the sink: unlike `log()`, they are not seriali
 |----------|--------|-------------|
 | `CT_LOG_LEVEL` | `debug`, `info`, `warn`, `error` (case-insensitive) | Set startup default minimum log level. Other values mean `info` |
 | `CT_DEBUG` | comma-separated names | Set startup default enabled modules. Spaces around names are ignored |
-| `NO_COLOR` | any value | Disable ANSI color output |
+| `NO_COLOR` | any non-empty value | Disable ANSI color output |
+
+`CT_LOG_LEVEL` and `CT_DEBUG` are read once, at the first logging call or, on POSIX, at the first `fork()`, whichever comes first.
 
 ## Output format
 

include/coretrace/logger.hpp

@@ -164,7 +164,7 @@ void enable_all_modules();
 
 /// Enable or disable mutex-based serialization of log output.
 /// Default: true (thread-safe). Each line then reaches the sink in one call,
-/// never concurrently with another line. The mutex is recursive, so a sink may
+/// never concurrently with another line. The lock is reentrant, so a sink may
 /// itself call log(). Set to false for single-threaded hot paths: the sink can
 /// then be called concurrently, and set_sink() does not wait.
 void set_thread_safe(bool enabled);
@@ -241,7 +241,7 @@ void write_hex(uintptr_t value);
 //  System info
 // #######################################
 
-/// Return the cached process ID.
+/// Return the process ID.
 [[nodiscard]] int pid();
 
 /// Return the current thread ID (platform-specific).

src/logger.cpp

@@ -45,11 +45,29 @@ std::atomic<int> g_modules_set_explicitly{0};
 
 // ── Synchronization ──────────────────────
 
+// Both locks are reentrant: a thread takes a lock only when its count for that
+// lock goes from 0 to 1, so that a sink, or a fork handler, can call the logger
+// while the thread holds them. Not std::recursive_mutex, which a child of
+// fork() cannot release: it checks the id of its owner, and the child's thread
+// has another one.
+
+// Never destroyed: fork() takes the locks even while the program exits, from an
+// atexit() handler or a static destructor that runs after this file's.
+template <typename T> union Immortal {
+  T value;
+  constexpr Immortal() : value() {}
+  ~Immortal() {}
+};
+
 // Protects mutable logger state (prefix + modules table).
-std::mutex g_state_mutex;
+Immortal<std::mutex> g_state_lock;
+std::mutex &g_state_mutex = g_state_lock.value;
+thread_local int t_state_depth = 0;
 
 // Protects atomicity of one log line output when thread-safe mode is on.
-std::recursive_mutex g_output_mutex;
+Immortal<std::mutex> g_output_lock;
+std::mutex &g_output_mutex = g_output_lock.value;
+thread_local int t_output_depth = 0;
 std::atomic<int> g_thread_safe{1}; // enabled by default
 
 // ── Sink ─────────────────────────────────
@@ -70,9 +88,20 @@ std::once_flag g_init_once;
 
 // ── Small lock guards ────────────────────
 
+void lock_reentrant(std::mutex &mutex, int &depth) {
+  if (depth == 0)
+    mutex.lock();
+  ++depth;
+}
+
+void unlock_reentrant(std::mutex &mutex, int &depth) {
+  if (--depth == 0)
+    mutex.unlock();
+}
+
 struct StateLockGuard {
-  StateLockGuard() { g_state_mutex.lock(); }
-  ~StateLockGuard() { g_state_mutex.unlock(); }
+  StateLockGuard() { lock_reentrant(g_state_mutex, t_state_depth); }
+  ~StateLockGuard() { unlock_reentrant(g_state_mutex, t_state_depth); }
 
   StateLockGuard(const StateLockGuard &) = delete;
   StateLockGuard &operator=(const StateLockGuard &) = delete;
@@ -82,12 +111,12 @@ struct OutputLockGuard {
   OutputLockGuard()
       : locked(g_thread_safe.load(std::memory_order_acquire) != 0) {
     if (locked)
-      g_output_mutex.lock();
+      lock_reentrant(g_output_mutex, t_output_depth);
   }
 
   ~OutputLockGuard() {
     if (locked)
-      g_output_mutex.unlock();
+      unlock_reentrant(g_output_mutex, t_output_depth);
   }
 
   OutputLockGuard(const OutputLockGuard &) = delete;
@@ -96,6 +125,28 @@ struct OutputLockGuard {
   bool locked;
 };
 
+// ── Fork ─────────────────────────────────
+
+// A child of fork() has only the thread that forked. So that it inherits
+// neither a lock nor the initialization taken by another thread of the parent,
+// fork() waits for them: the forking thread finishes the initialization, then
+// takes the locks, in the order of a sink that logs, and releases them in both
+// processes. Other fork handlers run in between, in the forking thread: since
+// the locks count as held by it, they can call the logger.
+void before_fork() {
+  init_once();
+  lock_reentrant(g_output_mutex, t_output_depth);
+  lock_reentrant(g_state_mutex, t_state_depth);
+}
+
+void after_fork() {
+  unlock_reentrant(g_state_mutex, t_state_depth);
+  unlock_reentrant(g_output_mutex, t_output_depth);
+}
+
+[[maybe_unused]] const bool g_fork_handlers_registered =
+    (platform::at_fork(before_fork, after_fork), true);
+
 struct PrefixSnapshot {
   char value[sizeof(g_prefix_buf)];
   size_t len = 0;
@@ -130,15 +181,30 @@ struct PrefixSnapshot {
 
 // ── Color detection ──────────────────────
 
-[[nodiscard]] bool use_color() {
-  static const bool enabled = []() {
-    if (env_var("NO_COLOR") != nullptr)
-      return false;
+enum class ColorDecision { Undecided, Off, On };
 
-    return platform::stderr_supports_color();
-  }();
+// Whether stderr takes colors, decided once per process. Not a function-local
+// static: a child of fork() would inherit its initialization guard as taken
+// when another thread of the parent was deciding at the time of the fork, and
+// wait for it forever. Lock-free for the same reason. Two threads may decide at
+// once: the first decision stored holds for both.
+std::atomic<ColorDecision> g_color_decision{ColorDecision::Undecided};
+static_assert(std::atomic<ColorDecision>::is_always_lock_free);
 
-  return enabled;
+[[nodiscard]] bool use_color() {
+  ColorDecision decision = g_color_decision.load(std::memory_order_acquire);
+  if (decision == ColorDecision::Undecided) {
+    // NO_COLOR disables the colors when it is not empty (no-color.org).
+    const char *no_color = env_var("NO_COLOR");
+    const bool enabled = (no_color == nullptr || no_color[0] == '\0') &&
+                         platform::stderr_supports_color();
+    ColorDecision expected = ColorDecision::Undecided;
+    decision = enabled ? ColorDecision::On : ColorDecision::Off;
+    if (!g_color_decision.compare_exchange_strong(expected, decision,
+                                                  std::memory_order_acq_rel))
+      decision = expected;
+  }
+  return decision == ColorDecision::On;
 }
 
 // ── String helpers ───────────────────────
@@ -587,10 +653,8 @@ void set_source_location(bool enabled) {
 //  System info
 // ####################################
 
-[[nodiscard]] int pid() {
-  static const int cached = platform::process_id();
-  return cached;
-}
+// Not cached: a child of fork() has its own pid.
+[[nodiscard]] int pid() { return platform::process_id(); }
 
 [[nodiscard]] unsigned long long thread_id() {
   return platform::current_thread_id();

src/logger_platform.hpp

@@ -20,6 +20,9 @@ void write_stderr(const char *data, size_t size);
 [[nodiscard]] int process_id();
 [[nodiscard]] unsigned long long current_thread_id();
 [[nodiscard]] bool utc_timestamp(UtcTimestamp &out);
+// Makes fork() call `before` first, in the thread that forks, and `after` then,
+// in that thread of the parent and of the child. Does nothing without fork().
+void at_fork(void (*before)(), void (*after)());
 
 } // namespace coretrace::platform
 

src/logger_posix.cpp

@@ -62,4 +62,8 @@ void write_stderr(const char *data, size_t size) {
   return true;
 }
 
+void at_fork(void (*before)(), void (*after)()) {
+  (void)pthread_atfork(before, after, after);
+}
+
 } // namespace coretrace::platform

src/logger_windows.cpp

@@ -86,4 +86,6 @@ void write_stderr(const char *data, size_t size) {
   return true;
 }
 
+void at_fork(void (*)(), void (*)()) {}
+
 } // namespace coretrace::platform

tests/CMakeLists.txt

@@ -59,6 +59,22 @@ if(UNIX)
     COMMAND coretrace_logger_test_colors_tty no_color)
   set_tests_properties(coretrace_logger.test_colors_tty.no_color
     PROPERTIES ENVIRONMENT "NO_COLOR=1")
+  add_test(NAME coretrace_logger.test_colors_tty.empty_no_color
+    COMMAND coretrace_logger_test_colors_tty empty_no_color)
+endif()
+
+if(UNIX)
+  # fork() while another thread decides the colors: the test redefines isatty(), which the
+  # logger calls then, to make that decision last.
+  add_executable(coretrace_logger_test_fork_color test_fork_color.cpp fork_color_isatty.cpp)
+  target_link_libraries(coretrace_logger_test_fork_color PRIVATE coretrace_logger)
+  add_test(NAME coretrace_logger.test_fork_color COMMAND coretrace_logger_test_fork_color)
+  set_tests_properties(coretrace_logger.test_fork_color PROPERTIES TIMEOUT 20)
+
+  add_executable(coretrace_logger_test_fork test_fork.cpp)
+  target_link_libraries(coretrace_logger_test_fork PRIVATE coretrace_logger)
+  add_test(NAME coretrace_logger.test_fork COMMAND coretrace_logger_test_fork)
+  set_tests_properties(coretrace_logger.test_fork PROPERTIES TIMEOUT 30)
 endif()
 
 add_executable(coretrace_logger_test_sink_reentrancy test_sink_reentrancy.cpp)

tests/fork_color_isatty.cpp

@@ -0,0 +1,23 @@
+// isatty() for test_fork_color.cpp, linked into the test program ahead of the
+// C library. The logger calls it to decide whether stderr takes colors. The
+// first call says stderr is a terminal, after long enough for the test to fork
+// and to decide in another thread during it; later calls say it is not, at
+// once.
+
+#include <atomic>
+#include <time.h>
+#include <unistd.h>
+
+std::atomic<bool> g_deciding_colors{false};
+std::atomic<int> g_isatty_calls{0};
+
+// Same exception specification as the C library's declaration, which glibc
+// marks noexcept.
+extern "C" int isatty(int) noexcept(noexcept(::isatty(0))) {
+  if (g_isatty_calls.fetch_add(1) != 0)
+    return 0;
+  g_deciding_colors.store(true);
+  const timespec delay{0, 300 * 1000 * 1000};
+  nanosleep(&delay, nullptr);
+  return 1;
+}

tests/fork_helpers.hpp

@@ -0,0 +1,53 @@
+#ifndef CORETRACE_LOGGER_TESTS_FORK_HELPERS_HPP
+#define CORETRACE_LOGGER_TESTS_FORK_HELPERS_HPP
+
+// Helpers shared by the POSIX tests that fork. They need the default SIGCHLD
+// action, which each test sets: when SIGCHLD is ignored, waitpid() cannot reap
+// a child.
+
+#include <atomic>
+#include <chrono>
+#include <csignal>
+#include <cstdio>
+#include <sys/wait.h>
+#include <thread>
+#include <unistd.h>
+
+namespace ct_test {
+
+inline constexpr std::chrono::seconds kForkTimeout{5};
+
+/// True when `child` exits with status 0. A child still running after
+/// kForkTimeout is killed, and reported as hung.
+[[nodiscard]] inline bool child_succeeded(pid_t child) {
+  if (child <= 0)
+    return false;
+  int status = 0;
+  const auto deadline = std::chrono::steady_clock::now() + kForkTimeout;
+  while (std::chrono::steady_clock::now() < deadline) {
+    if (waitpid(child, &status, WNOHANG) == child)
+      return WIFEXITED(status) && WEXITSTATUS(status) == 0;
+    usleep(1000);
+  }
+  kill(child, SIGKILL);
+  waitpid(child, &status, 0);
+  std::fprintf(stderr, "child %d hung: killed after %lld s\n",
+               static_cast<int>(child),
+               static_cast<long long>(kForkTimeout.count()));
+  return false;
+}
+
+/// True once `flag` is set, false after kForkTimeout.
+[[nodiscard]] inline bool wait_for(const std::atomic<bool> &flag) {
+  const auto deadline = std::chrono::steady_clock::now() + kForkTimeout;
+  while (!flag.load()) {
+    if (std::chrono::steady_clock::now() >= deadline)
+      return false;
+    std::this_thread::yield();
+  }
+  return true;
+}
+
+} // namespace ct_test
+
+#endif // CORETRACE_LOGGER_TESTS_FORK_HELPERS_HPP

tests/test_colors_tty.cpp

@@ -40,12 +40,16 @@ int attach_pty_to_stderr() {
 } // namespace
 
 // The logger decides once per process whether stderr gets colors, so ctest
-// runs one process with NO_COLOR=1 ("no_color") and one without it.
+// runs one process with NO_COLOR=1 ("no_color"), one with NO_COLOR empty
+// ("empty_no_color"), which leaves the colors on, and one without it.
 int main(int argc, char **argv) {
   using namespace coretrace;
 
-  const bool no_color = argc > 1 && std::string_view(argv[1]) == "no_color";
-  if (!no_color)
+  const std::string_view mode = argc > 1 ? argv[1] : "";
+  const bool no_color = mode == "no_color";
+  if (mode == "empty_no_color")
+    CHECK(ct_test::set_env("NO_COLOR", ""));
+  else if (!no_color)
     unsetenv("NO_COLOR");
 
   set_sink(ct_test::capture_sink);