From 610446e9d7b00a2ecbba9be624843072f510e2f7 Mon Sep 17 00:00:00 2001 From: Hugo Date: Thu, 15 Oct 2026 00:22:32 +0200 Subject: [PATCH 01/16] fix(logger): decide colors without a static guard a fork child inherits use_color() kept its decision in a function-local static. When another thread was initializing it at the time of a fork(), the child inherited the initialization guard as taken, and its first call to color() waited for it forever: no thread of the child would ever release it. The decision is now an atomic, decided by the first caller; two threads deciding at once reach the same answer. Seen in coretrace-compiler, where a child forked while a thread logged hung: https://github.com/CoreTrace/coretrace-compiler/issues/213 --- src/logger.cpp | 23 +++++++++++++++-------- 1 file changed, 15 insertions(+), 8 deletions(-) diff --git a/src/logger.cpp b/src/logger.cpp index cfa0870..cf323b9 100644 --- a/src/logger.cpp +++ b/src/logger.cpp @@ -130,15 +130,22 @@ struct PrefixSnapshot { // ── Color detection ────────────────────── -[[nodiscard]] bool use_color() { - static const bool enabled = []() { - if (env_var("NO_COLOR") != nullptr) - return false; - - return platform::stderr_supports_color(); - }(); +// Whether stderr takes colors, decided once: 0 until then, 1 for no, 2 for yes. +// 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. Two threads may decide at +// once; they reach the same answer. +std::atomic g_color_decision{0}; - return enabled; +[[nodiscard]] bool use_color() { + int decision = g_color_decision.load(std::memory_order_acquire); + if (decision == 0) { + const bool enabled = + env_var("NO_COLOR") == nullptr && platform::stderr_supports_color(); + decision = enabled ? 2 : 1; + g_color_decision.store(decision, std::memory_order_release); + } + return decision == 2; } // ── String helpers ─────────────────────── From 4edb259c92a686ff51f841506f1baa3cf82d10fc Mon Sep 17 00:00:00 2001 From: Hugo Date: Thu, 15 Oct 2026 00:22:32 +0200 Subject: [PATCH 02/16] test: fork while another thread decides the colors The test redefines isatty(), which the logger calls once to decide whether stderr takes colors, so that the decision lasts while the test forks; the child then asks for a color and must exit. Before the fix, the child hung on the decision's initialization guard every time. --- tests/CMakeLists.txt | 9 ++++++ tests/fork_color_isatty.cpp | 17 +++++++++++ tests/test_fork_color.cpp | 59 +++++++++++++++++++++++++++++++++++++ 3 files changed, 85 insertions(+) create mode 100644 tests/fork_color_isatty.cpp create mode 100644 tests/test_fork_color.cpp diff --git a/tests/CMakeLists.txt b/tests/CMakeLists.txt index ff35d97..70f08f3 100644 --- a/tests/CMakeLists.txt +++ b/tests/CMakeLists.txt @@ -61,6 +61,15 @@ if(UNIX) PROPERTIES ENVIRONMENT "NO_COLOR=1") 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 Threads::Threads) + 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) +endif() + add_executable(coretrace_logger_test_sink_reentrancy test_sink_reentrancy.cpp) target_link_libraries(coretrace_logger_test_sink_reentrancy PRIVATE coretrace_logger) add_test(NAME coretrace_logger.test_sink_reentrancy COMMAND coretrace_logger_test_sink_reentrancy) diff --git a/tests/fork_color_isatty.cpp b/tests/fork_color_isatty.cpp new file mode 100644 index 0000000..d4e9d6a --- /dev/null +++ b/tests/fork_color_isatty.cpp @@ -0,0 +1,17 @@ +// isatty() for test_fork_color.cpp. The logger calls it once, to decide whether +// stderr takes colors: this definition, linked into the test program ahead of +// the C library, makes that decision last long enough for the test to fork +// during it. Kept apart from , whose declaration of isatty() may +// carry an exception specification. + +#include +#include + +std::atomic g_deciding_colors{false}; + +extern "C" int isatty(int) { + g_deciding_colors.store(true); + const timespec delay{0, 300 * 1000 * 1000}; + nanosleep(&delay, nullptr); + return 0; +} diff --git a/tests/test_fork_color.cpp b/tests/test_fork_color.cpp new file mode 100644 index 0000000..527db41 --- /dev/null +++ b/tests/test_fork_color.cpp @@ -0,0 +1,59 @@ +// A child of fork() can use the colors although another thread of the parent +// was deciding them at the time of the fork: the child decides them again, +// instead of waiting for a decision that no thread of the child will ever +// finish. + +#include "check.hpp" + +#include + +#include +#include +#include +#include +#include +#include + +extern std::atomic g_deciding_colors; + +namespace { + +constexpr std::chrono::seconds kChildTimeout{5}; + +// True when `child` exited, with its status in `status`; a child still running +// after kChildTimeout is killed. +bool reap(pid_t child, int &status) { + const auto deadline = std::chrono::steady_clock::now() + kChildTimeout; + while (std::chrono::steady_clock::now() < deadline) { + if (waitpid(child, &status, WNOHANG) == child) + return true; + usleep(1000); + } + kill(child, SIGKILL); + waitpid(child, &status, 0); + return false; +} + +} // namespace + +int main() { + std::thread decider([] { (void)coretrace::color(coretrace::Color::Red); }); + while (!g_deciding_colors.load()) { + } + + const pid_t child = fork(); + if (child == 0) { + (void)coretrace::color(coretrace::Color::Red); + _exit(0); + } + decider.join(); + CHECK(child > 0); + if (child <= 0) + return ct_test::result(); + + int status = 0; + const bool exited = reap(child, status); + CHECK(exited); + CHECK(exited && WIFEXITED(status) && WEXITSTATUS(status) == 0); + return ct_test::result(); +} From 01fe73f668ff017fd1c9823ee64529371b2959cc Mon Sep 17 00:00:00 2001 From: Hugo Date: Thu, 15 Oct 2026 00:22:33 +0200 Subject: [PATCH 03/16] docs(changelog): note the fork-safe color decision --- CHANGELOG.md | 2 ++ 1 file changed, 2 insertions(+) diff --git a/CHANGELOG.md b/CHANGELOG.md index bd27995..ebf96ec 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -5,6 +5,8 @@ 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 colored line when another thread of the + parent was deciding whether stderr takes colors at the time of the fork. ## v1.1.0 From f339a83d22642fc5115446f528161b0cabd34d65 Mon Sep 17 00:00:00 2001 From: Hugo Date: Thu, 15 Oct 2026 03:25:29 +0200 Subject: [PATCH 04/16] test: keep the fork color test from hanging under NO_COLOR Under NO_COLOR, the logger decides without calling isatty(), so the test waited forever for the decision to start: the wait now gives up after 5 s with a failed check, and the test unsets NO_COLOR, as test_colors_tty does. It also restores the default SIGCHLD action, which waitpid() needs to reap the child. The fake isatty() takes the exception specification of the C library's declaration, noexcept with glibc, instead of relying on the compiler to accept a mismatch with a system header. Threads::Threads already comes with coretrace_logger. --- tests/CMakeLists.txt | 2 +- tests/fork_color_isatty.cpp | 13 +++++++------ tests/test_fork_color.cpp | 29 +++++++++++++++++++++++++---- 3 files changed, 33 insertions(+), 11 deletions(-) diff --git a/tests/CMakeLists.txt b/tests/CMakeLists.txt index 70f08f3..2f59707 100644 --- a/tests/CMakeLists.txt +++ b/tests/CMakeLists.txt @@ -65,7 +65,7 @@ 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 Threads::Threads) + 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) endif() diff --git a/tests/fork_color_isatty.cpp b/tests/fork_color_isatty.cpp index d4e9d6a..98b00b8 100644 --- a/tests/fork_color_isatty.cpp +++ b/tests/fork_color_isatty.cpp @@ -1,15 +1,16 @@ -// isatty() for test_fork_color.cpp. The logger calls it once, to decide whether -// stderr takes colors: this definition, linked into the test program ahead of -// the C library, makes that decision last long enough for the test to fork -// during it. Kept apart from , whose declaration of isatty() may -// carry an exception specification. +// 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: each +// call lasts long enough for the test to fork during it. #include #include +#include std::atomic g_deciding_colors{false}; -extern "C" int isatty(int) { +// Same exception specification as the C library's declaration, which glibc +// marks noexcept. +extern "C" int isatty(int) noexcept(noexcept(::isatty(0))) { g_deciding_colors.store(true); const timespec delay{0, 300 * 1000 * 1000}; nanosleep(&delay, nullptr); diff --git a/tests/test_fork_color.cpp b/tests/test_fork_color.cpp index 527db41..5128a41 100644 --- a/tests/test_fork_color.cpp +++ b/tests/test_fork_color.cpp @@ -10,6 +10,7 @@ #include #include #include +#include #include #include #include @@ -18,12 +19,12 @@ extern std::atomic g_deciding_colors; namespace { -constexpr std::chrono::seconds kChildTimeout{5}; +constexpr std::chrono::seconds kTimeout{5}; // True when `child` exited, with its status in `status`; a child still running -// after kChildTimeout is killed. +// after kTimeout is killed. bool reap(pid_t child, int &status) { - const auto deadline = std::chrono::steady_clock::now() + kChildTimeout; + const auto deadline = std::chrono::steady_clock::now() + kTimeout; while (std::chrono::steady_clock::now() < deadline) { if (waitpid(child, &status, WNOHANG) == child) return true; @@ -34,11 +35,31 @@ bool reap(pid_t child, int &status) { return false; } +// True once the logger is deciding the colors, false after kTimeout. +bool wait_for_decision() { + const auto deadline = std::chrono::steady_clock::now() + kTimeout; + while (!g_deciding_colors.load()) { + if (std::chrono::steady_clock::now() >= deadline) + return false; + std::this_thread::yield(); + } + return true; +} + } // namespace int main() { + // The logger decides without isatty() under NO_COLOR, and waitpid() cannot + // reap a child when SIGCHLD is ignored: both may come from the environment. + unsetenv("NO_COLOR"); + std::signal(SIGCHLD, SIG_DFL); + std::thread decider([] { (void)coretrace::color(coretrace::Color::Red); }); - while (!g_deciding_colors.load()) { + const bool deciding = wait_for_decision(); + CHECK(deciding); + if (!deciding) { + decider.join(); + return ct_test::result(); } const pid_t child = fork(); From 84d68191787af5352f6b90121a0ad4d9265e20f0 Mon Sep 17 00:00:00 2001 From: Hugo Date: Thu, 15 Oct 2026 03:25:58 +0200 Subject: [PATCH 05/16] test: check that the first color decision holds and is not made again Two threads may decide the colors at once. The fake isatty() now tells the first caller, after a delay, that stderr is a terminal, and later callers at once that it is not: the main thread decides while the decider waits, and both must get the same color, as must later calls, which must not call isatty() again. The test fails: the decider's slower decision overwrites the one already stored. --- tests/fork_color_isatty.cpp | 11 ++++++++--- tests/test_fork_color.cpp | 21 ++++++++++++++++++--- 2 files changed, 26 insertions(+), 6 deletions(-) diff --git a/tests/fork_color_isatty.cpp b/tests/fork_color_isatty.cpp index 98b00b8..7c89750 100644 --- a/tests/fork_color_isatty.cpp +++ b/tests/fork_color_isatty.cpp @@ -1,18 +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: each -// call lasts long enough for the test to fork during it. +// 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 #include #include std::atomic g_deciding_colors{false}; +std::atomic 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 0; + return 1; } diff --git a/tests/test_fork_color.cpp b/tests/test_fork_color.cpp index 5128a41..8de194e 100644 --- a/tests/test_fork_color.cpp +++ b/tests/test_fork_color.cpp @@ -1,7 +1,8 @@ // A child of fork() can use the colors although another thread of the parent // was deciding them at the time of the fork: the child decides them again, // instead of waiting for a decision that no thread of the child will ever -// finish. +// finish. In the parent, the first decision stored holds for every thread, and +// later calls do not decide again. #include "check.hpp" @@ -11,11 +12,13 @@ #include #include #include +#include #include #include #include extern std::atomic g_deciding_colors; +extern std::atomic g_isatty_calls; namespace { @@ -54,7 +57,12 @@ int main() { unsetenv("NO_COLOR"); std::signal(SIGCHLD, SIG_DFL); - std::thread decider([] { (void)coretrace::color(coretrace::Color::Red); }); + using coretrace::Color; + + // The decider is told stderr is a terminal, after the main thread is told it + // is not: the main thread's decision is stored first. + std::string_view decider_red; + std::thread decider([&] { decider_red = coretrace::color(Color::Red); }); const bool deciding = wait_for_decision(); CHECK(deciding); if (!deciding) { @@ -64,10 +72,17 @@ int main() { const pid_t child = fork(); if (child == 0) { - (void)coretrace::color(coretrace::Color::Red); + (void)coretrace::color(Color::Red); _exit(0); } + const std::string_view main_red = coretrace::color(Color::Red); decider.join(); + CHECK(decider_red == main_red); + + const int calls = g_isatty_calls.load(); + CHECK(coretrace::color(Color::Red) == main_red); + CHECK(g_isatty_calls.load() == calls); + CHECK(child > 0); if (child <= 0) return ct_test::result(); From a0c2f45cd38a4fec513c7aac62a1e6e24de29cb7 Mon Sep 17 00:00:00 2001 From: Hugo Date: Thu, 15 Oct 2026 03:26:21 +0200 Subject: [PATCH 06/16] fix(logger): keep the first color decision when two threads decide at once Each thread that decided stored its answer, so the last one won: when NO_COLOR changed in between, or when SetConsoleMode() failed for one of them on Windows, a thread could color its lines while the decision kept for later said no. The decision is now stored only when none is, with a compare-exchange, and a thread that loses takes the one stored. The three states are named by an enum, and a static_assert checks that the atomic is lock-free: a child of fork() must not inherit a lock taken by the parent. --- src/logger.cpp | 28 +++++++++++++++++----------- 1 file changed, 17 insertions(+), 11 deletions(-) diff --git a/src/logger.cpp b/src/logger.cpp index cf323b9..4d914ce 100644 --- a/src/logger.cpp +++ b/src/logger.cpp @@ -130,22 +130,28 @@ struct PrefixSnapshot { // ── Color detection ────────────────────── -// Whether stderr takes colors, decided once: 0 until then, 1 for no, 2 for yes. -// 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. Two threads may decide at -// once; they reach the same answer. -std::atomic g_color_decision{0}; +enum class ColorDecision { Undecided, Off, On }; + +// 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 g_color_decision{ColorDecision::Undecided}; +static_assert(std::atomic::is_always_lock_free); [[nodiscard]] bool use_color() { - int decision = g_color_decision.load(std::memory_order_acquire); - if (decision == 0) { + ColorDecision decision = g_color_decision.load(std::memory_order_acquire); + if (decision == ColorDecision::Undecided) { const bool enabled = env_var("NO_COLOR") == nullptr && platform::stderr_supports_color(); - decision = enabled ? 2 : 1; - g_color_decision.store(decision, std::memory_order_release); + 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 == 2; + return decision == ColorDecision::On; } // ── String helpers ─────────────────────── From 4d43094d10f4dbb4a02099bbcc6ac7813bb5f67c Mon Sep 17 00:00:00 2001 From: Hugo Date: Thu, 15 Oct 2026 03:26:42 +0200 Subject: [PATCH 07/16] test: keep the colors on when NO_COLOR is empty no-color.org asks programs to disable colors when NO_COLOR is present and not an empty string. The new test_colors_tty.empty_no_color case sets NO_COLOR to an empty string and expects the colors of the default case. It fails: the logger disables the colors whenever NO_COLOR is set. --- tests/CMakeLists.txt | 2 ++ tests/test_colors_tty.cpp | 10 +++++++--- 2 files changed, 9 insertions(+), 3 deletions(-) diff --git a/tests/CMakeLists.txt b/tests/CMakeLists.txt index 2f59707..229f178 100644 --- a/tests/CMakeLists.txt +++ b/tests/CMakeLists.txt @@ -59,6 +59,8 @@ 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) diff --git a/tests/test_colors_tty.cpp b/tests/test_colors_tty.cpp index 998f48b..3287b61 100644 --- a/tests/test_colors_tty.cpp +++ b/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); From dce596a9c99de43a27f6c24526ddd224458a2cca Mon Sep 17 00:00:00 2001 From: Hugo Date: Thu, 15 Oct 2026 03:27:01 +0200 Subject: [PATCH 08/16] fix(logger): keep the colors on when NO_COLOR is empty no-color.org disables colors when NO_COLOR is present and not an empty string; the logger disabled them for an empty NO_COLOR too, as when a script sets NO_COLOR= to clear it. The README says which values disable the colors. --- README.md | 4 ++-- src/logger.cpp | 6 ++++-- 2 files changed, 6 insertions(+), 4 deletions(-) diff --git a/README.md b/README.md index 555c909..25db66a 100644 --- a/README.md +++ b/README.md @@ -230,7 +230,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 @@ -252,7 +252,7 @@ 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 | ## Output format diff --git a/src/logger.cpp b/src/logger.cpp index 4d914ce..ce88763 100644 --- a/src/logger.cpp +++ b/src/logger.cpp @@ -143,8 +143,10 @@ static_assert(std::atomic::is_always_lock_free); [[nodiscard]] bool use_color() { ColorDecision decision = g_color_decision.load(std::memory_order_acquire); if (decision == ColorDecision::Undecided) { - const bool enabled = - env_var("NO_COLOR") == nullptr && platform::stderr_supports_color(); + // 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, From 2c734051f0b8c6b84538393b6038270f094a7510 Mon Sep 17 00:00:00 2001 From: Hugo Date: Thu, 15 Oct 2026 04:03:22 +0200 Subject: [PATCH 09/16] test: fork while threads of the parent use the logger test_fork forks after the logger was used, and the child must be able to log: - before any initialization, fork() must finish it, so the environment defaults are those at the time of the fork; - the child's pid() must be its own; - while another thread writes a line, through a sink that takes 300 ms; - from inside a sink, where the forking thread holds the output lock itself. The reap and wait loops of test_fork_color move to fork_helpers.hpp, shared by both tests. All four checks fail: the environment is read after the fork, the child reports the parent's pid, and both children hang on the output lock they inherit. --- tests/CMakeLists.txt | 5 ++ tests/fork_helpers.hpp | 53 +++++++++++++++++++ tests/test_fork.cpp | 107 ++++++++++++++++++++++++++++++++++++++ tests/test_fork_color.cpp | 49 ++--------------- 4 files changed, 170 insertions(+), 44 deletions(-) create mode 100644 tests/fork_helpers.hpp create mode 100644 tests/test_fork.cpp diff --git a/tests/CMakeLists.txt b/tests/CMakeLists.txt index 229f178..8cdb819 100644 --- a/tests/CMakeLists.txt +++ b/tests/CMakeLists.txt @@ -70,6 +70,11 @@ if(UNIX) 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) diff --git a/tests/fork_helpers.hpp b/tests/fork_helpers.hpp new file mode 100644 index 0000000..e3fa7e8 --- /dev/null +++ b/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 +#include +#include +#include +#include +#include +#include + +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(child), + static_cast(kForkTimeout.count())); + return false; +} + +/// True once `flag` is set, false after kForkTimeout. +[[nodiscard]] inline bool wait_for(const std::atomic &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 diff --git a/tests/test_fork.cpp b/tests/test_fork.cpp new file mode 100644 index 0000000..f0d7c16 --- /dev/null +++ b/tests/test_fork.cpp @@ -0,0 +1,107 @@ +// fork() while threads of the parent use the logger: the child can log. fork() +// waits for the logger's initialization and for a line another thread is +// writing, so the child inherits neither half done; a sink can fork and its +// child still log; and the child's lines carry the child's pid. + +#include "check.hpp" +#include "fork_helpers.hpp" + +#include + +#include +#include +#include +#include +#include +#include +#include + +namespace { + +using coretrace::Level; + +// fork() finishes the logger's initialization when no thread has: the +// environment defaults are those at the time of the fork. Runs first, before +// any call initializes the logger. +void check_fork_initializes() { + CHECK(ct_test::set_env("CT_LOG_LEVEL", "debug")); + const pid_t child = fork(); + if (child == 0) + _exit(coretrace::min_level() == Level::Debug ? 0 : 1); + CHECK(ct_test::set_env("CT_LOG_LEVEL", "error")); + CHECK(coretrace::min_level() == Level::Debug); + CHECK(ct_test::child_succeeded(child)); +} + +void check_child_pid() { + CHECK(coretrace::pid() == getpid()); + const pid_t child = fork(); + if (child == 0) + _exit(coretrace::pid() == getpid() ? 0 : 1); + CHECK(ct_test::child_succeeded(child)); +} + +std::atomic g_writing{false}; + +// Writes the first line in 300 ms, long enough for the test to fork meanwhile. +void slow_sink(const char *, size_t) { + if (!g_writing.exchange(true)) + std::this_thread::sleep_for(std::chrono::milliseconds(300)); +} + +void check_fork_while_writing() { + coretrace::set_sink(slow_sink); + // The writer outlives the fork: ThreadSanitizer reports a thread that a + // child inherits finished and not joined. + std::atomic forked{false}; + std::thread writer([&] { + coretrace::log(Level::Info, "parent\n"); + (void)ct_test::wait_for(forked); + }); + const bool writing = ct_test::wait_for(g_writing); + CHECK(writing); + const pid_t child = writing ? fork() : -1; + if (child == 0) { + coretrace::log(Level::Info, "child\n"); + _exit(0); + } + forked = true; + writer.join(); + CHECK(ct_test::child_succeeded(child)); + coretrace::reset_sink(); +} + +pid_t g_sink_child = -1; + +// Forks on the line "fork": the child logs, from the sink and after it. +void forking_sink(const char *data, size_t size) { + if (std::string_view(data, size).find("fork") == std::string_view::npos) + return; + g_sink_child = fork(); + if (g_sink_child == 0) + coretrace::log(Level::Info, "child, in the sink\n"); +} + +void check_fork_from_sink() { + coretrace::set_sink(forking_sink); + coretrace::log(Level::Info, "fork\n"); + if (g_sink_child == 0) { + coretrace::log(Level::Info, "child, after the sink\n"); + _exit(0); + } + coretrace::reset_sink(); + CHECK(ct_test::child_succeeded(g_sink_child)); +} + +} // namespace + +int main() { + std::signal(SIGCHLD, SIG_DFL); + check_fork_initializes(); + check_child_pid(); + coretrace::set_min_level(Level::Info); + coretrace::enable_logging(); + check_fork_while_writing(); + check_fork_from_sink(); + return ct_test::result(); +} diff --git a/tests/test_fork_color.cpp b/tests/test_fork_color.cpp index 8de194e..1e3f5a4 100644 --- a/tests/test_fork_color.cpp +++ b/tests/test_fork_color.cpp @@ -5,55 +5,23 @@ // later calls do not decide again. #include "check.hpp" +#include "fork_helpers.hpp" #include #include -#include #include #include #include -#include #include #include extern std::atomic g_deciding_colors; extern std::atomic g_isatty_calls; -namespace { - -constexpr std::chrono::seconds kTimeout{5}; - -// True when `child` exited, with its status in `status`; a child still running -// after kTimeout is killed. -bool reap(pid_t child, int &status) { - const auto deadline = std::chrono::steady_clock::now() + kTimeout; - while (std::chrono::steady_clock::now() < deadline) { - if (waitpid(child, &status, WNOHANG) == child) - return true; - usleep(1000); - } - kill(child, SIGKILL); - waitpid(child, &status, 0); - return false; -} - -// True once the logger is deciding the colors, false after kTimeout. -bool wait_for_decision() { - const auto deadline = std::chrono::steady_clock::now() + kTimeout; - while (!g_deciding_colors.load()) { - if (std::chrono::steady_clock::now() >= deadline) - return false; - std::this_thread::yield(); - } - return true; -} - -} // namespace - int main() { - // The logger decides without isatty() under NO_COLOR, and waitpid() cannot - // reap a child when SIGCHLD is ignored: both may come from the environment. + // The logger decides without isatty() under NO_COLOR, which may come from + // the environment. unsetenv("NO_COLOR"); std::signal(SIGCHLD, SIG_DFL); @@ -63,7 +31,7 @@ int main() { // is not: the main thread's decision is stored first. std::string_view decider_red; std::thread decider([&] { decider_red = coretrace::color(Color::Red); }); - const bool deciding = wait_for_decision(); + const bool deciding = ct_test::wait_for(g_deciding_colors); CHECK(deciding); if (!deciding) { decider.join(); @@ -83,13 +51,6 @@ int main() { CHECK(coretrace::color(Color::Red) == main_red); CHECK(g_isatty_calls.load() == calls); - CHECK(child > 0); - if (child <= 0) - return ct_test::result(); - - int status = 0; - const bool exited = reap(child, status); - CHECK(exited); - CHECK(exited && WIFEXITED(status) && WEXITSTATUS(status) == 0); + CHECK(ct_test::child_succeeded(child)); return ct_test::result(); } From 1be612d5650495ac910acaa5288cc9d2680b7ebc Mon Sep 17 00:00:00 2001 From: Hugo Date: Thu, 15 Oct 2026 04:03:46 +0200 Subject: [PATCH 10/16] fix(logger): give a child of fork() its own pid pid() cached the process id in a function-local static, so after fork() the child's lines carried the parent's pid, and the child could also inherit the static's initialization guard taken by another thread of the parent, as with the color decision. pid() now asks the system each time: getpid() costs a fraction of a log line. --- include/coretrace/logger.hpp | 2 +- src/logger.cpp | 6 ++---- 2 files changed, 3 insertions(+), 5 deletions(-) diff --git a/include/coretrace/logger.hpp b/include/coretrace/logger.hpp index 6a59247..1840654 100644 --- a/include/coretrace/logger.hpp +++ b/include/coretrace/logger.hpp @@ -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). diff --git a/src/logger.cpp b/src/logger.cpp index ce88763..d45530c 100644 --- a/src/logger.cpp +++ b/src/logger.cpp @@ -602,10 +602,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(); From 9c8a61568bea49971a1b1738c106db9ee4b58e09 Mon Sep 17 00:00:00 2001 From: Hugo Date: Thu, 15 Oct 2026 04:08:38 +0200 Subject: [PATCH 11/16] fix(logger): let a child of fork() log while other threads used the logger A child of fork() has only the thread that forked. It inherited the output lock, or the state lock, taken by another thread of the parent writing a line at the time of the fork, and its first line waited for them forever; with libc++, it also waited forever for an initialization another thread was running, since std::call_once does not survive fork(). pthread_atfork() handlers now make fork() wait for them: the forking thread finishes the initialization, takes the output lock then the state lock, the order of a sink that logs, and releases them in the parent and in the child. The environment defaults are thus read at the latest by the first fork(). The output lock is a std::mutex, with a thread-local count of the guards held, instead of a std::recursive_mutex: a recursive mutex checks the id of its owner, which the child's thread does not share with the forking thread, so the child could not release it. A sink can still log, and a sink that forks gives a child that can log. --- src/logger.cpp | 33 ++++++++++++++++++++++++++++++--- src/logger_platform.hpp | 3 +++ src/logger_posix.cpp | 4 ++++ src/logger_windows.cpp | 2 ++ 4 files changed, 39 insertions(+), 3 deletions(-) diff --git a/src/logger.cpp b/src/logger.cpp index d45530c..be7e142 100644 --- a/src/logger.cpp +++ b/src/logger.cpp @@ -49,7 +49,11 @@ std::atomic g_modules_set_explicitly{0}; std::mutex g_state_mutex; // Protects atomicity of one log line output when thread-safe mode is on. -std::recursive_mutex g_output_mutex; +// t_output_depth counts the guards of the thread that holds it, so that a sink +// can log: not a std::recursive_mutex, which a child of fork() cannot release, +// since it checks the id of its owner, and the child's thread has another one. +std::mutex g_output_mutex; +thread_local int t_output_depth = 0; std::atomic g_thread_safe{1}; // enabled by default // ── Sink ───────────────────────────────── @@ -81,12 +85,12 @@ struct StateLockGuard { struct OutputLockGuard { OutputLockGuard() : locked(g_thread_safe.load(std::memory_order_acquire) != 0) { - if (locked) + if (locked && t_output_depth++ == 0) g_output_mutex.lock(); } ~OutputLockGuard() { - if (locked) + if (locked && --t_output_depth == 0) g_output_mutex.unlock(); } @@ -96,6 +100,29 @@ 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. +void before_fork() { + init_once(); + if (t_output_depth == 0) + g_output_mutex.lock(); + g_state_mutex.lock(); +} + +void after_fork() { + g_state_mutex.unlock(); + if (t_output_depth == 0) + g_output_mutex.unlock(); +} + +[[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; diff --git a/src/logger_platform.hpp b/src/logger_platform.hpp index 3e9e7c4..cf8b578 100644 --- a/src/logger_platform.hpp +++ b/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 diff --git a/src/logger_posix.cpp b/src/logger_posix.cpp index 8955eeb..1bc689d 100644 --- a/src/logger_posix.cpp +++ b/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 diff --git a/src/logger_windows.cpp b/src/logger_windows.cpp index 5204809..ff032b5 100644 --- a/src/logger_windows.cpp +++ b/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 From 008823b42c87ec671971fc78ea03beb6b9d0a3db Mon Sep 17 00:00:00 2001 From: Hugo Date: Thu, 15 Oct 2026 04:09:03 +0200 Subject: [PATCH 12/16] docs: describe fork(), the reentrant lock and an empty NO_COLOR The changelog lists the fork() fixes and the NO_COLOR change. The README and the API comments no longer call the output lock recursive or pid() cached, say that fork() waits for a line being written, and when the environment defaults are read. --- CHANGELOG.md | 7 +++++-- README.md | 8 ++++++-- include/coretrace/logger.hpp | 2 +- 3 files changed, 12 insertions(+), 5 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index ebf96ec..10ab34f 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -5,8 +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 colored line when another thread of the - parent was deciding whether stderr takes colors at the time of the fork. +- 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 diff --git a/README.md b/README.md index 25db66a..eb36bed 100644 --- a/README.md +++ b/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 @@ -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 ``` @@ -254,6 +256,8 @@ These functions write straight to the sink: unlike `log()`, they are not seriali | `CT_DEBUG` | comma-separated names | Set startup default enabled modules. Spaces around names are ignored | | `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 ``` diff --git a/include/coretrace/logger.hpp b/include/coretrace/logger.hpp index 1840654..2adf188 100644 --- a/include/coretrace/logger.hpp +++ b/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); From d63a1844f5efd81e4317e3e116d1419fa3674212 Mon Sep 17 00:00:00 2001 From: Hugo Date: Thu, 15 Oct 2026 04:37:33 +0200 Subject: [PATCH 13/16] test: log from fork handlers registered before the logger's fork() calls the prepare handlers in the reverse order of their registration, and the parent and child handlers in that order. A handler registered before the logger's, here by the test's own initialization, thus runs while the forking thread holds the logger's locks. The new check logs and sets the sink from such handlers, in the prepare, parent and child phases, and expects the lines and the child to come through; alarm() ends the test if fork() hangs. It fails: the forking thread waits for the locks it holds, and fork() never returns. --- tests/test_fork.cpp | 43 ++++++++++++++++++++++++++++++++++++++++++- 1 file changed, 42 insertions(+), 1 deletion(-) diff --git a/tests/test_fork.cpp b/tests/test_fork.cpp index f0d7c16..4ff63e1 100644 --- a/tests/test_fork.cpp +++ b/tests/test_fork.cpp @@ -1,7 +1,8 @@ // fork() while threads of the parent use the logger: the child can log. fork() // waits for the logger's initialization and for a line another thread is // writing, so the child inherits neither half done; a sink can fork and its -// child still log; and the child's lines carry the child's pid. +// child still log; other fork handlers can still log; and the child's lines +// carry the child's pid. #include "check.hpp" #include "fork_helpers.hpp" @@ -12,6 +13,8 @@ #include #include #include +#include +#include #include #include #include @@ -93,6 +96,43 @@ void check_fork_from_sink() { CHECK(ct_test::child_succeeded(g_sink_child)); } +std::atomic g_log_from_fork_handlers{false}; + +void log_from_fork_handler() { + if (!g_log_from_fork_handlers.load()) + return; + coretrace::log(Level::Info, "from a fork handler\n"); + coretrace::set_sink(ct_test::capture_sink); +} + +// Registered by this translation unit's initialization, which runs before the +// logger's: fork() calls the prepare handler after the logger's, and the +// parent and child handlers before the logger's, while the forking thread holds +// the logger's locks. +const bool g_fork_handlers_registered = + pthread_atfork(log_from_fork_handler, log_from_fork_handler, + log_from_fork_handler) == 0; + +void check_logging_from_fork_handlers() { + CHECK(g_fork_handlers_registered); + coretrace::set_sink(ct_test::capture_sink); + const size_t from = ct_test::captured.size(); + g_log_from_fork_handlers = true; + alarm(5); // A fork() that hangs in a handler kills the test. + const pid_t child = fork(); + if (child == 0) + _exit(0); + alarm(0); + g_log_from_fork_handlers = false; + CHECK(ct_test::child_succeeded(child)); + + // One line from the prepare handler, one from the parent handler. + constexpr std::string_view line = "from a fork handler"; + const size_t first = ct_test::captured.find(line, from); + CHECK(first != std::string::npos && ct_test::logged(line, first + 1)); + coretrace::reset_sink(); +} + } // namespace int main() { @@ -103,5 +143,6 @@ int main() { coretrace::enable_logging(); check_fork_while_writing(); check_fork_from_sink(); + check_logging_from_fork_handlers(); return ct_test::result(); } From 2e82a6d51134b6e62ab4015163f79387553bbd15 Mon Sep 17 00:00:00 2001 From: Hugo Date: Thu, 15 Oct 2026 04:43:07 +0200 Subject: [PATCH 14/16] fix(logger): let fork handlers registered before the logger's call it Between the logger's prepare and parent or child handlers, fork() runs the handlers registered before the logger's, in the forking thread, which then held both locks: a log() or a set_sink() from such a handler waited for a lock its own thread held, and fork() never returned. A regression of the previous commit: without handlers, the logger never held a lock across the fork. The handlers' acquisitions now go through the reentrance of the guards: both locks keep a thread-local count, taken when it goes from 0 to 1 and released when it returns to 0, for the state lock as for the output lock. The forking thread can thus call the logger from any fork handler, while the other threads still wait. --- src/logger.cpp | 46 ++++++++++++++++++++++++++++++---------------- 1 file changed, 30 insertions(+), 16 deletions(-) diff --git a/src/logger.cpp b/src/logger.cpp index be7e142..a2292f6 100644 --- a/src/logger.cpp +++ b/src/logger.cpp @@ -45,13 +45,17 @@ std::atomic 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. + // Protects mutable logger state (prefix + modules table). std::mutex g_state_mutex; +thread_local int t_state_depth = 0; // Protects atomicity of one log line output when thread-safe mode is on. -// t_output_depth counts the guards of the thread that holds it, so that a sink -// can log: not a std::recursive_mutex, which a child of fork() cannot release, -// since it checks the id of its owner, and the child's thread has another one. std::mutex g_output_mutex; thread_local int t_output_depth = 0; std::atomic g_thread_safe{1}; // enabled by default @@ -74,9 +78,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; @@ -85,13 +100,13 @@ struct StateLockGuard { struct OutputLockGuard { OutputLockGuard() : locked(g_thread_safe.load(std::memory_order_acquire) != 0) { - if (locked && t_output_depth++ == 0) - g_output_mutex.lock(); + if (locked) + lock_reentrant(g_output_mutex, t_output_depth); } ~OutputLockGuard() { - if (locked && --t_output_depth == 0) - g_output_mutex.unlock(); + if (locked) + unlock_reentrant(g_output_mutex, t_output_depth); } OutputLockGuard(const OutputLockGuard &) = delete; @@ -106,18 +121,17 @@ struct OutputLockGuard { // 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. +// 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(); - if (t_output_depth == 0) - g_output_mutex.lock(); - g_state_mutex.lock(); + lock_reentrant(g_output_mutex, t_output_depth); + lock_reentrant(g_state_mutex, t_state_depth); } void after_fork() { - g_state_mutex.unlock(); - if (t_output_depth == 0) - g_output_mutex.unlock(); + unlock_reentrant(g_state_mutex, t_state_depth); + unlock_reentrant(g_output_mutex, t_output_depth); } [[maybe_unused]] const bool g_fork_handlers_registered = From d6f58a0c9a2a8f8c567494f93c69f829c3cf4afc Mon Sep 17 00:00:00 2001 From: Hugo Date: Thu, 15 Oct 2026 04:43:37 +0200 Subject: [PATCH 15/16] test: fork while the program exits, after the logger's destructors An atexit() handler registered by the test's own initialization, before the logger's, runs after the logger's static destructors, and forks. The logger's fork handlers still run then. It fails on macOS: libc++ destroys the logger's mutexes, and the prepare handler aborts on "mutex lock failed: Invalid argument". --- tests/test_fork.cpp | 21 +++++++++++++++++++-- 1 file changed, 19 insertions(+), 2 deletions(-) diff --git a/tests/test_fork.cpp b/tests/test_fork.cpp index 4ff63e1..be70aac 100644 --- a/tests/test_fork.cpp +++ b/tests/test_fork.cpp @@ -1,8 +1,8 @@ // fork() while threads of the parent use the logger: the child can log. fork() // waits for the logger's initialization and for a line another thread is // writing, so the child inherits neither half done; a sink can fork and its -// child still log; other fork handlers can still log; and the child's lines -// carry the child's pid. +// child still log; other fork handlers can still log; fork() still works while +// the program exits; and the child's lines carry the child's pid. #include "check.hpp" #include "fork_helpers.hpp" @@ -13,6 +13,8 @@ #include #include #include +#include +#include #include #include #include @@ -133,10 +135,25 @@ void check_logging_from_fork_handlers() { coretrace::reset_sink(); } +void fork_at_exit() { + const pid_t child = fork(); + if (child == 0) + _exit(0); + if (!ct_test::child_succeeded(child)) { + std::fputs("fork() at exit failed\n", stderr); + _exit(1); + } +} + +// Registered by this translation unit's initialization, which runs before the +// logger's: fork_at_exit() runs after the logger's static destructors. +const bool g_fork_at_exit_registered = std::atexit(fork_at_exit) == 0; + } // namespace int main() { std::signal(SIGCHLD, SIG_DFL); + CHECK(g_fork_at_exit_registered); check_fork_initializes(); check_child_pid(); coretrace::set_min_level(Level::Info); From 73c919805af8d3522c35f0834dc8820bb888049d Mon Sep 17 00:00:00 2001 From: Hugo Date: Thu, 15 Oct 2026 04:44:20 +0200 Subject: [PATCH 16/16] fix(logger): keep the locks alive while the program exits The fork handlers lock the logger's mutexes on every fork(), including one made by an atexit() handler or a static destructor that runs after this file's static destructors. libc++ destroys a std::mutex, and locking it then threw "mutex lock failed: Invalid argument" from the prepare handler, aborting the program. A regression of the fork handlers: without them, fork() never touched the logger. The two mutexes are now never destroyed: they live in a union whose destructor does nothing, still constant-initialized. --- src/logger.cpp | 14 ++++++++++++-- 1 file changed, 12 insertions(+), 2 deletions(-) diff --git a/src/logger.cpp b/src/logger.cpp index a2292f6..f70ede5 100644 --- a/src/logger.cpp +++ b/src/logger.cpp @@ -51,12 +51,22 @@ std::atomic g_modules_set_explicitly{0}; // 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 union Immortal { + T value; + constexpr Immortal() : value() {} + ~Immortal() {} +}; + // Protects mutable logger state (prefix + modules table). -std::mutex g_state_mutex; +Immortal 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::mutex g_output_mutex; +Immortal g_output_lock; +std::mutex &g_output_mutex = g_output_lock.value; thread_local int t_output_depth = 0; std::atomic g_thread_safe{1}; // enabled by default