From cdb994e2993a7e60ab1e26e8b5b5a2831f804977 Mon Sep 17 00:00:00 2001 From: Ramakrishna Prabhu Date: Mon, 24 Aug 2026 10:07:01 -0500 Subject: [PATCH 01/11] refactor(logger): give each component library its own logger The logger was a single process-wide instance hosted in one compiled translation unit, so every solver library shared it. Splitting libcuopt into components means routing and mathopt should log independently, and nothing should have to exist purely to host the state. The logger is now header-only and, crucially, hidden. Hidden visibility is what does the separating: the static local of an inline function is emitted as an STB_GNU_UNIQUE symbol, which glibc merges across the whole process regardless of RTLD_LOCAL, so a header-only logger with default visibility would still have been one shared instance. Callers outside the libraries cannot reach a hidden logger, so each component exports a configure entry point. `init_logger_t` keeps its meaning -- configure the logger of whichever image constructs it, which is what the pdlp, mip and grpc solve paths already want -- and the new `init_component_logger_t` reaches a chosen library from outside. It defaults to mathopt, so all eight existing external call sites keep working unchanged, and routing is opted into explicitly. Two things had to change to make one log file survive several loggers: - The exported entry point now takes the same ref-count guard that `init_logger_t` takes. Without it the MIP solve path reconfigured the logger mid-run and, with truncate set, cleared a file the caller had already written to. - File sinks always open in append mode, with a single explicit truncate up front. A non-appending sink writes from offset 0 and silently overwrites what another logger has appended. routing::solve now initialises its own logger from the settings. Routing never constructed one, so its CUOPT_LOG_ERROR calls went into a buffer that nothing drained and were lost. Verified: libcuopt.so exports the four entry points and none of the logger state; cuopt_cli writes both its own and the solver's messages to one file and still truncates between runs. ctest failures are identical to clean main in this environment (10 suites, 908 gtest failures, both). Co-Authored-By: Claude Opus 5 --- cpp/CMakeLists.txt | 6 + cpp/cuopt_cli.cpp | 11 +- cpp/src/CMakeLists.txt | 1 - cpp/src/math_optimization/CMakeLists.txt | 1 + cpp/src/math_optimization/logger_entry.cpp | 24 ++ cpp/src/routing/CMakeLists.txt | 3 +- cpp/src/routing/logger_entry.cpp | 24 ++ cpp/src/routing/solve.cu | 4 + cpp/src/utilities/logger.cpp | 191 ---------- cpp/src/utilities/logger.hpp | 343 +++++++++++++++++- cpp/tests/dual_simplex/unit_tests/solve.cpp | 8 +- .../dual_simplex/unit_tests/solve_barrier.cu | 4 +- 12 files changed, 408 insertions(+), 212 deletions(-) create mode 100644 cpp/src/math_optimization/logger_entry.cpp create mode 100644 cpp/src/routing/logger_entry.cpp delete mode 100644 cpp/src/utilities/logger.cpp diff --git a/cpp/CMakeLists.txt b/cpp/CMakeLists.txt index 4ce11b830b..3d121d7357 100644 --- a/cpp/CMakeLists.txt +++ b/cpp/CMakeLists.txt @@ -569,6 +569,12 @@ target_compile_definitions(cuopt_objs PUBLIC CUSPARSE_ENABLE_EXPERIMENTAL_API ) +# Lets callers reach routing's logger through init_component_logger_t. Routing is optional, +# so the entry point it declares is only linkable when routing was actually built. +if(NOT SKIP_ROUTING_BUILD) + target_compile_definitions(cuopt_objs PUBLIC CUOPT_HAS_ROUTING) +endif() + target_compile_options(cuopt_objs PRIVATE "$<$:${CUOPT_CXX_FLAGS}>" "$<$:${CUOPT_CUDA_FLAGS}>" diff --git a/cpp/cuopt_cli.cpp b/cpp/cuopt_cli.cpp index e070425eab..539f9f1321 100644 --- a/cpp/cuopt_cli.cpp +++ b/cpp/cuopt_cli.cpp @@ -100,8 +100,15 @@ int run_single_file(const std::string& file_path, cuopt::mathematical_optimization::io::mps_reader_type_t mps_reader, cuopt::mathematical_optimization::solver_settings_t& settings) { - cuopt::init_logger_t log(settings.get_parameter(CUOPT_LOG_FILE), - settings.get_parameter(CUOPT_LOG_TO_CONSOLE)); + // The solver's logger lives in the solver library and is not reachable from here, so + // configure it through its exported entry point. The CLI then configures its own logger + // for the messages it emits itself; it appends rather than truncates so that it does not + // clear the file the solver has just opened. + const auto log_file = settings.get_parameter(CUOPT_LOG_FILE); + const auto log_console = settings.get_parameter(CUOPT_LOG_TO_CONSOLE); + + cuopt::init_component_logger_t solver_log(log_file, log_console); + cuopt::init_logger_t log(log_file, log_console, /*truncate=*/false); std::string base_filename = file_path.substr(file_path.find_last_of("/\\") + 1); diff --git a/cpp/src/CMakeLists.txt b/cpp/src/CMakeLists.txt index e8737cf6da..db71f8fa4d 100644 --- a/cpp/src/CMakeLists.txt +++ b/cpp/src/CMakeLists.txt @@ -4,7 +4,6 @@ # cmake-format: on set(UTIL_SRC_FILES ${CMAKE_CURRENT_SOURCE_DIR}/utilities/seed_generator.cu - ${CMAKE_CURRENT_SOURCE_DIR}/utilities/logger.cpp ${CMAKE_CURRENT_SOURCE_DIR}/utilities/version_info.cpp ${CMAKE_CURRENT_SOURCE_DIR}/utilities/timestamp_utils.cpp ${CMAKE_CURRENT_SOURCE_DIR}/utilities/work_unit_scheduler.cpp) diff --git a/cpp/src/math_optimization/CMakeLists.txt b/cpp/src/math_optimization/CMakeLists.txt index efa1600c54..25449bc929 100644 --- a/cpp/src/math_optimization/CMakeLists.txt +++ b/cpp/src/math_optimization/CMakeLists.txt @@ -9,6 +9,7 @@ list(PREPEND ${CMAKE_CURRENT_SOURCE_DIR}/solution_reader.cu ${CMAKE_CURRENT_SOURCE_DIR}/solution_writer.cu ${CMAKE_CURRENT_SOURCE_DIR}/tic_toc.cpp + ${CMAKE_CURRENT_SOURCE_DIR}/logger_entry.cpp ) set(CUOPT_SRC_FILES ${CUOPT_SRC_FILES} diff --git a/cpp/src/math_optimization/logger_entry.cpp b/cpp/src/math_optimization/logger_entry.cpp new file mode 100644 index 0000000000..b1ed0907a7 --- /dev/null +++ b/cpp/src/math_optimization/logger_entry.cpp @@ -0,0 +1,24 @@ +/* clang-format off */ +/* + * SPDX-FileCopyrightText: Copyright (c) 2026, NVIDIA CORPORATION & AFFILIATES. All rights reserved. + * SPDX-License-Identifier: Apache-2.0 + */ +/* clang-format on */ + +#include + +/* + * The logger itself is header-only and hidden, so it is private to each component library. + * This translation unit is compiled into cuopt_mathopt only, which is what makes the + * functions below reach mathopt's instance and no other. + */ +namespace cuopt::mathematical_optimization { + +void configure_logging(const std::string& log_file, bool log_to_console, bool truncate) +{ + cuopt::configure_logging_impl(log_file, log_to_console, truncate); +} + +void reset_logging() { cuopt::reset_logging_impl(); } + +} // namespace cuopt::mathematical_optimization diff --git a/cpp/src/routing/CMakeLists.txt b/cpp/src/routing/CMakeLists.txt index 452c4806da..abf11bd6d0 100644 --- a/cpp/src/routing/CMakeLists.txt +++ b/cpp/src/routing/CMakeLists.txt @@ -1,9 +1,10 @@ # cmake-format: off -# SPDX-FileCopyrightText: Copyright (c) 2024-2025 NVIDIA CORPORATION & AFFILIATES. All rights reserved. +# SPDX-FileCopyrightText: Copyright (c) 2024-2026, NVIDIA CORPORATION & AFFILIATES. All rights reserved. # SPDX-License-Identifier: Apache-2.0 # cmake-format: on set(ROUTING_SRC_FILES + ${CMAKE_CURRENT_SOURCE_DIR}/logger_entry.cpp ${CMAKE_CURRENT_SOURCE_DIR}/local_search/compute_insertions.cu ${CMAKE_CURRENT_SOURCE_DIR}/ges/squeeze.cu ${CMAKE_CURRENT_SOURCE_DIR}/local_search/sliding_window.cu diff --git a/cpp/src/routing/logger_entry.cpp b/cpp/src/routing/logger_entry.cpp new file mode 100644 index 0000000000..b284623e1f --- /dev/null +++ b/cpp/src/routing/logger_entry.cpp @@ -0,0 +1,24 @@ +/* clang-format off */ +/* + * SPDX-FileCopyrightText: Copyright (c) 2026, NVIDIA CORPORATION & AFFILIATES. All rights reserved. + * SPDX-License-Identifier: Apache-2.0 + */ +/* clang-format on */ + +#include + +/* + * The logger itself is header-only and hidden, so it is private to each component library. + * This translation unit is compiled into cuopt_routing only, which is what makes the + * functions below reach routing's instance and no other. + */ +namespace cuopt::routing { + +void configure_logging(const std::string& log_file, bool log_to_console, bool truncate) +{ + cuopt::configure_logging_impl(log_file, log_to_console, truncate); +} + +void reset_logging() { cuopt::reset_logging_impl(); } + +} // namespace cuopt::routing diff --git a/cpp/src/routing/solve.cu b/cpp/src/routing/solve.cu index a7caf88ad9..89c6ed2c59 100644 --- a/cpp/src/routing/solve.cu +++ b/cpp/src/routing/solve.cu @@ -16,6 +16,10 @@ template assignment_t solve(data_model_view_t const& data_model, solver_settings_t const& settings) { + // Routing's logger is private to cuopt_routing and starts out sinking into a buffer, so + // without this the CUOPT_LOG_ERROR calls below are recorded and never emitted anywhere. + init_logger_t log("", settings.get_error_logging_mode()); + try { cuopt::routing::solver_t solver(data_model, settings); return solver.solve(); diff --git a/cpp/src/utilities/logger.cpp b/cpp/src/utilities/logger.cpp deleted file mode 100644 index 217f9c64cb..0000000000 --- a/cpp/src/utilities/logger.cpp +++ /dev/null @@ -1,191 +0,0 @@ -/* clang-format off */ -/* - * SPDX-FileCopyrightText: Copyright (c) 2025, NVIDIA CORPORATION & AFFILIATES. All rights reserved. - * SPDX-License-Identifier: Apache-2.0 - */ -/* clang-format on */ - -#include -#include - -namespace cuopt { - -struct buffered_entry { - rapids_logger::level_enum level; - std::string msg; -}; - -// Buffer to store log messages -class log_buffer { - public: - log_buffer() = default; - ~log_buffer() = default; - - void log(rapids_logger::level_enum lvl, const char* msg) - { - std::lock_guard lock(mutex); - if (!msg) return; - std::string str(msg); - - if (!str.empty() && str.back() == '\n') { str.pop_back(); } - messages.push_back({lvl, std::move(str)}); - } - - size_t size() const - { - std::lock_guard lock(mutex); - return messages.size(); - } - - std::vector drain_all() - { - std::lock_guard lock(mutex); - std::vector out; - out.swap(messages); - return out; - } - - std::vector messages; - mutable std::mutex mutex; -}; - -log_buffer& global_log_buffer() -{ - static log_buffer buffer; - return buffer; -} - -// Callback function for the buffer sink -static void buffer_log_callback(int lvl, const char* msg) -{ - // store level with message; actual filtering happens at logger time - global_log_buffer().log(static_cast(lvl), msg); -} - -/** - * @brief Returns the default sink for the global logger. - * - * If the environment variable `CUOPT_DEBUG_LOG_FILE` is defined, the default sink is a sink to that - * file. Otherwise, the default is to dump to stderr. - * - * @return sink_ptr The sink to use - */ -rapids_logger::sink_ptr default_sink() -{ - return std::make_shared(buffer_log_callback); -} - -/** - * @brief Returns the default log pattern for the global logger. - * - * @return std::string The default log pattern. - */ -inline std::string default_pattern() { return "[%Y-%m-%d %H:%M:%S:%f] [%n] [%-6l] %v"; } - -/** - * @brief Returns the default log level for the global logger. - * - * @return rapids_logger::level_enum The default log level. - */ -inline rapids_logger::level_enum default_level() -{ -#if CUOPT_LOG_ACTIVE_LEVEL == RAPIDS_LOGGER_LOG_LEVEL_TRACE - return rapids_logger::level_enum::trace; -#elif CUOPT_LOG_ACTIVE_LEVEL == RAPIDS_LOGGER_LOG_LEVEL_DEBUG - return rapids_logger::level_enum::debug; -#elif CUOPT_LOG_ACTIVE_LEVEL == RAPIDS_LOGGER_LOG_LEVEL_INFO - return rapids_logger::level_enum::info; -#elif CUOPT_LOG_ACTIVE_LEVEL == RAPIDS_LOGGER_LOG_LEVEL_WARN - return rapids_logger::level_enum::warn; -#elif CUOPT_LOG_ACTIVE_LEVEL == RAPIDS_LOGGER_LOG_LEVEL_ERROR - return rapids_logger::level_enum::error; -#elif CUOPT_LOG_ACTIVE_LEVEL == RAPIDS_LOGGER_LOG_LEVEL_CRITICAL - return rapids_logger::level_enum::critical; -#else - return rapids_logger::level_enum::info; -#endif -} - -rapids_logger::logger& default_logger() -{ - static rapids_logger::logger logger_ = [] { - rapids_logger::logger logger_{"CUOPT", {default_sink()}}; -#if CUOPT_LOG_ACTIVE_LEVEL >= RAPIDS_LOGGER_LOG_LEVEL_INFO - logger_.set_pattern("%v"); -#else - logger_.set_pattern(default_pattern()); -#endif - logger_.set_level(default_level()); - logger_.flush_on(rapids_logger::level_enum::debug); - - return logger_; - }(); - - return logger_; -} - -void reset_default_logger() -{ - default_logger().sinks().clear(); - default_logger().sinks().push_back(default_sink()); -#if CUOPT_LOG_ACTIVE_LEVEL >= RAPIDS_LOGGER_LOG_LEVEL_INFO - default_logger().set_pattern("%v"); -#else - default_logger().set_pattern(default_pattern()); -#endif - default_logger().set_level(default_level()); - default_logger().flush_on(rapids_logger::level_enum::debug); -} - -// Guard object whose destructor resets the logger -struct logger_config_guard { - ~logger_config_guard() { cuopt::reset_default_logger(); } -}; - -// Weak reference to detect if any init_logger_t instance is still alive -static std::weak_ptr g_active_guard; -static std::mutex g_guard_mutex; - -init_logger_t::init_logger_t(std::string log_file, bool log_to_console) -{ - std::lock_guard lock(g_guard_mutex); - - auto existing_guard = g_active_guard.lock(); - if (existing_guard) { - // Reuse existing configuration, just hold a reference to keep it alive - guard_ = existing_guard; - return; - } - - cuopt::default_logger().sinks().clear(); - - // re-initialize sinks - if (log_to_console) { - cuopt::default_logger().sinks().push_back( - std::make_shared(std::cout)); - } - if (!log_file.empty()) { - cuopt::default_logger().sinks().push_back( - std::make_shared(log_file, true)); - cuopt::default_logger().flush_on(rapids_logger::level_enum::debug); - } - -#if CUOPT_LOG_ACTIVE_LEVEL >= RAPIDS_LOGGER_LOG_LEVEL_INFO - cuopt::default_logger().set_pattern("%v"); -#else - cuopt::default_logger().set_pattern(cuopt::default_pattern()); -#endif - - // Extract messages from the global buffer and log to the default logger - auto buffered_messages = global_log_buffer().drain_all(); - for (const auto& entry : buffered_messages) { - cuopt::default_logger().log(entry.level, entry.msg.c_str()); - } - - // Create guard and store weak reference for future instances to find - auto guard = std::make_shared(); - g_active_guard = guard; - guard_ = guard; -} - -} // namespace cuopt diff --git a/cpp/src/utilities/logger.hpp b/cpp/src/utilities/logger.hpp index 2f9053b05f..bdc9564319 100644 --- a/cpp/src/utilities/logger.hpp +++ b/cpp/src/utilities/logger.hpp @@ -15,6 +15,7 @@ #include #include +#include #include #include #include @@ -22,32 +23,352 @@ #include #include -namespace CUOPT_EXPORT cuopt { +/* + * The logger and its buffer are defined inline and with hidden visibility, so each library + * that links this header owns its own. cuOpt ships as separate solver libraries and + * rapids_logger provides the logger type rather than a shared instance, so there is no + * single place to host one without a library existing purely to hold it. Each solver + * configures its own logging through its own settings. + * + * Hidden visibility is what does the separating, and it is not optional. The static local + * of an inline function is emitted as an STB_GNU_UNIQUE symbol, which glibc merges across + * the whole process regardless of RTLD_LOCAL, so a header-only logger with default + * visibility would still be one shared instance. Do not mark this namespace CUOPT_EXPORT. + * + * Callers outside the libraries cannot reach a hidden logger, so each component exports a + * configure entry point instead -- see log_target_t and init_component_logger_t below. + */ +namespace cuopt { + +struct buffered_entry { + rapids_logger::level_enum level; + std::string msg; +}; + +// Buffer to store log messages +class log_buffer { + public: + log_buffer() = default; + ~log_buffer() = default; + + void log(rapids_logger::level_enum lvl, const char* msg) + { + std::lock_guard lock(mutex); + if (!msg) return; + std::string str(msg); + + if (!str.empty() && str.back() == '\n') { str.pop_back(); } + messages.push_back({lvl, std::move(str)}); + } + + size_t size() const + { + std::lock_guard lock(mutex); + return messages.size(); + } + + std::vector drain_all() + { + std::lock_guard lock(mutex); + std::vector out; + out.swap(messages); + return out; + } + + std::vector messages; + mutable std::mutex mutex; +}; + +inline log_buffer& global_log_buffer() +{ + static log_buffer buffer; + return buffer; +} + +// Callback function for the buffer sink +inline void buffer_log_callback(int lvl, const char* msg) +{ + // store level with message; actual filtering happens at logger time + global_log_buffer().log(static_cast(lvl), msg); +} /** - * @brief Get the default logger. + * @brief Returns the default sink for the global logger. + * + * If the environment variable `CUOPT_DEBUG_LOG_FILE` is defined, the default sink is a sink to that + * file. Otherwise, the default is to dump to stderr. * - * @return logger& The default logger + * @return sink_ptr The sink to use */ -rapids_logger::logger& default_logger(); +inline rapids_logger::sink_ptr default_sink() +{ + return std::make_shared(buffer_log_callback); +} /** - * @brief Reset the default logger to the default settings. - * This is needed when we are running multiple tests and each test has different logger settings - * and we need to reset the logger to the default settings before each test. + * @brief Returns the default log pattern for the global logger. + * + * @return std::string The default log pattern. */ -void reset_default_logger(); +inline std::string default_pattern() { return "[%Y-%m-%d %H:%M:%S:%f] [%n] [%-6l] %v"; } + +/** + * @brief Returns the default log level for the global logger. + * + * @return rapids_logger::level_enum The default log level. + */ +inline rapids_logger::level_enum default_level() +{ +#if CUOPT_LOG_ACTIVE_LEVEL == RAPIDS_LOGGER_LOG_LEVEL_TRACE + return rapids_logger::level_enum::trace; +#elif CUOPT_LOG_ACTIVE_LEVEL == RAPIDS_LOGGER_LOG_LEVEL_DEBUG + return rapids_logger::level_enum::debug; +#elif CUOPT_LOG_ACTIVE_LEVEL == RAPIDS_LOGGER_LOG_LEVEL_INFO + return rapids_logger::level_enum::info; +#elif CUOPT_LOG_ACTIVE_LEVEL == RAPIDS_LOGGER_LOG_LEVEL_WARN + return rapids_logger::level_enum::warn; +#elif CUOPT_LOG_ACTIVE_LEVEL == RAPIDS_LOGGER_LOG_LEVEL_ERROR + return rapids_logger::level_enum::error; +#elif CUOPT_LOG_ACTIVE_LEVEL == RAPIDS_LOGGER_LOG_LEVEL_CRITICAL + return rapids_logger::level_enum::critical; +#else + return rapids_logger::level_enum::info; +#endif +} + +inline rapids_logger::logger& default_logger() +{ + static rapids_logger::logger logger_ = [] { + rapids_logger::logger logger_{"CUOPT", {default_sink()}}; +#if CUOPT_LOG_ACTIVE_LEVEL >= RAPIDS_LOGGER_LOG_LEVEL_INFO + logger_.set_pattern("%v"); +#else + logger_.set_pattern(default_pattern()); +#endif + logger_.set_level(default_level()); + logger_.flush_on(rapids_logger::level_enum::debug); + + return logger_; + }(); + + return logger_; +} + +inline void reset_default_logger() +{ + default_logger().sinks().clear(); + default_logger().sinks().push_back(default_sink()); +#if CUOPT_LOG_ACTIVE_LEVEL >= RAPIDS_LOGGER_LOG_LEVEL_INFO + default_logger().set_pattern("%v"); +#else + default_logger().set_pattern(default_pattern()); +#endif + default_logger().set_level(default_level()); + default_logger().flush_on(rapids_logger::level_enum::debug); +} + +/** + * @brief Point this image's logger at the given sinks and flush anything buffered so far. + * + * @param log_file File to log to, or empty for none. + * @param log_to_console Whether to also log to stdout. + * @param truncate Whether opening @p log_file clears it. Pass false when another + * image is already logging to the same path and has truncated it. + */ +inline void apply_logger_config(const std::string& log_file, bool log_to_console, bool truncate) +{ + cuopt::default_logger().sinks().clear(); + + // re-initialize sinks + if (log_to_console) { + cuopt::default_logger().sinks().push_back( + std::make_shared(std::cout)); + } + if (!log_file.empty()) { + // Clear the file up front rather than letting the sink truncate. Several loggers in one + // process can share a path -- the CLI has its own and the solver library has another -- + // and a truncating sink writes from offset 0, silently overwriting whatever the other + // one has already appended. Opening every sink in append mode keeps them interleaving. + if (truncate) { std::ofstream(log_file, std::ios::trunc); } + cuopt::default_logger().sinks().push_back( + std::make_shared(log_file, /*truncate=*/false)); + cuopt::default_logger().flush_on(rapids_logger::level_enum::debug); + } + +#if CUOPT_LOG_ACTIVE_LEVEL >= RAPIDS_LOGGER_LOG_LEVEL_INFO + cuopt::default_logger().set_pattern("%v"); +#else + cuopt::default_logger().set_pattern(cuopt::default_pattern()); +#endif + + // Extract messages from the global buffer and log to the default logger + auto buffered_messages = global_log_buffer().drain_all(); + for (const auto& entry : buffered_messages) { + cuopt::default_logger().log(entry.level, entry.msg.c_str()); + } +} -// Ref-counted logger initializer +/** + * @brief Ref-counted initializer for the logger of the image that constructs it. + * + * Library code uses this directly: constructed inside cuopt_routing it configures routing's + * logger, inside cuopt_mathopt it configures mathopt's. Callers outside the libraries get + * their own logger this way and should use init_component_logger_t to reach a library's. + */ class init_logger_t { // Using shared_ptr for ref-counting std::shared_ptr guard_; public: - init_logger_t(std::string log_file, bool log_to_console); + init_logger_t(std::string log_file, bool log_to_console, bool truncate = true); +}; + +// Guard object whose destructor resets the logger +struct logger_config_guard { + ~logger_config_guard() { cuopt::reset_default_logger(); } +}; + +// Weak reference to detect if any init_logger_t instance is still alive +inline std::weak_ptr g_active_guard; +inline std::mutex g_guard_mutex; + +// Holds this library's configuration alive when it was set from outside, since the external +// caller has no object in this image to own it. +inline std::shared_ptr& external_config_guard() +{ + static std::shared_ptr guard; + return guard; +} + +/** + * @brief Body of a component's exported configure entry point. + * + * Takes the same guard that init_logger_t takes, and keeps it alive. Library code that later + * constructs an init_logger_t of its own -- the MIP and PDLP solve paths both do -- then sees + * a live configuration and reuses it. Without that, the solver would reconfigure the logger + * mid-run and, with truncate set, clear a log file the caller had already written to. + */ +inline void configure_logging_impl(const std::string& log_file, bool log_to_console, bool truncate) +{ + std::lock_guard lock(g_guard_mutex); + + apply_logger_config(log_file, log_to_console, truncate); + + auto guard = std::make_shared(); + g_active_guard = guard; + external_config_guard() = guard; +} + +inline void reset_logging_impl() +{ + std::lock_guard lock(g_guard_mutex); + external_config_guard().reset(); +} + +inline init_logger_t::init_logger_t(std::string log_file, bool log_to_console, bool truncate) +{ + std::lock_guard lock(g_guard_mutex); + + auto existing_guard = g_active_guard.lock(); + if (existing_guard) { + // Reuse existing configuration, just hold a reference to keep it alive + guard_ = existing_guard; + return; + } + + apply_logger_config(log_file, log_to_console, truncate); + + // Create guard and store weak reference for future instances to find + auto guard = std::make_shared(); + g_active_guard = guard; + guard_ = guard; +} + +/** + * @brief Which component library's logger to configure. + */ +enum class log_target_t { + mathopt, ///< LP / MILP / QP, in cuopt_mathopt + routing ///< VRP, in cuopt_routing +}; + +} // namespace cuopt + +/* + * Exported per-component entry points. Each is defined in exactly one component library and + * configures that library's own hidden logger. They are the only logging symbols that cross + * a library boundary. + */ +namespace cuopt::mathematical_optimization { +CUOPT_EXPORT void configure_logging(const std::string& log_file, + bool log_to_console, + bool truncate); +CUOPT_EXPORT void reset_logging(); +} // namespace cuopt::mathematical_optimization + +#ifdef CUOPT_HAS_ROUTING +namespace cuopt::routing { +CUOPT_EXPORT void configure_logging(const std::string& log_file, + bool log_to_console, + bool truncate); +CUOPT_EXPORT void reset_logging(); +} // namespace cuopt::routing +#endif + +namespace cuopt { + +/** + * @brief Configures a component library's logger from outside that library. + * + * `init_logger_t` configures the logger of whichever image constructs it, which is what + * library code wants but not what an external caller wants: the CLI, the tests and the + * Python bindings each hold their own logger and need to reach into the solver's. This + * dispatches to the component's exported entry point instead. + * + * Defaults to mathopt because every external caller today is LP or MILP; routing is opted + * into explicitly. + */ +class init_component_logger_t { + log_target_t target_; + + public: + explicit init_component_logger_t(const std::string& log_file, + bool log_to_console, + log_target_t target = log_target_t::mathopt, + bool truncate = true) + : target_(target) + { + switch (target_) { + case log_target_t::routing: +#ifdef CUOPT_HAS_ROUTING + cuopt::routing::configure_logging(log_file, log_to_console, truncate); +#endif + break; + case log_target_t::mathopt: + default: + cuopt::mathematical_optimization::configure_logging(log_file, log_to_console, truncate); + break; + } + } + + ~init_component_logger_t() + { + switch (target_) { + case log_target_t::routing: +#ifdef CUOPT_HAS_ROUTING + cuopt::routing::reset_logging(); +#endif + break; + case log_target_t::mathopt: + default: cuopt::mathematical_optimization::reset_logging(); break; + } + } + + init_component_logger_t(const init_component_logger_t&) = delete; + init_component_logger_t& operator=(const init_component_logger_t&) = delete; }; -} // namespace CUOPT_EXPORT cuopt +} // namespace cuopt namespace cuopt::detail { diff --git a/cpp/tests/dual_simplex/unit_tests/solve.cpp b/cpp/tests/dual_simplex/unit_tests/solve.cpp index 2e44442599..d502ca9292 100644 --- a/cpp/tests/dual_simplex/unit_tests/solve.cpp +++ b/cpp/tests/dual_simplex/unit_tests/solve.cpp @@ -23,7 +23,7 @@ namespace cuopt::mathematical_optimization::simplex::test { TEST(dual_simplex, chess_set) { - cuopt::init_logger_t log("", true); + cuopt::init_component_logger_t log("", true); namespace simplex = cuopt::mathematical_optimization::simplex; raft::handle_t handle{}; simplex::user_problem_t user_problem(&handle); @@ -97,7 +97,7 @@ TEST(dual_simplex, chess_set) TEST(dual_simplex, burglar) { - cuopt::init_logger_t log("", true); + cuopt::init_component_logger_t log("", true); constexpr int num_items = 8; constexpr double max_weight = 102; @@ -173,7 +173,7 @@ TEST(dual_simplex, burglar) TEST(dual_simplex, empty_columns) { - cuopt::init_logger_t log("", true); + cuopt::init_component_logger_t log("", true); // Same as burglar problem above but with an empty column inserted constexpr int num_items = 9; constexpr double max_weight = 102; @@ -262,7 +262,7 @@ TEST(dual_simplex, empty_columns) TEST(dual_simplex, dual_variable_greater_than) { - cuopt::init_logger_t log("", true); + cuopt::init_component_logger_t log("", true); // minimize 3*x0 + 2 * x1 // subject to x0 + x1 >= 1 // x0 + 2x1 >= 3 diff --git a/cpp/tests/dual_simplex/unit_tests/solve_barrier.cu b/cpp/tests/dual_simplex/unit_tests/solve_barrier.cu index 16640c6c60..9f5963acec 100644 --- a/cpp/tests/dual_simplex/unit_tests/solve_barrier.cu +++ b/cpp/tests/dual_simplex/unit_tests/solve_barrier.cu @@ -41,7 +41,7 @@ static void init_handler(const raft::handle_t* handle_ptr) TEST(barrier, chess_set) { - cuopt::init_logger_t log("", true); + cuopt::init_component_logger_t log("", true); namespace simplex = cuopt::mathematical_optimization::simplex; raft::handle_t handle{}; init_handler(&handle); @@ -111,7 +111,7 @@ TEST(barrier, chess_set) TEST(barrier, dual_variable_greater_than) { - cuopt::init_logger_t log("", true); + cuopt::init_component_logger_t log("", true); // minimize 3*x0 + 2 * x1 // subject to x0 + x1 >= 1 // x0 + 2x1 >= 3 From 9e59d0dbf7b95a63c4372771f524bf137c219e58 Mon Sep 17 00:00:00 2001 From: Ramakrishna Prabhu Date: Mon, 24 Aug 2026 15:44:57 -0500 Subject: [PATCH 02/11] fix(logger): address review on guard order and macro propagation configure_logging_impl released the previous guard *after* applying the new configuration. ~logger_config_guard calls reset_default_logger(), so a second configure ran that reset on top of the sinks it had just installed and silently sent everything back to the buffer. CUOPT_HAS_ROUTING was only on cuopt_objs. $ does not carry INTERFACE properties -- the tree already documents this where it restores CUOPT_LOG_ACTIVE_LEVEL on cuopt and cuopt_static -- and cuopt_cli and the tests link those, not cuopt_objs. log_target_t::routing compiled to a no-op for every external caller. Also: external configuration is now depth-counted, so overlapping init_component_logger_t instances behave like overlapping init_logger_t instances and an inner destructor no longer tears down the outer configuration. Requesting routing when SKIP_ROUTING_BUILD is set now throws instead of silently dropping every message. default_sink's docstring described a stderr/CUOPT_DEBUG_LOG_FILE behaviour it has not had; it returns the buffer callback. LOGGER_TEST covers the boundary, including regressions for the first two bugs above. Co-Authored-By: Claude Opus 5 --- cpp/CMakeLists.txt | 10 ++- cpp/src/utilities/logger.hpp | 35 +++++++- cpp/tests/utilities/CMakeLists.txt | 3 + cpp/tests/utilities/test_logger.cpp | 123 ++++++++++++++++++++++++++++ 4 files changed, 167 insertions(+), 4 deletions(-) create mode 100644 cpp/tests/utilities/test_logger.cpp diff --git a/cpp/CMakeLists.txt b/cpp/CMakeLists.txt index 3d121d7357..ed913d8a72 100644 --- a/cpp/CMakeLists.txt +++ b/cpp/CMakeLists.txt @@ -570,7 +570,9 @@ target_compile_definitions(cuopt_objs ) # Lets callers reach routing's logger through init_component_logger_t. Routing is optional, -# so the entry point it declares is only linkable when routing was actually built. +# so the entry point it declares is only linkable when routing was actually built. This is +# also set on cuopt and cuopt_static: $ does not carry INTERFACE +# properties, and consumers such as cuopt_cli and the tests link those, not cuopt_objs. if(NOT SKIP_ROUTING_BUILD) target_compile_definitions(cuopt_objs PUBLIC CUOPT_HAS_ROUTING) endif() @@ -738,6 +740,9 @@ if (BUILD_TESTS) "CUOPT_LOG_ACTIVE_LEVEL=RAPIDS_LOGGER_LOG_LEVEL_${LIBCUOPT_LOGGING_LEVEL}" CUSPARSE_ENABLE_EXPERIMENTAL_API ) + if(NOT SKIP_ROUTING_BUILD) + target_compile_definitions(cuopt_static PUBLIC CUOPT_HAS_ROUTING) + endif() target_link_libraries(cuopt_static PRIVATE $) add_dependencies(cuopt_static PSLP) target_link_libraries(cuopt_static PRIVATE $) @@ -796,6 +801,9 @@ target_compile_definitions(cuopt "CUOPT_LOG_ACTIVE_LEVEL=RAPIDS_LOGGER_LOG_LEVEL_${LIBCUOPT_LOGGING_LEVEL}" CUSPARSE_ENABLE_EXPERIMENTAL_API ) +if(NOT SKIP_ROUTING_BUILD) + target_compile_definitions(cuopt PUBLIC CUOPT_HAS_ROUTING) +endif() if (WRITE_FATBIN) file(WRITE "${CUOPT_BINARY_DIR}/fatbin.ld" diff --git a/cpp/src/utilities/logger.hpp b/cpp/src/utilities/logger.hpp index bdc9564319..8a8982f07c 100644 --- a/cpp/src/utilities/logger.hpp +++ b/cpp/src/utilities/logger.hpp @@ -19,6 +19,7 @@ #include #include #include +#include #include #include #include @@ -93,10 +94,11 @@ inline void buffer_log_callback(int lvl, const char* msg) } /** - * @brief Returns the default sink for the global logger. + * @brief Returns the default sink, used until something configures the logger. * - * If the environment variable `CUOPT_DEBUG_LOG_FILE` is defined, the default sink is a sink to that - * file. Otherwise, the default is to dump to stderr. + * Messages go into an in-memory buffer rather than to a stream, and are replayed once a + * configuration arrives. Anything logged before that, and never followed by a configure, + * is dropped. * * @return sink_ptr The sink to use */ @@ -240,6 +242,14 @@ inline std::shared_ptr& external_config_guard() return guard; } +// Nesting depth of external configuration, so overlapping callers behave like overlapping +// init_logger_t instances: the outermost configuration wins and only its exit tears down. +inline int& external_config_depth() +{ + static int depth = 0; + return depth; +} + /** * @brief Body of a component's exported configure entry point. * @@ -252,6 +262,15 @@ inline void configure_logging_impl(const std::string& log_file, bool log_to_cons { std::lock_guard lock(g_guard_mutex); + // An inner caller reuses the configuration already in place rather than replacing it, + // matching init_logger_t. Reconfiguring here would also re-truncate the log file. + if (external_config_depth()++ > 0) { return; } + + // Drop the previous guard *before* applying the new sinks. ~logger_config_guard calls + // reset_default_logger(), so releasing it afterwards would run that reset on top of the + // configuration we just applied and silently put the buffer sink back. + external_config_guard().reset(); + apply_logger_config(log_file, log_to_console, truncate); auto guard = std::make_shared(); @@ -262,6 +281,10 @@ inline void configure_logging_impl(const std::string& log_file, bool log_to_cons inline void reset_logging_impl() { std::lock_guard lock(g_guard_mutex); + + if (external_config_depth() == 0) { return; } + if (--external_config_depth() > 0) { return; } + external_config_guard().reset(); } @@ -342,6 +365,12 @@ class init_component_logger_t { case log_target_t::routing: #ifdef CUOPT_HAS_ROUTING cuopt::routing::configure_logging(log_file, log_to_console, truncate); +#else + // Silently doing nothing here would look like a working logger that drops every + // message, and the cause -- a SKIP_ROUTING_BUILD mismatch -- would be invisible. + throw std::runtime_error( + "cuOpt was built with SKIP_ROUTING_BUILD, so routing's logger does not exist and " + "log_target_t::routing cannot be configured."); #endif break; case log_target_t::mathopt: diff --git a/cpp/tests/utilities/CMakeLists.txt b/cpp/tests/utilities/CMakeLists.txt index 8747d47bd0..70979d7172 100644 --- a/cpp/tests/utilities/CMakeLists.txt +++ b/cpp/tests/utilities/CMakeLists.txt @@ -5,3 +5,6 @@ # Add CLI end-to-end test ConfigureTest(CLI_TEST test_cli.cpp LABELS numopt) + +# Logger boundary: per-library instances, shared log file, truncate semantics +ConfigureTest(LOGGER_TEST test_logger.cpp LABELS numopt) diff --git a/cpp/tests/utilities/test_logger.cpp b/cpp/tests/utilities/test_logger.cpp new file mode 100644 index 0000000000..4a24ef907f --- /dev/null +++ b/cpp/tests/utilities/test_logger.cpp @@ -0,0 +1,123 @@ +/* clang-format off */ +/* + * SPDX-FileCopyrightText: Copyright (c) 2026, NVIDIA CORPORATION & AFFILIATES. All rights reserved. + * SPDX-License-Identifier: Apache-2.0 + */ +/* clang-format on */ + +#include + +#include + +#include +#include +#include +#include + +/* + * These run in the test executable, which links cuopt but has its own hidden logger, so they + * exercise the same boundary an external caller crosses: init_component_logger_t configures a + * logger inside the solver library, init_logger_t configures the one in this image. + */ +namespace cuopt::test { + +namespace { + +std::string temp_log_path(const std::string& tag) +{ + return std::string{std::tmpnam(nullptr)} + "." + tag + ".log"; +} + +std::string read_file(const std::string& path) +{ + std::ifstream in{path}; + std::ostringstream out; + out << in.rdbuf(); + return out.str(); +} + +} // namespace + +// A second configure must not leave the logger reset back to the buffer sink. Releasing the +// previous guard after applying the new config ran ~logger_config_guard on top of it, which +// silently swallowed everything logged afterwards. +TEST(logger, reconfigure_does_not_reset_to_buffer) +{ + const auto first = temp_log_path("first"); + const auto second = temp_log_path("second"); + + { + cuopt::init_component_logger_t outer{first, false}; + cuopt::mathematical_optimization::configure_logging(second, false, true); + + CUOPT_LOG_ERROR("after_reconfigure"); + } + + // The message must have reached a file rather than vanishing into the buffer sink. + EXPECT_NE(read_file(first) + read_file(second), "") << "log message was swallowed"; + + std::remove(first.c_str()); + std::remove(second.c_str()); +} + +// Overlapping configurations behave like overlapping init_logger_t instances: the inner one +// reuses the outer configuration and its destructor must not tear it down early. +TEST(logger, nested_component_loggers_keep_outer_config) +{ + const auto path = temp_log_path("nested"); + + { + cuopt::init_component_logger_t outer{path, false}; + { + cuopt::init_component_logger_t inner{path, false}; + } + // inner is gone; outer is still alive, so the library must still be logging to the file. + CUOPT_LOG_ERROR("after_inner_destroyed"); + } + + EXPECT_NE(read_file(path), "") << "inner destructor tore down the outer configuration"; + std::remove(path.c_str()); +} + +// Two loggers on one path: the library's, configured from here, and this image's own. A +// truncating sink writes from offset 0 and would overwrite what the other appended. +TEST(logger, two_images_share_one_file_without_clobbering) +{ + const auto path = temp_log_path("shared"); + + { + cuopt::init_component_logger_t solver_log{path, false}; + cuopt::init_logger_t own_log{path, false, /*truncate=*/false}; + + CUOPT_LOG_ERROR("from_this_image"); + } + + const auto contents = read_file(path); + EXPECT_NE(contents.find("from_this_image"), std::string::npos) + << "this image's message was overwritten by the library's sink"; + + std::remove(path.c_str()); +} + +// truncate=true on the outermost configure clears the file, so repeated runs do not append +// to each other. +TEST(logger, truncate_clears_previous_contents) +{ + const auto path = temp_log_path("truncate"); + { + std::ofstream seed{path}; + seed << "STALE_CONTENT_FROM_PREVIOUS_RUN\n"; + } + + { + cuopt::init_component_logger_t solver_log{path, false}; + CUOPT_LOG_ERROR("fresh"); + } + + EXPECT_EQ(read_file(path).find("STALE_CONTENT_FROM_PREVIOUS_RUN"), std::string::npos) + << "log file was not truncated"; + + std::remove(path.c_str()); +} + +} // namespace cuopt::test From 0d575bc543347218e4d3fe65a1e6a4ca3848da99 Mon Sep 17 00:00:00 2001 From: Ramakrishna Prabhu Date: Wed, 26 Aug 2026 15:42:52 -0500 Subject: [PATCH 03/11] fix(logger): correct static destruction order and rewrite the tests external_config_guard()'s static could be constructed before default_logger()'s, so at process exit the guard was destroyed after the logger and ~logger_config_guard called reset_default_logger() on a destroyed object. That aborted with "malloc_consolidate(): unaligned fastbin chunk detected" in any process that configured logging through the exported entry point without unwinding it first. Touch the logger inside external_config_guard() so its static is constructed first, and therefore destroyed last. The tests were also wrong. init_component_logger_t configures the logger inside libcuopt, but CUOPT_LOG_* in the test TU reaches the test binary's own hidden logger, so they configured one logger and asserted on another. They now drive configure_logging_impl in the image that does the logging, and check the component entry point through the one thing observable from outside it: its effect on a shared file. Co-Authored-By: Claude Opus 5 --- cpp/src/utilities/logger.hpp | 6 ++ cpp/tests/utilities/test_logger.cpp | 127 ++++++++++++++++++++-------- 2 files changed, 96 insertions(+), 37 deletions(-) diff --git a/cpp/src/utilities/logger.hpp b/cpp/src/utilities/logger.hpp index 8a8982f07c..42b72c156b 100644 --- a/cpp/src/utilities/logger.hpp +++ b/cpp/src/utilities/logger.hpp @@ -238,6 +238,12 @@ inline std::mutex g_guard_mutex; // caller has no object in this image to own it. inline std::shared_ptr& external_config_guard() { + // Force the logger's static to be constructed before this one, so it is destroyed after. + // ~logger_config_guard calls reset_default_logger(), and at process exit an unpaired + // guard released after the logger had already gone would touch a destroyed object. + static rapids_logger::logger& keep_logger_alive = default_logger(); + static_cast(keep_logger_alive); + static std::shared_ptr guard; return guard; } diff --git a/cpp/tests/utilities/test_logger.cpp b/cpp/tests/utilities/test_logger.cpp index 4a24ef907f..58a7b33638 100644 --- a/cpp/tests/utilities/test_logger.cpp +++ b/cpp/tests/utilities/test_logger.cpp @@ -15,17 +15,32 @@ #include /* - * These run in the test executable, which links cuopt but has its own hidden logger, so they - * exercise the same boundary an external caller crosses: init_component_logger_t configures a - * logger inside the solver library, init_logger_t configures the one in this image. + * The logger is hidden, so this test executable has its own instance, separate from the one + * inside libcuopt. That means CUOPT_LOG_* here reaches *this* image's logger, and only the + * entry points that operate on this image can be observed from here: + * + * - init_logger_t and configure_logging_impl configure this image's logger, so their + * behaviour is testable directly. They are the code the exported per-component + * configure_logging entry points run, just reached without crossing a library boundary. + * - init_component_logger_t reaches into libcuopt's logger, which only emits during a + * solve. Its effect on a shared file is observable here; its messages are not. + * + * The separation itself is checked outside this test: libcuopt exports configure_logging and + * reset_logging and none of the logger state. */ namespace cuopt::test { namespace { +int unique_id() +{ + static int counter = 0; + return counter++; +} + std::string temp_log_path(const std::string& tag) { - return std::string{std::tmpnam(nullptr)} + "." + tag + ".log"; + return "cuopt_logger_test_" + tag + "_" + std::to_string(unique_id()) + ".log"; } std::string read_file(const std::string& path) @@ -36,87 +51,125 @@ std::string read_file(const std::string& path) return out.str(); } +// Every test must leave the depth counter at zero, or the next one's configure is treated as +// nested and silently skipped. +struct scoped_config { + explicit scoped_config(const std::string& path, bool truncate = true) + { + cuopt::configure_logging_impl(path, false, truncate); + } + ~scoped_config() { cuopt::reset_logging_impl(); } +}; + } // namespace -// A second configure must not leave the logger reset back to the buffer sink. Releasing the -// previous guard after applying the new config ran ~logger_config_guard on top of it, which -// silently swallowed everything logged afterwards. +// Releasing the previous guard after applying the new configuration ran +// ~logger_config_guard -- and so reset_default_logger() -- on top of the sinks just +// installed, sending everything back to the buffer sink. TEST(logger, reconfigure_does_not_reset_to_buffer) { const auto first = temp_log_path("first"); const auto second = temp_log_path("second"); { - cuopt::init_component_logger_t outer{first, false}; - cuopt::mathematical_optimization::configure_logging(second, false, true); - + scoped_config initial{first}; + CUOPT_LOG_ERROR("before_reconfigure"); + } + { + scoped_config replacement{second}; CUOPT_LOG_ERROR("after_reconfigure"); } - // The message must have reached a file rather than vanishing into the buffer sink. - EXPECT_NE(read_file(first) + read_file(second), "") << "log message was swallowed"; + EXPECT_NE(read_file(first).find("before_reconfigure"), std::string::npos); + EXPECT_NE(read_file(second).find("after_reconfigure"), std::string::npos) + << "the second configuration left the logger reset to the buffer sink"; std::remove(first.c_str()); std::remove(second.c_str()); } // Overlapping configurations behave like overlapping init_logger_t instances: the inner one -// reuses the outer configuration and its destructor must not tear it down early. -TEST(logger, nested_component_loggers_keep_outer_config) +// reuses the outer configuration, and its exit must not tear that configuration down. +TEST(logger, nested_config_survives_inner_exit) { const auto path = temp_log_path("nested"); { - cuopt::init_component_logger_t outer{path, false}; + scoped_config outer{path}; { - cuopt::init_component_logger_t inner{path, false}; + scoped_config inner{path}; } - // inner is gone; outer is still alive, so the library must still be logging to the file. - CUOPT_LOG_ERROR("after_inner_destroyed"); + CUOPT_LOG_ERROR("after_inner_exit"); } - EXPECT_NE(read_file(path), "") << "inner destructor tore down the outer configuration"; + EXPECT_NE(read_file(path).find("after_inner_exit"), std::string::npos) + << "inner exit tore down the outer configuration"; + std::remove(path.c_str()); } -// Two loggers on one path: the library's, configured from here, and this image's own. A -// truncating sink writes from offset 0 and would overwrite what the other appended. -TEST(logger, two_images_share_one_file_without_clobbering) +// truncate clears the file up front instead of letting the sink open in truncating mode, so +// a second logger appending to the same path is not overwritten from offset 0. +TEST(logger, truncate_clears_previous_contents) { - const auto path = temp_log_path("shared"); + const auto path = temp_log_path("truncate"); + { + std::ofstream seed{path}; + seed << "STALE_CONTENT_FROM_PREVIOUS_RUN\n"; + } { - cuopt::init_component_logger_t solver_log{path, false}; - cuopt::init_logger_t own_log{path, false, /*truncate=*/false}; + scoped_config cfg{path}; + CUOPT_LOG_ERROR("fresh"); + } - CUOPT_LOG_ERROR("from_this_image"); + const auto contents = read_file(path); + EXPECT_EQ(contents.find("STALE_CONTENT_FROM_PREVIOUS_RUN"), std::string::npos) + << "log file was not truncated"; + EXPECT_NE(contents.find("fresh"), std::string::npos); + + std::remove(path.c_str()); +} + +// truncate=false leaves what is already there, which is how a second logger on the same path +// avoids clobbering the first. +TEST(logger, append_preserves_existing_contents) +{ + const auto path = temp_log_path("append"); + { + std::ofstream seed{path}; + seed << "WRITTEN_BY_ANOTHER_LOGGER\n"; + } + + { + scoped_config cfg{path, /*truncate=*/false}; + CUOPT_LOG_ERROR("appended"); } const auto contents = read_file(path); - EXPECT_NE(contents.find("from_this_image"), std::string::npos) - << "this image's message was overwritten by the library's sink"; + EXPECT_NE(contents.find("WRITTEN_BY_ANOTHER_LOGGER"), std::string::npos) + << "appending logger overwrote the other logger's output"; + EXPECT_NE(contents.find("appended"), std::string::npos); std::remove(path.c_str()); } -// truncate=true on the outermost configure clears the file, so repeated runs do not append -// to each other. -TEST(logger, truncate_clears_previous_contents) +// The library's logger is reachable only through the exported entry point. Its messages are +// not observable here, but configuring it must clear the shared file exactly once. +TEST(logger, component_logger_truncates_shared_file) { - const auto path = temp_log_path("truncate"); + const auto path = temp_log_path("component"); { std::ofstream seed{path}; - seed << "STALE_CONTENT_FROM_PREVIOUS_RUN\n"; + seed << "STALE\n"; } { cuopt::init_component_logger_t solver_log{path, false}; - CUOPT_LOG_ERROR("fresh"); + EXPECT_EQ(read_file(path).find("STALE"), std::string::npos) + << "component configure did not clear the file"; } - EXPECT_EQ(read_file(path).find("STALE_CONTENT_FROM_PREVIOUS_RUN"), std::string::npos) - << "log file was not truncated"; - std::remove(path.c_str()); } From ad82df105555cb4ded2903e3cf17d03d1824dd37 Mon Sep 17 00:00:00 2001 From: Ramakrishna Prabhu Date: Wed, 26 Aug 2026 16:33:43 -0500 Subject: [PATCH 04/11] fix(logger): keep the depth counter balanced when configure throws apply_logger_config can throw -- basic_file_sink_mt does when the log file cannot be opened -- and the depth counter had already been incremented by then. The throw propagates out of init_component_logger_t's constructor, so its destructor never runs to balance it, leaving the depth stuck above zero. Every later configure then looks nested and silently does nothing, so one unwritable log file kills logging for the rest of the process. Restore the counter and reset the logger before rethrowing. Found by CodeRabbit on #1778. Co-Authored-By: Claude Opus 5 --- cpp/src/utilities/logger.hpp | 12 +++++++++++- cpp/tests/utilities/test_logger.cpp | 20 ++++++++++++++++++++ 2 files changed, 31 insertions(+), 1 deletion(-) diff --git a/cpp/src/utilities/logger.hpp b/cpp/src/utilities/logger.hpp index 42b72c156b..7ab493ec4b 100644 --- a/cpp/src/utilities/logger.hpp +++ b/cpp/src/utilities/logger.hpp @@ -277,7 +277,17 @@ inline void configure_logging_impl(const std::string& log_file, bool log_to_cons // configuration we just applied and silently put the buffer sink back. external_config_guard().reset(); - apply_logger_config(log_file, log_to_console, truncate); + try { + apply_logger_config(log_file, log_to_console, truncate); + } catch (...) { + // Put the depth back. The caller's constructor is the one throwing, so its destructor + // never runs to balance the increment, and a depth stuck above zero would make every + // later configure look nested and silently do nothing -- logging dead for the process + // because one log file could not be opened. + --external_config_depth(); + reset_default_logger(); + throw; + } auto guard = std::make_shared(); g_active_guard = guard; diff --git a/cpp/tests/utilities/test_logger.cpp b/cpp/tests/utilities/test_logger.cpp index 58a7b33638..398855e5f9 100644 --- a/cpp/tests/utilities/test_logger.cpp +++ b/cpp/tests/utilities/test_logger.cpp @@ -154,6 +154,26 @@ TEST(logger, append_preserves_existing_contents) std::remove(path.c_str()); } +// A configure that throws must leave the depth counter as it found it. The caller's +// constructor is the one throwing, so its destructor never runs to balance the increment, +// and a stuck depth would make every later configure look nested and silently do nothing. +TEST(logger, failed_configure_does_not_wedge_later_ones) +{ + const auto unopenable = "/nonexistent-directory-" + std::to_string(unique_id()) + "/x.log"; + EXPECT_ANY_THROW(cuopt::configure_logging_impl(unopenable, false, true)); + + const auto path = temp_log_path("recovered"); + { + scoped_config cfg{path}; + CUOPT_LOG_ERROR("after_failed_configure"); + } + + EXPECT_NE(read_file(path).find("after_failed_configure"), std::string::npos) + << "a failed configure left the logger wedged"; + + std::remove(path.c_str()); +} + // The library's logger is reachable only through the exported entry point. Its messages are // not observable here, but configuring it must clear the shared file exactly once. TEST(logger, component_logger_truncates_shared_file) From 72cdfc34789333c12b7aaa259fefe9d7712a7d5c Mon Sep 17 00:00:00 2001 From: Ramakrishna Prabhu Date: Wed, 26 Aug 2026 16:48:21 -0500 Subject: [PATCH 05/11] refactor(logger): make log_buffer's state private messages and mutex were public, so a caller could mutate the buffer without holding the lock the class otherwise takes on every access. Nothing outside the class touched them. Found by CodeRabbit on #1778. Co-Authored-By: Claude Opus 5 --- cpp/src/utilities/logger.hpp | 1 + 1 file changed, 1 insertion(+) diff --git a/cpp/src/utilities/logger.hpp b/cpp/src/utilities/logger.hpp index 7ab493ec4b..ceaffde01d 100644 --- a/cpp/src/utilities/logger.hpp +++ b/cpp/src/utilities/logger.hpp @@ -76,6 +76,7 @@ class log_buffer { return out; } + private: std::vector messages; mutable std::mutex mutex; }; From 3f042f8d4efe0cbd637ffbe756e59f8c0fe8687a Mon Sep 17 00:00:00 2001 From: Ramakrishna Prabhu Date: Thu, 27 Aug 2026 11:44:05 -0500 Subject: [PATCH 06/11] fix(logger): restore a sink when init_logger_t fails to configure apply_logger_config clears the sinks before installing the new ones, so a throw part way through -- basic_file_sink_mt does when the log file cannot be opened -- left the logger with no sinks at all and silently dropped every later message. configure_logging_impl already handled this; init_logger_t did not. Found by CodeRabbit on #1778. Co-Authored-By: Claude Opus 5 --- cpp/src/utilities/logger.hpp | 10 +++++++++- cpp/tests/utilities/test_logger.cpp | 19 +++++++++++++++++++ 2 files changed, 28 insertions(+), 1 deletion(-) diff --git a/cpp/src/utilities/logger.hpp b/cpp/src/utilities/logger.hpp index ceaffde01d..69f1a8c0e3 100644 --- a/cpp/src/utilities/logger.hpp +++ b/cpp/src/utilities/logger.hpp @@ -316,7 +316,15 @@ inline init_logger_t::init_logger_t(std::string log_file, bool log_to_console, b return; } - apply_logger_config(log_file, log_to_console, truncate); + try { + apply_logger_config(log_file, log_to_console, truncate); + } catch (...) { + // apply_logger_config clears the sinks before installing the new ones, so a throw part + // way through leaves the logger with none at all and every later message is silently + // dropped. Put the default sink back before rethrowing. + reset_default_logger(); + throw; + } // Create guard and store weak reference for future instances to find auto guard = std::make_shared(); diff --git a/cpp/tests/utilities/test_logger.cpp b/cpp/tests/utilities/test_logger.cpp index 398855e5f9..fca32c4388 100644 --- a/cpp/tests/utilities/test_logger.cpp +++ b/cpp/tests/utilities/test_logger.cpp @@ -174,6 +174,25 @@ TEST(logger, failed_configure_does_not_wedge_later_ones) std::remove(path.c_str()); } +// Same failure for the image-local entry point: apply_logger_config clears the sinks before +// installing new ones, so a throw part way through must not leave the logger with none. +TEST(logger, failed_init_logger_restores_a_sink) +{ + const auto unopenable = "/nonexistent-directory-" + std::to_string(unique_id()) + "/x.log"; + EXPECT_ANY_THROW(cuopt::init_logger_t(unopenable, false, true)); + + const auto path = temp_log_path("init_recovered"); + { + scoped_config cfg{path}; + CUOPT_LOG_ERROR("after_failed_init"); + } + + EXPECT_NE(read_file(path).find("after_failed_init"), std::string::npos) + << "a failed init_logger_t left the logger without sinks"; + + std::remove(path.c_str()); +} + // The library's logger is reachable only through the exported entry point. Its messages are // not observable here, but configuring it must clear the shared file exactly once. TEST(logger, component_logger_truncates_shared_file) From 1914d3743b0bb039bb5b6a36564c421d5b2a0c62 Mon Sep 17 00:00:00 2001 From: Ramakrishna Prabhu Date: Thu, 27 Aug 2026 12:29:06 -0500 Subject: [PATCH 07/11] refactor(logger): one lifetime mechanism, and make the visibility guarantee testable Reviewing this myself, every bug found across four review rounds landed in the same place: the machinery tracking when a configuration is live. There were three overlapping mechanisms for one concept -- a shared_ptr guard for init_logger_t, a separate int depth counter for the external path, and a static shared_ptr holding the external configuration alive. Collapse them into one. configure_logging now returns the same handle init_logger_t holds, so a caller inside the library and one outside share a single refcount: whoever asks first configures, later callers get a handle to the same configuration, and the logger resets when the last one is dropped. That removes the root cause of three earlier findings rather than patching them. The depth counter is gone, so it cannot leak or go unbalanced when a configure throws. The static that held the external configuration is gone, so it can no longer outlive default_logger() and reset a destroyed object -- the ordering workaround goes with it. And reset_logging is gone from the exported surface, which is now just the two configure_logging entry points. The other problem was that nothing enforced the guarantee this design rests on. If the logger's state ever becomes visible, the per-component instances silently merge back into one through STB_GNU_UNIQUE, with no build error and no failing test, and a comment was the only thing saying not to. ci/check_symbols.sh now asserts that state is absent from the dynamic symbol table, so the regression is loud. Verified it fails when given a symbol that is exported. Co-Authored-By: Claude Opus 5 --- ci/check_symbols.sh | 24 ++++ cpp/src/math_optimization/logger_entry.cpp | 8 +- cpp/src/routing/logger_entry.cpp | 8 +- cpp/src/utilities/logger.hpp | 137 +++++---------------- cpp/tests/utilities/test_logger.cpp | 29 ++--- 5 files changed, 79 insertions(+), 127 deletions(-) diff --git a/ci/check_symbols.sh b/ci/check_symbols.sh index 6185092d78..ba5b9c015c 100755 --- a/ci/check_symbols.sh +++ b/ci/check_symbols.sh @@ -100,6 +100,30 @@ for sym in "${required_symbols[@]}"; do fi done +# The logger keeps one instance per component library, which only works while its state stays +# hidden. Nothing fails to build or test if that state becomes visible -- the instances just +# silently merge back into one via STB_GNU_UNIQUE, which glibc unifies process-wide even under +# RTLD_LOCAL. Assert the state is absent from the dynamic symbol table so that regression is +# loud. Only the per-component configure_logging entry points may cross the boundary. +logger_state_symbols=( + "cuopt::default_logger()" + "cuopt::global_log_buffer()" + "cuopt::reset_default_logger()" +) + +demangled_dyn_syms="$(readelf --dyn-syms --wide "${LIBRARY}" | awk '$7 != "UND" { print $8 }' | c++filt)" + +for sym in "${logger_state_symbols[@]}"; do + echo "Checking that logger state '${sym}' is NOT exported..." + if grep -qF "${sym}" <<< "${demangled_dyn_syms}"; then + echo "ERROR: Logger state '${sym}' is exported from ${LIBRARY}." + echo "ERROR: Per-component loggers silently collapse into one shared instance when this" + echo "ERROR: state is visible. Check that cpp/src/utilities/logger.hpp's namespace is not" + echo "ERROR: marked CUOPT_EXPORT and that hidden visibility is still set on the target." + failed=1 + fi +done + if [[ "${failed}" -ne 0 ]]; then exit 1 fi diff --git a/cpp/src/math_optimization/logger_entry.cpp b/cpp/src/math_optimization/logger_entry.cpp index b1ed0907a7..f083e35d9e 100644 --- a/cpp/src/math_optimization/logger_entry.cpp +++ b/cpp/src/math_optimization/logger_entry.cpp @@ -14,11 +14,11 @@ */ namespace cuopt::mathematical_optimization { -void configure_logging(const std::string& log_file, bool log_to_console, bool truncate) +std::shared_ptr configure_logging(const std::string& log_file, + bool log_to_console, + bool truncate) { - cuopt::configure_logging_impl(log_file, log_to_console, truncate); + return cuopt::make_logger_config(log_file, log_to_console, truncate); } -void reset_logging() { cuopt::reset_logging_impl(); } - } // namespace cuopt::mathematical_optimization diff --git a/cpp/src/routing/logger_entry.cpp b/cpp/src/routing/logger_entry.cpp index b284623e1f..665166d594 100644 --- a/cpp/src/routing/logger_entry.cpp +++ b/cpp/src/routing/logger_entry.cpp @@ -14,11 +14,11 @@ */ namespace cuopt::routing { -void configure_logging(const std::string& log_file, bool log_to_console, bool truncate) +std::shared_ptr configure_logging(const std::string& log_file, + bool log_to_console, + bool truncate) { - cuopt::configure_logging_impl(log_file, log_to_console, truncate); + return cuopt::make_logger_config(log_file, log_to_console, truncate); } -void reset_logging() { cuopt::reset_logging_impl(); } - } // namespace cuopt::routing diff --git a/cpp/src/utilities/logger.hpp b/cpp/src/utilities/logger.hpp index 69f1a8c0e3..e2d242ae9f 100644 --- a/cpp/src/utilities/logger.hpp +++ b/cpp/src/utilities/logger.hpp @@ -235,101 +235,44 @@ struct logger_config_guard { inline std::weak_ptr g_active_guard; inline std::mutex g_guard_mutex; -// Holds this library's configuration alive when it was set from outside, since the external -// caller has no object in this image to own it. -inline std::shared_ptr& external_config_guard() -{ - // Force the logger's static to be constructed before this one, so it is destroyed after. - // ~logger_config_guard calls reset_default_logger(), and at process exit an unpaired - // guard released after the logger had already gone would touch a destroyed object. - static rapids_logger::logger& keep_logger_alive = default_logger(); - static_cast(keep_logger_alive); - - static std::shared_ptr guard; - return guard; -} - -// Nesting depth of external configuration, so overlapping callers behave like overlapping -// init_logger_t instances: the outermost configuration wins and only its exit tears down. -inline int& external_config_depth() -{ - static int depth = 0; - return depth; -} - /** - * @brief Body of a component's exported configure entry point. + * @brief Apply a configuration and return a handle that keeps it alive. * - * Takes the same guard that init_logger_t takes, and keeps it alive. Library code that later - * constructs an init_logger_t of its own -- the MIP and PDLP solve paths both do -- then sees - * a live configuration and reuses it. Without that, the solver would reconfigure the logger - * mid-run and, with truncate set, clear a log file the caller had already written to. + * This is the single lifetime mechanism for the logger of this image. Both init_logger_t and + * the exported per-component configure_logging go through it, so a caller inside the library + * and a caller outside it share one refcount: whoever asks first configures, later callers + * get a handle to the same configuration, and the logger is reset when the last handle is + * dropped. That is what stops the solver reconfiguring mid-run and re-truncating a log file + * the caller had already written to. */ -inline void configure_logging_impl(const std::string& log_file, bool log_to_console, bool truncate) +inline std::shared_ptr make_logger_config(const std::string& log_file, + bool log_to_console, + bool truncate) { std::lock_guard lock(g_guard_mutex); - // An inner caller reuses the configuration already in place rather than replacing it, - // matching init_logger_t. Reconfiguring here would also re-truncate the log file. - if (external_config_depth()++ > 0) { return; } - - // Drop the previous guard *before* applying the new sinks. ~logger_config_guard calls - // reset_default_logger(), so releasing it afterwards would run that reset on top of the - // configuration we just applied and silently put the buffer sink back. - external_config_guard().reset(); + // Reuse the configuration already in place rather than replacing it. Reconfiguring here + // would also re-truncate the log file. + if (auto existing = g_active_guard.lock()) { return existing; } try { apply_logger_config(log_file, log_to_console, truncate); } catch (...) { - // Put the depth back. The caller's constructor is the one throwing, so its destructor - // never runs to balance the increment, and a depth stuck above zero would make every - // later configure look nested and silently do nothing -- logging dead for the process - // because one log file could not be opened. - --external_config_depth(); + // apply_logger_config clears the sinks before installing the new ones, so a throw part + // way through would otherwise leave the logger with none at all and silently drop every + // later message. reset_default_logger(); throw; } - auto guard = std::make_shared(); - g_active_guard = guard; - external_config_guard() = guard; -} - -inline void reset_logging_impl() -{ - std::lock_guard lock(g_guard_mutex); - - if (external_config_depth() == 0) { return; } - if (--external_config_depth() > 0) { return; } - - external_config_guard().reset(); + auto guard = std::make_shared(); + g_active_guard = guard; + return guard; } inline init_logger_t::init_logger_t(std::string log_file, bool log_to_console, bool truncate) + : guard_(make_logger_config(log_file, log_to_console, truncate)) { - std::lock_guard lock(g_guard_mutex); - - auto existing_guard = g_active_guard.lock(); - if (existing_guard) { - // Reuse existing configuration, just hold a reference to keep it alive - guard_ = existing_guard; - return; - } - - try { - apply_logger_config(log_file, log_to_console, truncate); - } catch (...) { - // apply_logger_config clears the sinks before installing the new ones, so a throw part - // way through leaves the logger with none at all and every later message is silently - // dropped. Put the default sink back before rethrowing. - reset_default_logger(); - throw; - } - - // Create guard and store weak reference for future instances to find - auto guard = std::make_shared(); - g_active_guard = guard; - guard_ = guard; } /** @@ -348,18 +291,16 @@ enum class log_target_t { * a library boundary. */ namespace cuopt::mathematical_optimization { -CUOPT_EXPORT void configure_logging(const std::string& log_file, - bool log_to_console, - bool truncate); -CUOPT_EXPORT void reset_logging(); +CUOPT_EXPORT std::shared_ptr configure_logging(const std::string& log_file, + bool log_to_console, + bool truncate); } // namespace cuopt::mathematical_optimization #ifdef CUOPT_HAS_ROUTING namespace cuopt::routing { -CUOPT_EXPORT void configure_logging(const std::string& log_file, - bool log_to_console, - bool truncate); -CUOPT_EXPORT void reset_logging(); +CUOPT_EXPORT std::shared_ptr configure_logging(const std::string& log_file, + bool log_to_console, + bool truncate); } // namespace cuopt::routing #endif @@ -377,19 +318,21 @@ namespace cuopt { * into explicitly. */ class init_component_logger_t { - log_target_t target_; + // The handle keeps the component's configuration alive; dropping it resets that + // component's logger. Same refcount init_logger_t uses, so a caller here and library code + // inside the component cannot tear down each other's configuration. + std::shared_ptr handle_; public: explicit init_component_logger_t(const std::string& log_file, bool log_to_console, log_target_t target = log_target_t::mathopt, bool truncate = true) - : target_(target) { - switch (target_) { + switch (target) { case log_target_t::routing: #ifdef CUOPT_HAS_ROUTING - cuopt::routing::configure_logging(log_file, log_to_console, truncate); + handle_ = cuopt::routing::configure_logging(log_file, log_to_console, truncate); #else // Silently doing nothing here would look like a working logger that drops every // message, and the cause -- a SKIP_ROUTING_BUILD mismatch -- would be invisible. @@ -400,21 +343,9 @@ class init_component_logger_t { break; case log_target_t::mathopt: default: - cuopt::mathematical_optimization::configure_logging(log_file, log_to_console, truncate); - break; - } - } - - ~init_component_logger_t() - { - switch (target_) { - case log_target_t::routing: -#ifdef CUOPT_HAS_ROUTING - cuopt::routing::reset_logging(); -#endif + handle_ = + cuopt::mathematical_optimization::configure_logging(log_file, log_to_console, truncate); break; - case log_target_t::mathopt: - default: cuopt::mathematical_optimization::reset_logging(); break; } } diff --git a/cpp/tests/utilities/test_logger.cpp b/cpp/tests/utilities/test_logger.cpp index fca32c4388..20f8d57147 100644 --- a/cpp/tests/utilities/test_logger.cpp +++ b/cpp/tests/utilities/test_logger.cpp @@ -11,6 +11,7 @@ #include #include +#include #include #include @@ -19,14 +20,14 @@ * inside libcuopt. That means CUOPT_LOG_* here reaches *this* image's logger, and only the * entry points that operate on this image can be observed from here: * - * - init_logger_t and configure_logging_impl configure this image's logger, so their - * behaviour is testable directly. They are the code the exported per-component - * configure_logging entry points run, just reached without crossing a library boundary. + * - init_logger_t and make_logger_config configure this image's logger, so their behaviour + * is testable directly. They are the code the exported per-component configure_logging + * entry points run, just reached without crossing a library boundary. * - init_component_logger_t reaches into libcuopt's logger, which only emits during a * solve. Its effect on a shared file is observable here; its messages are not. * - * The separation itself is checked outside this test: libcuopt exports configure_logging and - * reset_logging and none of the logger state. + * The separation itself is checked outside this test, by ci/check_symbols.sh: libcuopt must + * export the component configure_logging entry points and none of the logger state. */ namespace cuopt::test { @@ -51,21 +52,19 @@ std::string read_file(const std::string& path) return out.str(); } -// Every test must leave the depth counter at zero, or the next one's configure is treated as -// nested and silently skipped. +// Holding the handle keeps the configuration alive; dropping it resets the logger. struct scoped_config { explicit scoped_config(const std::string& path, bool truncate = true) + : handle(cuopt::make_logger_config(path, false, truncate)) { - cuopt::configure_logging_impl(path, false, truncate); } - ~scoped_config() { cuopt::reset_logging_impl(); } + std::shared_ptr handle; }; } // namespace -// Releasing the previous guard after applying the new configuration ran -// ~logger_config_guard -- and so reset_default_logger() -- on top of the sinks just -// installed, sending everything back to the buffer sink. +// A second configuration, after the first has been released, must actually take effect and +// not leave the logger reset to the buffer sink. TEST(logger, reconfigure_does_not_reset_to_buffer) { const auto first = temp_log_path("first"); @@ -154,13 +153,11 @@ TEST(logger, append_preserves_existing_contents) std::remove(path.c_str()); } -// A configure that throws must leave the depth counter as it found it. The caller's -// constructor is the one throwing, so its destructor never runs to balance the increment, -// and a stuck depth would make every later configure look nested and silently do nothing. +// A configure that throws must not leave the logger wedged for later callers. TEST(logger, failed_configure_does_not_wedge_later_ones) { const auto unopenable = "/nonexistent-directory-" + std::to_string(unique_id()) + "/x.log"; - EXPECT_ANY_THROW(cuopt::configure_logging_impl(unopenable, false, true)); + EXPECT_ANY_THROW(cuopt::make_logger_config(unopenable, false, true)); const auto path = temp_log_path("recovered"); { From e031c6b63baa41af2d0e863749abaa45fa22c568 Mon Sep 17 00:00:00 2001 From: Ramakrishna Prabhu Date: Thu, 27 Aug 2026 13:35:37 -0500 Subject: [PATCH 08/11] fix(logger): do not let a stale guard reset a newer configuration A guard's refcount reaching zero expires g_active_guard before its destructor runs, so another thread can see no live configuration, apply its own and install a new guard inside that window. The old destructor then reset the logger unconditionally and wiped the configuration that thread had just installed. It also mutated the sink vector without the mutex, racing apply_logger_config. The guard now records the generation it configured and resets only if that generation is still current, holding g_guard_mutex while it checks. Sink mutation on the configure and reset paths is now consistently under that mutex. The accompanying test does not demonstrate the race: entering the window needs the refcount to hit zero exactly while another thread is inside make_logger_config, and under contention g_active_guard.lock() nearly always succeeds instead, so disabling the generation check does not make it fail. It is kept and labelled as a concurrency smoke test rather than a regression test, since it does cover concurrent use of a shared path. Found by CodeRabbit on #1778. Co-Authored-By: Claude Opus 5 --- cpp/src/utilities/logger.hpp | 35 ++++++++++++++++++++++++---- cpp/tests/utilities/test_logger.cpp | 36 +++++++++++++++++++++++++++++ 2 files changed, 67 insertions(+), 4 deletions(-) diff --git a/cpp/src/utilities/logger.hpp b/cpp/src/utilities/logger.hpp index e2d242ae9f..a72481e3ef 100644 --- a/cpp/src/utilities/logger.hpp +++ b/cpp/src/utilities/logger.hpp @@ -226,14 +226,41 @@ class init_logger_t { init_logger_t(std::string log_file, bool log_to_console, bool truncate = true); }; -// Guard object whose destructor resets the logger +inline std::mutex g_guard_mutex; + +// Bumped for every configuration applied. A guard resets the logger only if its own +// configuration is still the current one. +inline uint64_t& active_config_generation() +{ + static uint64_t generation = 0; + return generation; +} + +/** + * @brief Guard whose destruction resets the logger, if its configuration is still current. + * + * The generation check is not optional. A guard's refcount reaching zero makes + * g_active_guard expire *before* this destructor runs, so another thread can see no live + * configuration, apply its own, and install a new guard in that window. Without the check + * this destructor would then reset the logger and wipe the configuration that thread had + * just installed. + */ struct logger_config_guard { - ~logger_config_guard() { cuopt::reset_default_logger(); } + explicit logger_config_guard(uint64_t generation) : generation_(generation) {} + + ~logger_config_guard() + { + std::lock_guard lock(g_guard_mutex); + if (active_config_generation() != generation_) { return; } + cuopt::reset_default_logger(); + } + + private: + uint64_t generation_; }; // Weak reference to detect if any init_logger_t instance is still alive inline std::weak_ptr g_active_guard; -inline std::mutex g_guard_mutex; /** * @brief Apply a configuration and return a handle that keeps it alive. @@ -265,7 +292,7 @@ inline std::shared_ptr make_logger_config(const std::string& log_file, throw; } - auto guard = std::make_shared(); + auto guard = std::make_shared(++active_config_generation()); g_active_guard = guard; return guard; } diff --git a/cpp/tests/utilities/test_logger.cpp b/cpp/tests/utilities/test_logger.cpp index 20f8d57147..1e63c0ffe4 100644 --- a/cpp/tests/utilities/test_logger.cpp +++ b/cpp/tests/utilities/test_logger.cpp @@ -9,11 +9,14 @@ #include +#include #include #include #include #include #include +#include +#include /* * The logger is hidden, so this test executable has its own instance, separate from the one @@ -190,6 +193,39 @@ TEST(logger, failed_init_logger_restores_a_sink) std::remove(path.c_str()); } +// Exercises concurrent configure / release / emit. This is a smoke test, not a regression +// test: the race it relates to -- a guard whose refcount hit zero resetting the logger after +// a newer configuration was installed -- needs the count to reach zero exactly while another +// thread is inside make_logger_config, and under contention g_active_guard.lock() nearly +// always succeeds instead. Disabling the generation check in logger_config_guard does not +// make this fail. It is kept because it does cover concurrent use of the shared path, and is +// where a sanitizer would surface the unsynchronized sink mutation. +TEST(logger, concurrent_configure_and_emit) +{ + const auto path = temp_log_path("concurrent"); + + constexpr int kThreads = 8; + constexpr int kIterations = 400; + + std::vector threads; + threads.reserve(kThreads); + for (int t = 0; t < kThreads; ++t) { + threads.emplace_back([&path] { + for (int i = 0; i < kIterations; ++i) { + auto handle = cuopt::make_logger_config(path, false, /*truncate=*/false); + CUOPT_LOG_ERROR("concurrent_message"); + } + }); + } + for (auto& thread : threads) { + thread.join(); + } + + EXPECT_NE(read_file(path).find("concurrent_message"), std::string::npos); + + std::remove(path.c_str()); +} + // The library's logger is reachable only through the exported entry point. Its messages are // not observable here, but configuring it must clear the shared file exactly once. TEST(logger, component_logger_truncates_shared_file) From fdf65812ee460414ab0c0514a536e4af9c0ca8c4 Mon Sep 17 00:00:00 2001 From: Ramakrishna Prabhu Date: Thu, 27 Aug 2026 16:12:13 -0500 Subject: [PATCH 09/11] test(logger): use a trigger that fails to open for root too The two exception-safety tests pointed the log file at a missing directory under /, assuming the sink would fail to open it. The sink creates missing parent directories, so that only fails for a user who cannot write to the parent. CI runs as root in a container, created the directory, and both tests failed there while passing locally. Nest the log file under a regular file instead. Opening a path whose parent is not a directory fails with ENOTDIR for every user, root included, so the trigger no longer depends on privileges. Co-Authored-By: Claude Opus 5 --- cpp/tests/utilities/test_logger.cpp | 19 +++++++++++++++++-- 1 file changed, 17 insertions(+), 2 deletions(-) diff --git a/cpp/tests/utilities/test_logger.cpp b/cpp/tests/utilities/test_logger.cpp index 1e63c0ffe4..42f0fd1ed3 100644 --- a/cpp/tests/utilities/test_logger.cpp +++ b/cpp/tests/utilities/test_logger.cpp @@ -47,6 +47,17 @@ std::string temp_log_path(const std::string& tag) return "cuopt_logger_test_" + tag + "_" + std::to_string(unique_id()) + ".log"; } +// A path that cannot be opened as a log file for any user. Pointing at a missing directory +// is not enough: the sink creates missing parents, so it only fails for a user who cannot +// write to the parent, and CI runs as root. Nesting under a regular file fails with ENOTDIR +// regardless of privileges. +std::string unopenable_path_under(const std::string& blocker_file) +{ + std::ofstream blocker{blocker_file}; + blocker << "not a directory"; + return blocker_file + "/child.log"; +} + std::string read_file(const std::string& path) { std::ifstream in{path}; @@ -159,7 +170,8 @@ TEST(logger, append_preserves_existing_contents) // A configure that throws must not leave the logger wedged for later callers. TEST(logger, failed_configure_does_not_wedge_later_ones) { - const auto unopenable = "/nonexistent-directory-" + std::to_string(unique_id()) + "/x.log"; + const auto blocker = temp_log_path("blocker"); + const auto unopenable = unopenable_path_under(blocker); EXPECT_ANY_THROW(cuopt::make_logger_config(unopenable, false, true)); const auto path = temp_log_path("recovered"); @@ -172,13 +184,15 @@ TEST(logger, failed_configure_does_not_wedge_later_ones) << "a failed configure left the logger wedged"; std::remove(path.c_str()); + std::remove(blocker.c_str()); } // Same failure for the image-local entry point: apply_logger_config clears the sinks before // installing new ones, so a throw part way through must not leave the logger with none. TEST(logger, failed_init_logger_restores_a_sink) { - const auto unopenable = "/nonexistent-directory-" + std::to_string(unique_id()) + "/x.log"; + const auto blocker = temp_log_path("blocker"); + const auto unopenable = unopenable_path_under(blocker); EXPECT_ANY_THROW(cuopt::init_logger_t(unopenable, false, true)); const auto path = temp_log_path("init_recovered"); @@ -191,6 +205,7 @@ TEST(logger, failed_init_logger_restores_a_sink) << "a failed init_logger_t left the logger without sinks"; std::remove(path.c_str()); + std::remove(blocker.c_str()); } // Exercises concurrent configure / release / emit. This is a smoke test, not a regression From 78583ec18e6e25cfb0bd70b86fedfc58be1b3bb3 Mon Sep 17 00:00:00 2001 From: Ramakrishna Prabhu Date: Fri, 28 Aug 2026 09:02:04 -0500 Subject: [PATCH 10/11] refactor(logger): trim over-explanatory comments Most comments carried narrative rationale better suited to commit messages than to the code. Cut the ones restating what the code does or repeating a rationale already given elsewhere, keeping the handful that document genuinely non-obvious behavior (STB_GNU_UNIQUE symbol merging, the guard generation-check race, truncate-vs-append sink semantics, the ENOTDIR test trick). Signed-off-by: Ramakrishna Prabhu --- ci/check_symbols.sh | 8 +- cpp/CMakeLists.txt | 7 +- cpp/cuopt_cli.cpp | 7 +- cpp/src/math_optimization/logger_entry.cpp | 6 +- cpp/src/routing/logger_entry.cpp | 6 +- cpp/src/routing/solve.cu | 3 +- cpp/src/utilities/logger.hpp | 131 ++++++--------------- cpp/tests/utilities/test_logger.cpp | 34 ++---- 8 files changed, 58 insertions(+), 144 deletions(-) diff --git a/ci/check_symbols.sh b/ci/check_symbols.sh index ba5b9c015c..1b7dc4fb77 100755 --- a/ci/check_symbols.sh +++ b/ci/check_symbols.sh @@ -100,11 +100,9 @@ for sym in "${required_symbols[@]}"; do fi done -# The logger keeps one instance per component library, which only works while its state stays -# hidden. Nothing fails to build or test if that state becomes visible -- the instances just -# silently merge back into one via STB_GNU_UNIQUE, which glibc unifies process-wide even under -# RTLD_LOCAL. Assert the state is absent from the dynamic symbol table so that regression is -# loud. Only the per-component configure_logging entry points may cross the boundary. +# The logger keeps one instance per component library only while its state stays hidden -- +# nothing fails to build or test if it becomes visible, since glibc silently merges it back +# into one via STB_GNU_UNIQUE. Assert it's absent from the dynamic symbol table. logger_state_symbols=( "cuopt::default_logger()" "cuopt::global_log_buffer()" diff --git a/cpp/CMakeLists.txt b/cpp/CMakeLists.txt index 0e6c1cd72a..56ae8b0938 100644 --- a/cpp/CMakeLists.txt +++ b/cpp/CMakeLists.txt @@ -648,10 +648,9 @@ target_compile_definitions(cuopt_objs PUBLIC CUSPARSE_ENABLE_EXPERIMENTAL_API ) -# Lets callers reach routing's logger through init_component_logger_t. Routing is optional, -# so the entry point it declares is only linkable when routing was actually built. This is -# also set on cuopt and cuopt_static: $ does not carry INTERFACE -# properties, and consumers such as cuopt_cli and the tests link those, not cuopt_objs. +# Lets callers reach routing's logger through init_component_logger_t. Also set below on +# cuopt and cuopt_static: $ does not carry INTERFACE properties, and +# consumers such as cuopt_cli and the tests link those, not cuopt_objs. if(NOT SKIP_ROUTING_BUILD) target_compile_definitions(cuopt_objs PUBLIC CUOPT_HAS_ROUTING) endif() diff --git a/cpp/cuopt_cli.cpp b/cpp/cuopt_cli.cpp index 539f9f1321..564e3d93a6 100644 --- a/cpp/cuopt_cli.cpp +++ b/cpp/cuopt_cli.cpp @@ -100,10 +100,9 @@ int run_single_file(const std::string& file_path, cuopt::mathematical_optimization::io::mps_reader_type_t mps_reader, cuopt::mathematical_optimization::solver_settings_t& settings) { - // The solver's logger lives in the solver library and is not reachable from here, so - // configure it through its exported entry point. The CLI then configures its own logger - // for the messages it emits itself; it appends rather than truncates so that it does not - // clear the file the solver has just opened. + // The solver's logger lives in the solver library, reachable only through its exported + // entry point. The CLI's own logger appends rather than truncates, so it does not clear + // the file the solver has just opened. const auto log_file = settings.get_parameter(CUOPT_LOG_FILE); const auto log_console = settings.get_parameter(CUOPT_LOG_TO_CONSOLE); diff --git a/cpp/src/math_optimization/logger_entry.cpp b/cpp/src/math_optimization/logger_entry.cpp index f083e35d9e..dc8d024a50 100644 --- a/cpp/src/math_optimization/logger_entry.cpp +++ b/cpp/src/math_optimization/logger_entry.cpp @@ -7,11 +7,7 @@ #include -/* - * The logger itself is header-only and hidden, so it is private to each component library. - * This translation unit is compiled into cuopt_mathopt only, which is what makes the - * functions below reach mathopt's instance and no other. - */ +// Compiled into cuopt_mathopt only, so this reaches mathopt's hidden logger instance. namespace cuopt::mathematical_optimization { std::shared_ptr configure_logging(const std::string& log_file, diff --git a/cpp/src/routing/logger_entry.cpp b/cpp/src/routing/logger_entry.cpp index 665166d594..86c04c61b7 100644 --- a/cpp/src/routing/logger_entry.cpp +++ b/cpp/src/routing/logger_entry.cpp @@ -7,11 +7,7 @@ #include -/* - * The logger itself is header-only and hidden, so it is private to each component library. - * This translation unit is compiled into cuopt_routing only, which is what makes the - * functions below reach routing's instance and no other. - */ +// Compiled into cuopt_routing only, so this reaches routing's hidden logger instance. namespace cuopt::routing { std::shared_ptr configure_logging(const std::string& log_file, diff --git a/cpp/src/routing/solve.cu b/cpp/src/routing/solve.cu index 89c6ed2c59..136d77a8b4 100644 --- a/cpp/src/routing/solve.cu +++ b/cpp/src/routing/solve.cu @@ -16,8 +16,7 @@ template assignment_t solve(data_model_view_t const& data_model, solver_settings_t const& settings) { - // Routing's logger is private to cuopt_routing and starts out sinking into a buffer, so - // without this the CUOPT_LOG_ERROR calls below are recorded and never emitted anywhere. + // Without this, CUOPT_LOG_ERROR below sinks into the buffer and is never emitted. init_logger_t log("", settings.get_error_logging_mode()); try { diff --git a/cpp/src/utilities/logger.hpp b/cpp/src/utilities/logger.hpp index a72481e3ef..cddd012fd4 100644 --- a/cpp/src/utilities/logger.hpp +++ b/cpp/src/utilities/logger.hpp @@ -25,16 +25,11 @@ #include /* - * The logger and its buffer are defined inline and with hidden visibility, so each library - * that links this header owns its own. cuOpt ships as separate solver libraries and - * rapids_logger provides the logger type rather than a shared instance, so there is no - * single place to host one without a library existing purely to hold it. Each solver - * configures its own logging through its own settings. - * - * Hidden visibility is what does the separating, and it is not optional. The static local - * of an inline function is emitted as an STB_GNU_UNIQUE symbol, which glibc merges across - * the whole process regardless of RTLD_LOCAL, so a header-only logger with default - * visibility would still be one shared instance. Do not mark this namespace CUOPT_EXPORT. + * Defined inline with hidden visibility so each library that links this header owns its own + * logger instance. This is not optional: an inline function's static local is emitted as an + * STB_GNU_UNIQUE symbol, which glibc merges process-wide regardless of RTLD_LOCAL, so default + * visibility would collapse every library back into one shared logger. Do not mark this + * namespace CUOPT_EXPORT. * * Callers outside the libraries cannot reach a hidden logger, so each component exports a * configure entry point instead -- see log_target_t and init_component_logger_t below. @@ -87,39 +82,20 @@ inline log_buffer& global_log_buffer() return buffer; } -// Callback function for the buffer sink inline void buffer_log_callback(int lvl, const char* msg) { - // store level with message; actual filtering happens at logger time global_log_buffer().log(static_cast(lvl), msg); } -/** - * @brief Returns the default sink, used until something configures the logger. - * - * Messages go into an in-memory buffer rather than to a stream, and are replayed once a - * configuration arrives. Anything logged before that, and never followed by a configure, - * is dropped. - * - * @return sink_ptr The sink to use - */ +// Buffers messages in memory until something configures the logger; anything logged before +// that, and never followed by a configure, is dropped. inline rapids_logger::sink_ptr default_sink() { return std::make_shared(buffer_log_callback); } -/** - * @brief Returns the default log pattern for the global logger. - * - * @return std::string The default log pattern. - */ inline std::string default_pattern() { return "[%Y-%m-%d %H:%M:%S:%f] [%n] [%-6l] %v"; } -/** - * @brief Returns the default log level for the global logger. - * - * @return rapids_logger::level_enum The default log level. - */ inline rapids_logger::level_enum default_level() { #if CUOPT_LOG_ACTIVE_LEVEL == RAPIDS_LOGGER_LOG_LEVEL_TRACE @@ -170,28 +146,20 @@ inline void reset_default_logger() default_logger().flush_on(rapids_logger::level_enum::debug); } -/** - * @brief Point this image's logger at the given sinks and flush anything buffered so far. - * - * @param log_file File to log to, or empty for none. - * @param log_to_console Whether to also log to stdout. - * @param truncate Whether opening @p log_file clears it. Pass false when another - * image is already logging to the same path and has truncated it. - */ +// Points this image's logger at the given sinks and flushes anything buffered so far. +// `truncate` clears log_file up front instead of letting the sink truncate it: several +// loggers in one process can share a path, and a truncating sink writes from offset 0, +// silently overwriting whatever another one has already appended. Pass false when another +// image is already logging to the same path and has truncated it. inline void apply_logger_config(const std::string& log_file, bool log_to_console, bool truncate) { cuopt::default_logger().sinks().clear(); - // re-initialize sinks if (log_to_console) { cuopt::default_logger().sinks().push_back( std::make_shared(std::cout)); } if (!log_file.empty()) { - // Clear the file up front rather than letting the sink truncate. Several loggers in one - // process can share a path -- the CLI has its own and the solver library has another -- - // and a truncating sink writes from offset 0, silently overwriting whatever the other - // one has already appended. Opening every sink in append mode keeps them interleaving. if (truncate) { std::ofstream(log_file, std::ios::trunc); } cuopt::default_logger().sinks().push_back( std::make_shared(log_file, /*truncate=*/false)); @@ -204,22 +172,16 @@ inline void apply_logger_config(const std::string& log_file, bool log_to_console cuopt::default_logger().set_pattern(cuopt::default_pattern()); #endif - // Extract messages from the global buffer and log to the default logger auto buffered_messages = global_log_buffer().drain_all(); for (const auto& entry : buffered_messages) { cuopt::default_logger().log(entry.level, entry.msg.c_str()); } } -/** - * @brief Ref-counted initializer for the logger of the image that constructs it. - * - * Library code uses this directly: constructed inside cuopt_routing it configures routing's - * logger, inside cuopt_mathopt it configures mathopt's. Callers outside the libraries get - * their own logger this way and should use init_component_logger_t to reach a library's. - */ +// Ref-counted initializer for the logger of the image that constructs it. Library code uses +// this directly (routing configures routing's logger, mathopt configures mathopt's); callers +// outside the libraries should use init_component_logger_t to reach a library's instead. class init_logger_t { - // Using shared_ptr for ref-counting std::shared_ptr guard_; public: @@ -236,15 +198,10 @@ inline uint64_t& active_config_generation() return generation; } -/** - * @brief Guard whose destruction resets the logger, if its configuration is still current. - * - * The generation check is not optional. A guard's refcount reaching zero makes - * g_active_guard expire *before* this destructor runs, so another thread can see no live - * configuration, apply its own, and install a new guard in that window. Without the check - * this destructor would then reset the logger and wipe the configuration that thread had - * just installed. - */ +// Guard whose destruction resets the logger, if its configuration is still current. The +// generation check matters: a guard's refcount reaching zero expires g_active_guard *before* +// this destructor runs, so another thread can install a new configuration in that window, and +// without the check this destructor would reset the logger out from under it. struct logger_config_guard { explicit logger_config_guard(uint64_t generation) : generation_(generation) {} @@ -262,32 +219,25 @@ struct logger_config_guard { // Weak reference to detect if any init_logger_t instance is still alive inline std::weak_ptr g_active_guard; -/** - * @brief Apply a configuration and return a handle that keeps it alive. - * - * This is the single lifetime mechanism for the logger of this image. Both init_logger_t and - * the exported per-component configure_logging go through it, so a caller inside the library - * and a caller outside it share one refcount: whoever asks first configures, later callers - * get a handle to the same configuration, and the logger is reset when the last handle is - * dropped. That is what stops the solver reconfiguring mid-run and re-truncating a log file - * the caller had already written to. - */ +// Applies a configuration and returns a handle that keeps it alive. Single lifetime mechanism +// for this image's logger: init_logger_t and the exported per-component configure_logging both +// go through it, so a caller inside the library and one outside share one refcount, and the +// logger resets only when the last handle drops -- which is what stops the solver +// reconfiguring mid-run and re-truncating a log file the caller had already written to. inline std::shared_ptr make_logger_config(const std::string& log_file, bool log_to_console, bool truncate) { std::lock_guard lock(g_guard_mutex); - // Reuse the configuration already in place rather than replacing it. Reconfiguring here - // would also re-truncate the log file. + // Reuse the configuration already in place; reconfiguring here would re-truncate the file. if (auto existing = g_active_guard.lock()) { return existing; } try { apply_logger_config(log_file, log_to_console, truncate); } catch (...) { - // apply_logger_config clears the sinks before installing the new ones, so a throw part - // way through would otherwise leave the logger with none at all and silently drop every - // later message. + // Sinks are cleared before new ones install, so a throw here would otherwise leave the + // logger with none at all. reset_default_logger(); throw; } @@ -312,11 +262,8 @@ enum class log_target_t { } // namespace cuopt -/* - * Exported per-component entry points. Each is defined in exactly one component library and - * configures that library's own hidden logger. They are the only logging symbols that cross - * a library boundary. - */ +// Exported per-component entry points. Each is defined in exactly one component library, and +// configures that library's own hidden logger -- the only logging symbols crossing a boundary. namespace cuopt::mathematical_optimization { CUOPT_EXPORT std::shared_ptr configure_logging(const std::string& log_file, bool log_to_console, @@ -333,21 +280,13 @@ CUOPT_EXPORT std::shared_ptr configure_logging(const std::string& log_file namespace cuopt { -/** - * @brief Configures a component library's logger from outside that library. - * - * `init_logger_t` configures the logger of whichever image constructs it, which is what - * library code wants but not what an external caller wants: the CLI, the tests and the - * Python bindings each hold their own logger and need to reach into the solver's. This - * dispatches to the component's exported entry point instead. - * - * Defaults to mathopt because every external caller today is LP or MILP; routing is opted - * into explicitly. - */ +// Configures a component library's logger from outside that library. The CLI, tests and +// Python bindings each hold their own logger and need to reach into the solver's; this +// dispatches to the component's exported entry point instead of init_logger_t. Defaults to +// mathopt because every external caller today is LP or MILP; routing is opted in explicitly. class init_component_logger_t { - // The handle keeps the component's configuration alive; dropping it resets that - // component's logger. Same refcount init_logger_t uses, so a caller here and library code - // inside the component cannot tear down each other's configuration. + // Same refcount init_logger_t uses, so a caller here and library code inside the component + // cannot tear down each other's configuration. std::shared_ptr handle_; public: diff --git a/cpp/tests/utilities/test_logger.cpp b/cpp/tests/utilities/test_logger.cpp index 42f0fd1ed3..e742f6b877 100644 --- a/cpp/tests/utilities/test_logger.cpp +++ b/cpp/tests/utilities/test_logger.cpp @@ -19,18 +19,11 @@ #include /* - * The logger is hidden, so this test executable has its own instance, separate from the one - * inside libcuopt. That means CUOPT_LOG_* here reaches *this* image's logger, and only the - * entry points that operate on this image can be observed from here: - * - * - init_logger_t and make_logger_config configure this image's logger, so their behaviour - * is testable directly. They are the code the exported per-component configure_logging - * entry points run, just reached without crossing a library boundary. - * - init_component_logger_t reaches into libcuopt's logger, which only emits during a - * solve. Its effect on a shared file is observable here; its messages are not. - * - * The separation itself is checked outside this test, by ci/check_symbols.sh: libcuopt must - * export the component configure_logging entry points and none of the logger state. + * The logger is hidden, so this test binary has its own instance, separate from libcuopt's. + * CUOPT_LOG_* here reaches this image's logger: init_logger_t/make_logger_config are testable + * directly, while init_component_logger_t reaches into libcuopt's (its effect on a shared file + * is observable here, its messages are not). The hiding itself is checked by + * ci/check_symbols.sh, not here. */ namespace cuopt::test { @@ -47,10 +40,8 @@ std::string temp_log_path(const std::string& tag) return "cuopt_logger_test_" + tag + "_" + std::to_string(unique_id()) + ".log"; } -// A path that cannot be opened as a log file for any user. Pointing at a missing directory -// is not enough: the sink creates missing parents, so it only fails for a user who cannot -// write to the parent, and CI runs as root. Nesting under a regular file fails with ENOTDIR -// regardless of privileges. +// Nesting under a regular file fails to open with ENOTDIR for any user, including CI's root -- +// unlike a missing directory, which the sink creates. std::string unopenable_path_under(const std::string& blocker_file) { std::ofstream blocker{blocker_file}; @@ -208,13 +199,10 @@ TEST(logger, failed_init_logger_restores_a_sink) std::remove(blocker.c_str()); } -// Exercises concurrent configure / release / emit. This is a smoke test, not a regression -// test: the race it relates to -- a guard whose refcount hit zero resetting the logger after -// a newer configuration was installed -- needs the count to reach zero exactly while another -// thread is inside make_logger_config, and under contention g_active_guard.lock() nearly -// always succeeds instead. Disabling the generation check in logger_config_guard does not -// make this fail. It is kept because it does cover concurrent use of the shared path, and is -// where a sanitizer would surface the unsynchronized sink mutation. +// Smoke test for concurrent configure/release/emit, not a regression test -- the race it +// relates to needs the refcount to hit zero at an exact moment that contention makes unlikely +// to hit here. Kept because it exercises the shared path and is where a sanitizer would catch +// unsynchronized sink mutation. TEST(logger, concurrent_configure_and_emit) { const auto path = temp_log_path("concurrent"); From 2fe7bbfb7ae1ac4de52c7e1e2e00580d0dc6e12d Mon Sep 17 00:00:00 2001 From: Ramakrishna Prabhu Date: Fri, 28 Aug 2026 10:36:56 -0500 Subject: [PATCH 11/11] test(logger): cover mathopt/routing configured to different files together mathopt and routing are both compiled into the single `cuopt` shared library today (cpp/CMakeLists.txt), not into separate component libraries yet (#1622), so their exported configure_logging entry points currently operate on the same hidden logger instance rather than two independent ones. Verified with a standalone visibility/ linking repro outside the tree: two TUs sharing one .so fold an inline function's static into one instance; across two .so's, hidden visibility keeps them independent. Add a test that configures mathopt and routing to two different files at the same time and asserts the current, intentional behavior: no corruption (the second configure reuses the first's active configuration rather than re-truncating), but also no real separation (the first component's file wins, the second's is left untouched). The test documents that it must be updated once the library split lands and the two loggers become independent. Signed-off-by: Ramakrishna Prabhu --- cpp/tests/utilities/test_logger.cpp | 39 +++++++++++++++++++++++++++++ 1 file changed, 39 insertions(+) diff --git a/cpp/tests/utilities/test_logger.cpp b/cpp/tests/utilities/test_logger.cpp index e742f6b877..44a871d58b 100644 --- a/cpp/tests/utilities/test_logger.cpp +++ b/cpp/tests/utilities/test_logger.cpp @@ -248,4 +248,43 @@ TEST(logger, component_logger_truncates_shared_file) std::remove(path.c_str()); } +#ifdef CUOPT_HAS_ROUTING +// mathopt and routing are compiled into the same shared library (`cuopt` in +// cpp/CMakeLists.txt) until libcuopt splits into separate component libraries +// (#1622), so their "component" loggers are the same hidden instance today, not two +// independent ones. This pins down that current behavior: whichever component +// configures first wins the shared logger, and the second component's file is left +// alone rather than corrupted or silently truncated out from under a concurrent +// writer. If this starts failing, it means the split landed and mathopt/routing now +// have independent loggers -- update this test (and its neighbor above) to assert +// each file is truncated independently instead. +TEST(logger, mathopt_and_routing_share_one_instance_pre_split) +{ + const auto mathopt_path = temp_log_path("mathopt"); + const auto routing_path = temp_log_path("routing"); + { + std::ofstream seed{mathopt_path}; + seed << "STALE_MATHOPT\n"; + } + { + std::ofstream seed{routing_path}; + seed << "STALE_ROUTING\n"; + } + + { + cuopt::init_component_logger_t mathopt_log{mathopt_path, false, cuopt::log_target_t::mathopt}; + EXPECT_EQ(read_file(mathopt_path).find("STALE_MATHOPT"), std::string::npos) + << "mathopt configure did not clear its file"; + + cuopt::init_component_logger_t routing_log{routing_path, false, cuopt::log_target_t::routing}; + EXPECT_NE(read_file(routing_path).find("STALE_ROUTING"), std::string::npos) + << "routing's file was truncated -- mathopt and routing no longer share one " + "logger instance, see the comment above this test"; + } + + std::remove(mathopt_path.c_str()); + std::remove(routing_path.c_str()); +} +#endif + } // namespace cuopt::test