diff --git a/AGENTS.md b/AGENTS.md index fa6e8f75..2b4c72d6 100644 --- a/AGENTS.md +++ b/AGENTS.md @@ -461,6 +461,7 @@ These paths run at 60 fps or more from game callbacks. `[B-02]` governs allocati - `detail::InputPoller::is_binding_active(index/name/token)` uses a `shared_lock` and a relaxed load. - The `Logger::log()` level check and `is_enabled()` use one atomic load. +- The formatted `Logger::log()` stamp check uses one relaxed atomic load after the level check. - The `Logger::log()` asynchronous enqueue uses an atomic shared-pointer snapshot and a lock-free queue push. The snapshot uses a bounded internal lock. - `memory::is_readable(Region)` uses a sharded SRWLOCK reader and a cache lookup. - `memory::is_readable_nonblocking(Region)` uses a shared try-lock and a cache lookup. It returns `Unknown` after contention or an unpublished cache result. @@ -498,7 +499,7 @@ A same-ID design-note pointer owns the complete rationale for that rule. A gener - `[B-10]` `[CONVENTION]` **Generated build artifacts must not enter commits.** [docs/design/build-ci.md](docs/design/build-ci.md) supplies related evidence. - `[B-11]` `[CONVENTION]` **A change must not remove or weaken current tests.** New code must have new tests. [docs/design/testing.md](docs/design/testing.md) supplies the test policy. - `[B-12]` `[CONVENTION]` **Top-level public API must not expose implementation-only container or entry types.** Such types must remain in `namespace detail` or an internal header. A backend type must stay behind a forward-declared `Impl`. [docs/design/public-api.md](docs/design/public-api.md) `[B-12]` owns the rationale. -- `[B-13]` `[CONVENTION]` **If one listed trigger applies, a public function must use a request or options struct.** The struct must default-initialize its fields for designated initialization. Each new field must follow all established fields. [docs/design/public-api.md](docs/design/public-api.md) `[B-13]` owns the rationale. The triggers are adjacent parameters of the same type, more than about five parameters, or at least three counted knobs. Optional, policy, and configuration knobs all contribute to the count. +- `[B-13]` `[CONVENTION]` **If one listed trigger applies, a public function must use a request or options struct.** The struct must default-initialize its fields for designated initialization. Each new field must follow all established fields. [docs/design/public-api.md](docs/design/public-api.md) `[B-13]` owns the rationale. The triggers are adjacent parameters of the same type, more than about five parameters, or at least three counted knobs. Optional, policy, and configuration knobs all contribute to the count. One settled exception preserves the existing `Logger` constructor and `configure` surface. `source_stamp_mode` remains a trailing defaulted parameter. - `[B-14]` `[CONVENTION]` **Output code must use `'\n'` instead of `std::endl`.** `std::endl` forces a flush. [docs/design/build-ci.md](docs/design/build-ci.md) supplies related evidence. - `[B-15]` `[SAFETY]` **Hook callbacks must use `EventDispatcher::emit_safe()`.** It contains handler exceptions. `EventDispatcherTest.EmitSafe_CatchesHandlerExceptions` proves the contract. - `[B-16]` `[SAFETY]` **Teardown must destroy layered hooks on one target newest-first.** `hook::HookStack` enforces this order. [docs/design/hooking.md](docs/design/hooking.md) `[B-16]` owns the rationale. diff --git a/CMakeLists.txt b/CMakeLists.txt index 9be9c72c..8998fbc1 100644 --- a/CMakeLists.txt +++ b/CMakeLists.txt @@ -1,6 +1,6 @@ cmake_minimum_required(VERSION 3.28) -project(DetourModKit VERSION 4.1.1 LANGUAGES CXX) +project(DetourModKit VERSION 4.2.0 LANGUAGES CXX) # DetourModKit patches native x86-64 Windows processes. Another target fails before platform-specific checks cascade. # The public header and installed package enforce the same target contract. diff --git a/docs/design/logging.md b/docs/design/logging.md index b5f224bd..97938c7e 100644 --- a/docs/design/logging.md +++ b/docs/design/logging.md @@ -21,6 +21,8 @@ Async reads use an `atomic` snapshot. The snapshot takes a bounded i Hot-path mechanism: The `log()` level check costs one atomic load. +Formatted records apply one `LogSourceStampMode` policy. `always()` retains every stamp. `at_or_below(level)` retains stamps from Trace through that level. `never()` removes every stamp. The default uses `at_or_below(Debug)`, so the default Info admission produces no stamped records. The policy does not change record admission or the raw record tier. Each formatted path reads one relaxed atomic value before line format. + ### AsyncLogger The queue is a lock-free Vyukov-style MPMC queue. Shutdown has a single owner: admitted producers finish, later producers drop and count, and the writer alone drains and acknowledges completion. diff --git a/docs/design/public-api.md b/docs/design/public-api.md index ede91144..0e9b2481 100644 --- a/docs/design/public-api.md +++ b/docs/design/public-api.md @@ -72,6 +72,8 @@ The two standing high-arity idioms are deliberately mitigated and are the patter Reach for the struct form on every new public entry point. +The existing `Logger` constructor and `configure` form one settled exception. Their `source_stamp_mode` parameter stays trailing and defaulted for ordinary call compatibility. + ### [B-69] `error.hpp` documents that `SystemCallFailed`'s `detail` carries `GetLastError()`, and `detail::acquire_module_ref` restores the thread's last-error on failure precisely so its caller can read it. A failure site that builds `Error{SystemCallFailed, where}` with no detail leaves the consumer with a read of 0. diff --git a/include/DetourModKit/logger.hpp b/include/DetourModKit/logger.hpp index 60350c21..65626b21 100644 --- a/include/DetourModKit/logger.hpp +++ b/include/DetourModKit/logger.hpp @@ -3,11 +3,13 @@ /** * @file logger.hpp - * @brief Process logging value facade, the free log() accessor, and source-location-stamped formatting. - * @details Logger is a VALUE FACADE: a constructible object owning one file sink and an optional async writer. The - * free log() returns the process-default instance. Formatted records auto-stamp their call site through - * LocatedFormat. Logging is FAIL-SOFT: a dropped or filtered line is a best-effort bool, never a Result. The - * async transport stays behind the AsyncLogger pimpl. + * @brief Process logging value facade, the free log() accessor, and source-location stamp policy. + * @details Logger is a VALUE FACADE that owns one file sink and an optional async writer. + * The free log() returns the process-default instance. + * Formatted records apply the configured stamp policy through LocatedFormat. + * The logger is FAIL-SOFT. + * A dropped or filtered line is a best-effort bool, never a Result. + * The async transport stays behind the AsyncLogger pimpl. * @warning `[B-100]` Run Logger construction, first use of log(), and enable_async_mode() outside the loader lock. * These routes allocate. enable_async_mode() can create the writer thread. The loader-lock teardown path * detaches the writer without a wait. `LoggerTest.LoaderLock*` pins the boundary. @@ -25,6 +27,7 @@ #include #include #include +#include namespace DetourModKit { @@ -105,6 +108,66 @@ namespace DetourModKit Append }; + /** + * @class LogSourceStampMode + * @brief Selects which formatted log levels render a source-location stamp. + * @details Lower LogLevel values carry more diagnostic detail. + * at_or_below() retains stamps through one selected level. + * The default retains stamps for Trace and Debug. + */ + class LogSourceStampMode + { + public: + /// Constructs the default policy, which renders Trace and Debug source-location stamps. + constexpr LogSourceStampMode() noexcept = default; + + /// Returns a policy that renders every source-location stamp. + [[nodiscard]] static constexpr LogSourceStampMode always() noexcept { return LogSourceStampMode{ERROR_LEVEL}; } + + /** + * @brief Returns a policy that renders stamps from Trace through @p maximum_level. + * @param maximum_level The least verbose level that retains its stamp. + * @return The requested policy. An out-of-range level selects @ref LogSourceStampMode::always. + */ + [[nodiscard]] static constexpr LogSourceStampMode at_or_below(LogLevel maximum_level) noexcept + { + const auto level = static_cast(maximum_level); + return LogSourceStampMode{ + level <= static_cast(LogLevel::Error) ? static_cast(level) : ERROR_LEVEL + }; + } + + /// Returns a policy that renders no source-location stamp. + [[nodiscard]] static constexpr LogSourceStampMode never() noexcept { return LogSourceStampMode{NEVER_LEVEL}; } + + /** + * @brief Tests whether @p level retains its source-location stamp. + * @param level The record level. + * @return true when the stamp renders. + */ + [[nodiscard]] constexpr bool renders(LogLevel level) const noexcept + { + return static_cast(static_cast(level)) <= m_maximum_level; + } + + /// Compares two stamp policies by value. + [[nodiscard]] friend constexpr bool + operator==(const LogSourceStampMode &left, const LogSourceStampMode &right) noexcept = default; + + private: + static constexpr std::int8_t NEVER_LEVEL = -1; + static constexpr std::int8_t DEBUG_LEVEL = static_cast(LogLevel::Debug); + static constexpr std::int8_t ERROR_LEVEL = static_cast(LogLevel::Error); + + explicit constexpr LogSourceStampMode(std::int8_t maximum_level) noexcept : m_maximum_level(maximum_level) {} + + std::int8_t m_maximum_level{DEBUG_LEVEL}; + }; + + static_assert(std::is_trivially_copyable_v); + static_assert(sizeof(LogSourceStampMode) == sizeof(std::int8_t)); + static_assert(std::atomic::is_always_lock_free); + /// Default subsystem prefix stamped into the log file's banner line. inline constexpr std::string_view DEFAULT_LOG_PREFIX{"DetourModKit"}; /// Default log file name, resolved against the runtime module directory when relative. @@ -123,10 +186,11 @@ namespace DetourModKit /** * @struct LocatedFormat - * @brief A std::format_string that also captures the call site, so a variadic log() can auto-stamp source location. - * @details A defaulted std::source_location parameter cannot follow a variadic pack, so the format-string - * argument captures the location instead. The consteval constructor validates the format string at - * compile time and records the caller's log site, not a location inside the logger. + * @brief A std::format_string that captures the call site for the configured stamp policy. + * @details A defaulted std::source_location parameter cannot follow a variadic pack. + * The format-string argument captures the location instead. + * The consteval constructor validates the format string at compile time. + * It records the caller's log site, not a location inside the logger. * @tparam Args The formatted argument types, deduced from the trailing pack at the call site. */ template struct LocatedFormat @@ -144,18 +208,19 @@ namespace DetourModKit /// The validated format string forwarded to std::format at render time. std::format_string fmt; - /// The captured call site, rendered as a compact [file:line] stamp ahead of the message. + /// The captured call site, available to the active source-location stamp policy. std::source_location where; }; /** * @class Logger * @brief A thread-safe file logger: the value facade behind the free log() accessor and Session::log(). - * @details Owns one mutex-protected file sink plus an optional async writer. The minimum level is atomic, so a - * level change is lock-free and a record below it is dropped before any formatting (lazy evaluation). Two - * formatting tiers share the sink: the level-named templates and the variadic log()/try_log() take a - * LocatedFormat and auto-stamp [file:line] with compile-time format validation, while the plain - * log(level, string_view) / log_noexcept forms take an already-rendered line and add no stamp. + * @details The logger owns one mutex-protected file sink plus an optional async writer. + * The minimum level is atomic, so a level change is lock-free. + * A record below that level is dropped before format evaluation. + * The level-named templates and variadic log()/try_log() take a LocatedFormat. + * These methods apply the stamp policy, and the compiler validates their format strings. + * The raw log() and log_noexcept() forms add no stamp. */ class Logger { @@ -168,13 +233,15 @@ namespace DetourModKit * @param file_name The log file path. Relative paths resolve against the runtime module directory. * @param timestamp_fmt The strftime-style timestamp format for each line. * @param open_mode The action for an existing target file. See @ref LogOpenMode. + * @param source_stamp_mode The source-location stamp policy. The default retains Trace and Debug stamps. * @note Setup/control-plane only. Construction allocates and opens the sink. */ explicit Logger( std::string_view prefix, std::string_view file_name, std::string_view timestamp_fmt = DEFAULT_TIMESTAMP_FORMAT, - LogOpenMode open_mode = LogOpenMode::Truncate + LogOpenMode open_mode = LogOpenMode::Truncate, + LogSourceStampMode source_stamp_mode = LogSourceStampMode{} ); ~Logger() noexcept; @@ -199,6 +266,7 @@ namespace DetourModKit * @param timestamp_fmt Default timestamp format string (strftime compatible). * @param open_mode The mode for the process default's first sink open. An existing default follows the * @ref reconfigure reopen rule, even if its sink is closed. + * @param source_stamp_mode The source-location stamp policy. The default retains Trace and Debug stamps. * @note Setup/control-plane only. The call allocates and can reopen the log file. Do not call it from a hook * or input callback. */ @@ -206,7 +274,8 @@ namespace DetourModKit std::string_view prefix, std::string_view file_name, std::string_view timestamp_fmt = DEFAULT_TIMESTAMP_FORMAT, - LogOpenMode open_mode = LogOpenMode::Truncate + LogOpenMode open_mode = LogOpenMode::Truncate, + LogSourceStampMode source_stamp_mode = LogSourceStampMode{} ); /** @@ -313,6 +382,22 @@ namespace DetourModKit */ void set_log_level(LogLevel level); + /// Returns the source-location stamp policy. Callback-safe: one relaxed lock-free atomic read. + [[nodiscard]] LogSourceStampMode get_source_stamp_mode() const noexcept + { + return m_source_stamp_mode.load(std::memory_order_relaxed); + } + + /** + * @brief Sets the source-location stamp policy for later formatted records. + * @param mode The new policy. + * @note Callback-safe: one relaxed lock-free atomic store. The change emits no control record. + */ + void set_source_stamp_mode(LogSourceStampMode mode) noexcept + { + m_source_stamp_mode.store(mode, std::memory_order_relaxed); + } + /** * @brief Logs an already-rendered message at @p level (no source-location stamp). * @param level The level of the message. @@ -348,10 +433,11 @@ namespace DetourModKit [[nodiscard]] bool log_noexcept(LogLevel level, std::string_view message) noexcept; /** - * @brief Logs a source-location-stamped, std::format-style message at @p level. - * @details Arguments are formatted only when @p level passes the filter (lazy evaluation). The leading - * LocatedFormat captures the call site, so the rendered line is prefixed with a compact [file:line] - * stamp; the format string is validated against @p args at compile time. + * @brief Logs a std::format-style message and captures its source location. + * @details The active LogSourceStampMode policy controls the stamp. + * It adds a compact [file:line] stamp only when it enables @p level. + * Arguments format only after @p level passes the filter. + * The compiler validates the format string against @p args. * @tparam Args Deduced formatted argument types. * @param level The level of the message. * @param fmt The format string (auto-wrapped into a LocatedFormat capturing the call site). @@ -368,6 +454,7 @@ namespace DetourModKit { (void)format_located( [this, level](std::string_view rendered) { return this->log(level, rendered); }, + source_stamp_enabled(level), fmt.where, fmt.fmt, std::forward(args)... @@ -377,7 +464,10 @@ namespace DetourModKit /** * @name Level-named convenience loggers - * @brief Provides shorthand for log(LogLevel::X, fmt, args...). Each function stamps the call site. + * @brief Provides shorthand for log(LogLevel::X, fmt, args...). + * @details Each function captures the call site. + * The active LogSourceStampMode policy controls the stamp. + * It adds a compact [file:line] stamp only when it enables that function's level. * @note The functions inherit these contracts from @ref log: * - They inherit its delivery contract. * - They inherit its lazy-evaluation contract. @@ -412,10 +502,14 @@ namespace DetourModKit /** @} */ /** - * @brief No-throw, source-location-stamped formatted logging for callers on a noexcept boundary. - * @details Like log(level, fmt, args...) but formats inside a try/catch and routes through log_noexcept(), so - * neither a std::format failure nor a sink failure can propagate. Prefer this over the throwing forms - * inside hook callbacks. Arguments are formatted only when @p level is enabled. + * @brief Formats and logs without exceptions for callers on a noexcept boundary. + * @details Like log(level, fmt, args...), this overload captures the call site. + * The active LogSourceStampMode policy controls the stamp. + * It adds a compact [file:line] stamp only when it enables @p level. + * A local try/catch contains format failures. + * The log_noexcept() route contains sink failures. + * Prefer this overload inside hook callbacks. + * Arguments format only when @p level is enabled. * @return true if the message was handed to the sink, false if filtered out or dropped because * formatting/logging failed. A dropped record is counted in @ref dropped_count. * @note Best-effort and no-throw: it swallows every std::format and sink failure, so it will not terminate a @@ -434,6 +528,7 @@ namespace DetourModKit { return format_located( [this, level](std::string_view rendered) noexcept { return this->log_noexcept(level, rendered); }, + source_stamp_enabled(level), fmt.where, fmt.fmt, std::forward(args)... @@ -465,6 +560,8 @@ namespace DetourModKit std::string timestamp_format; /// The mode for the first sink open. LogOpenMode open_mode; + /// The source-location stamp policy for formatted records. + LogSourceStampMode source_stamp_mode; /** * @brief Constructs a complete process default snapshot. @@ -472,15 +569,17 @@ namespace DetourModKit * @param file The log file name. * @param ts_fmt The timestamp format. * @param mode The first sink open mode. + * @param stamp_mode The source-location stamp policy. The default retains Trace and Debug stamps. */ StaticConfig( std::string prefix, std::string file, std::string ts_fmt, - LogOpenMode mode = LogOpenMode::Truncate + LogOpenMode mode = LogOpenMode::Truncate, + LogSourceStampMode stamp_mode = LogSourceStampMode{} ) : log_prefix(std::move(prefix)), log_file_name(std::move(file)), timestamp_format(std::move(ts_fmt)), - open_mode(mode) + open_mode(mode), source_stamp_mode(stamp_mode) { } }; @@ -530,26 +629,38 @@ namespace DetourModKit /** * @brief Renders a source-located line into a stack buffer and hands it to @p sink. - * @details Renders the "[file:line] " stamp and message into one LOG_INLINE_MESSAGE_SIZE stack buffer. A line - * that fits is passed as a view with no heap allocation. A longer line is re-rendered once through - * std::format, the documented overflow path. The formatter only reads its arguments, so forwarding - * the same pack to both paths is safe. + * @details When @p with_stamp is true, the output starts with "[file:line] ". A line that fits uses one + * LOG_INLINE_MESSAGE_SIZE stack buffer. A longer line uses std::format once for the documented + * overflow path. The formatter only reads its arguments, so both attempts can share the pack. + * @param with_stamp true to render the captured source location. * @return Whatever @p sink returns for the line. */ template - static auto - format_located(Sink &&sink, const std::source_location &where, std::format_string fmt, Args &&...args) + static auto format_located( + Sink &&sink, + bool with_stamp, + const std::source_location &where, + std::format_string fmt, + Args &&...args + ) { - const std::string_view file = source_basename(where.file_name()); - const auto line = where.line(); - std::array buffer; - const auto stamp = std::format_to_n(buffer.data(), buffer.size(), "[{}:{}] ", file, line); - const auto stamp_len = static_cast(stamp.size); + std::string_view file; + std::uint_least32_t line{0}; + std::size_t stamp_len{0}; + auto body_out = buffer.data(); + if (with_stamp) + { + file = source_basename(where.file_name()); + line = where.line(); + const auto stamp = std::format_to_n(buffer.data(), buffer.size(), "[{}:{}] ", file, line); + stamp_len = static_cast(stamp.size); + body_out = stamp.out; + } if (stamp_len <= buffer.size()) { const auto body = - std::format_to_n(stamp.out, buffer.size() - stamp_len, fmt, std::forward(args)...); + std::format_to_n(body_out, buffer.size() - stamp_len, fmt, std::forward(args)...); const auto total = stamp_len + static_cast(body.size); if (total <= buffer.size()) { @@ -557,9 +668,21 @@ namespace DetourModKit } } - return sink( - std::string_view(std::format("[{}:{}] {}", file, line, std::format(fmt, std::forward(args)...))) - ); + if (with_stamp) + { + return sink( + std::string_view( + std::format("[{}:{}] {}", file, line, std::format(fmt, std::forward(args)...)) + ) + ); + } + return sink(std::string_view(std::format(fmt, std::forward(args)...))); + } + + /// Tests the current source-location stamp policy with one relaxed atomic read. + [[nodiscard]] bool source_stamp_enabled(LogLevel level) const noexcept + { + return m_source_stamp_mode.load(std::memory_order_relaxed).renders(level); } /** @@ -628,6 +751,7 @@ namespace DetourModKit std::shared_ptr m_log_file_stream_ptr; std::shared_ptr m_log_mutex_ptr; std::atomic m_current_log_level{LogLevel::Info}; + std::atomic m_source_stamp_mode{LogSourceStampMode{}}; std::atomic m_shutdown_called{false}; // Facade-level drop counter: records refused by an inert/shut-down facade, records lost at the synchronous diff --git a/include/DetourModKit/session.hpp b/include/DetourModKit/session.hpp index 546f46c8..56d31309 100644 --- a/include/DetourModKit/session.hpp +++ b/include/DetourModKit/session.hpp @@ -57,6 +57,8 @@ namespace DetourModKit * @details Append preserves the prior generation's records across a staged-generation reload. */ LogOpenMode log_open_mode{LogOpenMode::Truncate}; + /// The source-location stamp policy for formatted records. The default retains Trace and Debug stamps. + LogSourceStampMode log_source_stamp_mode{}; }; /** diff --git a/src/logger.cpp b/src/logger.cpp index 4c961228..2d03a494 100644 --- a/src/logger.cpp +++ b/src/logger.cpp @@ -155,7 +155,8 @@ namespace DetourModKit std::string_view prefix, std::string_view file_name, std::string_view timestamp_fmt, - LogOpenMode open_mode + LogOpenMode open_mode, + LogSourceStampMode source_stamp_mode ) { std::lock_guard config_lock(static_config_mutex()); @@ -166,7 +167,8 @@ namespace DetourModKit std::string(prefix), std::string(file_name), std::string(timestamp_fmt), - open_mode + open_mode, + source_stamp_mode ); auto previous_config = get_static_config(); set_static_config(std::move(staged_config)); @@ -201,6 +203,10 @@ namespace DetourModKit { set_static_config(std::move(previous_config)); } + else + { + instance.set_source_stamp_mode(source_stamp_mode); + } } catch (...) { @@ -341,6 +347,7 @@ namespace DetourModKit m_log_prefix = config->log_prefix; m_log_file_name = config->log_file_name; m_timestamp_format = config->timestamp_format; + m_source_stamp_mode.store(config->source_stamp_mode, std::memory_order_relaxed); // A default construction starts a fresh log unless the published configuration selected Append. // Reconfiguration never truncates. @@ -359,10 +366,11 @@ namespace DetourModKit std::string_view prefix, std::string_view file_name, std::string_view timestamp_fmt, - LogOpenMode open_mode + LogOpenMode open_mode, + LogSourceStampMode source_stamp_mode ) : m_log_prefix(prefix), m_log_file_name(file_name), m_timestamp_format(timestamp_fmt), - m_log_mutex_ptr(std::make_shared()) + m_log_mutex_ptr(std::make_shared()), m_source_stamp_mode(source_stamp_mode) { // Construction starts a fresh log unless the caller selected Append. Reconfiguration never truncates. adopt_first_sink(/*truncate=*/open_mode == LogOpenMode::Truncate); @@ -539,6 +547,7 @@ namespace DetourModKit // The new threshold precedes this record. The ordinary predicate discards the record after an upward change. (void)format_located( [this](std::string_view rendered) { return this->emit_record(LogLevel::Info, rendered); }, + source_stamp_enabled(LogLevel::Info), std::source_location::current(), "Log level changed from {} to {}", to_string(old_level), diff --git a/src/session.cpp b/src/session.cpp index 58e1910c..92517253 100644 --- a/src/session.cpp +++ b/src/session.cpp @@ -84,6 +84,7 @@ namespace DetourModKit std::chrono::milliseconds block_timeout_ms{16}; size_t block_max_spin_iterations{1000}; LogOpenMode log_open_mode{LogOpenMode::Truncate}; + LogSourceStampMode log_source_stamp_mode{}; [[nodiscard]] bool stage(const ModInfo &info) noexcept { @@ -104,6 +105,7 @@ namespace DetourModKit block_timeout_ms = info.log.block_timeout_ms; block_max_spin_iterations = info.log.block_max_spin_iterations; log_open_mode = info.log_open_mode; + log_source_stamp_mode = info.log_source_stamp_mode; return true; } @@ -524,7 +526,8 @@ namespace DetourModKit s_bootstrap_logger_info.name_view(), s_bootstrap_logger_info.log_file_view(), DEFAULT_TIMESTAMP_FORMAT, - s_bootstrap_logger_info.log_open_mode + s_bootstrap_logger_info.log_open_mode, + s_bootstrap_logger_info.log_source_stamp_mode ); DetourModKit::log().enable_async_mode(s_bootstrap_logger_info.logger_config()); } @@ -817,7 +820,13 @@ namespace DetourModKit // enable_async_mode contains its failures, so this catch owns only configuration. try { - Logger::configure(info.name, info.log_file, DEFAULT_TIMESTAMP_FORMAT, info.log_open_mode); + Logger::configure( + info.name, + info.log_file, + DEFAULT_TIMESTAMP_FORMAT, + info.log_open_mode, + info.log_source_stamp_mode + ); // Qualified: inside this static member the free accessor is hidden by the non-static Session::log(). DetourModKit::log().enable_async_mode(info.log); } diff --git a/tests/test_logger.cpp b/tests/test_logger.cpp index 110c9099..b3854bc5 100644 --- a/tests/test_logger.cpp +++ b/tests/test_logger.cpp @@ -1,4 +1,5 @@ #include +#include #include #include #include @@ -46,6 +47,24 @@ namespace (std::string(stem) + "_" + std::to_string(_getpid()) + "_" + std::to_string(counter) + ".log"); } + [[nodiscard]] std::string read_line_containing(const std::filesystem::path &path, std::string_view marker) + { + std::ifstream stream(path); + for (std::string line; std::getline(stream, line);) + { + if (line.find(marker) != std::string::npos) + { + return line; + } + } + return {}; + } + + [[nodiscard]] bool has_source_stamp(std::string_view line) noexcept + { + return line.find("] :: [") != std::string_view::npos; + } + void rendezvous_level_transition() noexcept { if (s_level_transition_arrivals.fetch_add(1, std::memory_order_acq_rel) + 1 == 2) @@ -1857,7 +1876,7 @@ TEST_F(LoggerTest, SetLogLevel_ChangedThresholdsEmitInfoControlRecord) } ASSERT_FALSE(record_line.empty()); EXPECT_NE(record_line.find("[INFO ] ::"), std::string::npos) << "control record line: " << record_line; - EXPECT_NE(record_line.find("] :: [logger.cpp:"), std::string::npos) << "control record line: " << record_line; + EXPECT_EQ(record_line.find("] :: [logger.cpp:"), std::string::npos) << "control record line: " << record_line; logger.set_log_level(LogLevel::Info); } @@ -2214,8 +2233,9 @@ TEST_F(LoggerTest, SourceLocation_StampsFileAndLine) { Logger &logger = log(); logger.set_log_level(LogLevel::Info); + logger.set_source_stamp_mode(LogSourceStampMode::always()); - // The formatted (LocatedFormat) path auto-stamps the call site as a compact [file:line] prefix. Capture the line + // The always policy stamps the call site as a compact [file:line] prefix. Capture the line // number of the info() call from __LINE__ so the assertion is exact (it tracks future edits to this file) rather // than a loose digit search. const unsigned call_line = static_cast(__LINE__) + 1; @@ -2232,6 +2252,156 @@ TEST_F(LoggerTest, SourceLocation_StampsFileAndLine) << "expected the rendered line to carry the source stamp " << expected_stamp; } +TEST_F(LoggerTest, SourceStampModePredicateTable) +{ + // An out-of-range level selects always(). An unclamped value of 255 compares as never(). + static_assert(LogSourceStampMode{} == LogSourceStampMode::at_or_below(LogLevel::Debug)); + static_assert(LogSourceStampMode::at_or_below(static_cast(5)) == LogSourceStampMode::always()); + static_assert(LogSourceStampMode::at_or_below(static_cast(255)) == LogSourceStampMode::always()); + + struct PolicyCase + { + LogSourceStampMode mode; + std::array expected; + }; + + constexpr std::array levels{ + LogLevel::Trace, + LogLevel::Debug, + LogLevel::Info, + LogLevel::Warning, + LogLevel::Error, + }; + constexpr std::array policies{ + PolicyCase{.mode = LogSourceStampMode::never(), .expected = {false, false, false, false, false}}, + PolicyCase{ + .mode = LogSourceStampMode::at_or_below(LogLevel::Trace), + .expected = {true, false, false, false, false} + }, + PolicyCase{ + .mode = LogSourceStampMode::at_or_below(LogLevel::Debug), + .expected = {true, true, false, false, false} + }, + PolicyCase{ + .mode = LogSourceStampMode::at_or_below(LogLevel::Info), + .expected = {true, true, true, false, false} + }, + PolicyCase{ + .mode = LogSourceStampMode::at_or_below(LogLevel::Warning), + .expected = {true, true, true, true, false} + }, + PolicyCase{ + .mode = LogSourceStampMode::at_or_below(LogLevel::Error), + .expected = {true, true, true, true, true} + }, + PolicyCase{.mode = LogSourceStampMode::always(), .expected = {true, true, true, true, true}}, + }; + + for (const auto &policy : policies) + { + for (std::size_t i = 0; i < levels.size(); ++i) + { + EXPECT_EQ(policy.mode.renders(levels[i]), policy.expected[i]); + } + } +} + +TEST_F(LoggerTest, SourceStampModeAtOrBelowDebugStampsTraceAndDebugOnly) +{ + Logger &logger = log(); + logger.set_log_level(LogLevel::Trace); + EXPECT_EQ(logger.get_source_stamp_mode(), LogSourceStampMode::at_or_below(LogLevel::Debug)); + + logger.trace("STAMP_TABLE_TRACE"); + logger.debug("STAMP_TABLE_DEBUG"); + logger.info("STAMP_TABLE_INFO"); + logger.warning("STAMP_TABLE_WARNING"); + logger.error("STAMP_TABLE_ERROR"); + logger.flush(); + + const std::array, 5> expected{ + std::pair{"STAMP_TABLE_TRACE", true}, + std::pair{"STAMP_TABLE_DEBUG", true}, + std::pair{"STAMP_TABLE_INFO", false}, + std::pair{"STAMP_TABLE_WARNING", false}, + std::pair{"STAMP_TABLE_ERROR", false}, + }; + for (const auto &[marker, stamped] : expected) + { + const std::string line = read_line_containing(m_test_log_file, marker); + ASSERT_FALSE(line.empty()) << marker; + EXPECT_EQ(has_source_stamp(line), stamped) << line; + } +} + +TEST_F(LoggerTest, SourceStampModeNeverCoversTryLogAndOverflow) +{ + Logger &logger = log(); + logger.set_log_level(LogLevel::Trace); + logger.set_source_stamp_mode(LogSourceStampMode::never()); + + EXPECT_TRUE(logger.try_log(LogLevel::Debug, "TRYLOG_NO_STAMP_{}", 17)); + const std::string oversized(LOG_INLINE_MESSAGE_SIZE + 64, 'X'); + logger.info("OVERFLOW_NO_STAMP_{}", oversized); + logger.set_source_stamp_mode(LogSourceStampMode::at_or_below(LogLevel::Debug)); + logger.debug("OVERFLOW_STAMPED_{}", oversized); + logger.flush(); + + const std::string try_log_line = read_line_containing(m_test_log_file, "TRYLOG_NO_STAMP_17"); + const std::string overflow_line = read_line_containing(m_test_log_file, "OVERFLOW_NO_STAMP_"); + const std::string stamped_overflow_line = read_line_containing(m_test_log_file, "OVERFLOW_STAMPED_"); + ASSERT_FALSE(try_log_line.empty()); + ASSERT_FALSE(overflow_line.empty()); + ASSERT_FALSE(stamped_overflow_line.empty()); + EXPECT_FALSE(has_source_stamp(try_log_line)); + EXPECT_FALSE(has_source_stamp(overflow_line)); + EXPECT_TRUE(has_source_stamp(stamped_overflow_line)); +} + +TEST_F(LoggerTest, SourceStampModeAccessorFlipAffectsLaterRecordsAndControlRecord) +{ + Logger &logger = log(); + logger.set_log_level(LogLevel::Trace); + EXPECT_EQ(logger.get_source_stamp_mode(), LogSourceStampMode::at_or_below(LogLevel::Debug)); + logger.set_source_stamp_mode(LogSourceStampMode::always()); + + logger.info("STAMP_BEFORE_MODE_FLIP"); + logger.set_source_stamp_mode(LogSourceStampMode::never()); + EXPECT_EQ(logger.get_source_stamp_mode(), LogSourceStampMode::never()); + logger.info("STAMP_AFTER_MODE_FLIP"); + logger.set_log_level(LogLevel::Warning); + logger.flush(); + + const std::string before = read_line_containing(m_test_log_file, "STAMP_BEFORE_MODE_FLIP"); + const std::string after = read_line_containing(m_test_log_file, "STAMP_AFTER_MODE_FLIP"); + const std::string control = read_line_containing(m_test_log_file, "Log level changed from TRACE to WARNING"); + ASSERT_FALSE(before.empty()); + ASSERT_FALSE(after.empty()); + ASSERT_FALSE(control.empty()); + EXPECT_TRUE(has_source_stamp(before)); + EXPECT_FALSE(has_source_stamp(after)); + EXPECT_FALSE(has_source_stamp(control)); +} + +TEST_F(LoggerTest, SourceStampModeConfigureCommitsOnlyAfterAcceptedSink) +{ + Logger &logger = log(); + const auto trace_and_debug = LogSourceStampMode::at_or_below(LogLevel::Debug); + Logger::configure("TEST", m_test_log_file.string(), "%Y-%m-%d %H:%M:%S", LogOpenMode::Truncate, trace_and_debug); + EXPECT_EQ(logger.get_source_stamp_mode(), trace_and_debug); + EXPECT_EQ(detail::LoggerTestSeams::static_config_for_test()->source_stamp_mode, trace_and_debug); + + Logger::configure( + "BAD_STAMP_CONFIG", + "Z:\\nonexistent\\dir\\stamp_mode.log", + "%H:%M:%S", + LogOpenMode::Truncate, + LogSourceStampMode::never() + ); + EXPECT_EQ(logger.get_source_stamp_mode(), trace_and_debug); + EXPECT_EQ(detail::LoggerTestSeams::static_config_for_test()->source_stamp_mode, trace_and_debug); +} + TEST_F(LoggerTest, RawStringViewLog_HasNoSourceStamp) { Logger &logger = log(); diff --git a/tests/test_session.cpp b/tests/test_session.cpp index bbd28cf5..968711a0 100644 --- a/tests/test_session.cpp +++ b/tests/test_session.cpp @@ -65,6 +65,24 @@ namespace (std::string(stem) + "_" + std::to_string(_getpid()) + "_" + std::to_string(counter) + ".log"); } + [[nodiscard]] std::string read_session_line_containing(const std::filesystem::path &path, std::string_view marker) + { + std::ifstream stream(path); + for (std::string line; std::getline(stream, line);) + { + if (line.find(marker) != std::string::npos) + { + return line; + } + } + return {}; + } + + [[nodiscard]] bool session_line_has_source_stamp(std::string_view line) noexcept + { + return line.find("] :: [") != std::string_view::npos; + } + std::string current_exe_basename() { char exe_path[MAX_PATH]{}; @@ -841,6 +859,30 @@ TEST(SessionTeardown, FlushesConfiguredLogger) } } +TEST(SessionLoggerConfiguration, StartPropagatesNeverSourceStampMode) +{ + const auto log_path = unique_session_log_path("test_session_stamp_start"); + std::error_code error_code; + std::filesystem::remove(log_path, error_code); + + { + Result opened = Session::start( + ModInfo{ + .name = "SESS_STAMP_START", + .log_file = log_path.string(), + .log_source_stamp_mode = LogSourceStampMode::never(), + } + ); + ASSERT_TRUE(opened.has_value()) << opened.error().message(); + opened->log().info("SESSION_START_STAMP_MODE_{}", "NEVER"); + } + + const std::string line = read_session_line_containing(log_path, "SESSION_START_STAMP_MODE_NEVER"); + ASSERT_FALSE(line.empty()); + EXPECT_FALSE(session_line_has_source_stamp(line)); + std::filesystem::remove(log_path, error_code); +} + TEST(SessionTeardown, ResetsMemoryCache) { { @@ -1188,6 +1230,39 @@ TEST_F(SessionBootstrapTest, HappyPathBootstrapRunsOnReady) EXPECT_EQ(m_sig.ready_calls.load(), 1); } +TEST_F(SessionBootstrapTest, BootstrapPropagatesNeverSourceStampMode) +{ + const auto log_path = unique_session_log_path("test_session_stamp_bootstrap"); + std::error_code error_code; + std::filesystem::remove(log_path, error_code); + + Result started = bootstrap( + ModInfo{ + .name = "SESS_STAMP_BOOTSTRAP", + .log_file = log_path.string(), + .log_source_stamp_mode = LogSourceStampMode::never(), + }, + [this](Session &session) -> Result + { + session.log().info("SESSION_BOOTSTRAP_STAMP_MODE_{}", "NEVER"); + m_sig.signal_ready(); + return {}; + } + ); + ASSERT_TRUE(started.has_value()) << started.error().message(); + m_bootstrapped = true; + ASSERT_TRUE(m_sig.wait_for_ready(kTestTimeout)) << "on_ready did not complete within timeout"; + + Result drained = shutdown_and_wait(); + ASSERT_TRUE(drained.has_value()) << drained.error().message(); + m_bootstrapped = false; + + const std::string line = read_session_line_containing(log_path, "SESSION_BOOTSTRAP_STAMP_MODE_NEVER"); + ASSERT_FALSE(line.empty()); + EXPECT_FALSE(session_line_has_source_stamp(line)); + std::filesystem::remove(log_path, error_code); +} + TEST_F(SessionBootstrapTest, ProcessGateMismatchDoesNotSpawnWorker) { Result started = bootstrap( diff --git a/tests/test_version.cpp b/tests/test_version.cpp index d5384605..0ee1d004 100644 --- a/tests/test_version.cpp +++ b/tests/test_version.cpp @@ -13,8 +13,8 @@ namespace // version bump must touch in this file. Every other case below is relational so it tracks the macros // automatically. The release workflow separately guards that CMakeLists.txt project(VERSION) matches the tag. EXPECT_EQ(DMK_VERSION_MAJOR, 4); - EXPECT_EQ(DMK_VERSION_MINOR, 1); - EXPECT_EQ(DMK_VERSION_PATCH, 1); + EXPECT_EQ(DMK_VERSION_MINOR, 2); + EXPECT_EQ(DMK_VERSION_PATCH, 0); } TEST(VersionTest, VersionStringMatchesMacros) @@ -43,13 +43,14 @@ namespace EXPECT_TRUE(DMK_VERSION_AT_LEAST(2, 0, 0)); // Current-major boundary, pinned as literals (not derived from the macros) so a regression that silently - // dropped the version back below 4.1.1 is caught here even if the macros themselves were edited in lockstep. - // The 4.1.1 floor is satisfied. The next patch and minor on this major are not yet reached. + // dropped the version back below 4.2.0 is caught here even if the macros themselves were edited in lockstep. + // The 4.2.0 floor is satisfied. The next patch and major are not yet reached. EXPECT_TRUE(DMK_VERSION_AT_LEAST(4, 0, 0)); EXPECT_TRUE(DMK_VERSION_AT_LEAST(4, 1, 0)); EXPECT_TRUE(DMK_VERSION_AT_LEAST(4, 1, 1)); - EXPECT_FALSE(DMK_VERSION_AT_LEAST(4, 1, 2)); - EXPECT_FALSE(DMK_VERSION_AT_LEAST(4, 2, 0)); + EXPECT_TRUE(DMK_VERSION_AT_LEAST(4, 1, 2)); + EXPECT_TRUE(DMK_VERSION_AT_LEAST(4, 2, 0)); + EXPECT_FALSE(DMK_VERSION_AT_LEAST(4, 2, 1)); EXPECT_FALSE(DMK_VERSION_AT_LEAST(5, 0, 0)); // Relational invariants derived from the current macros instead of literal future versions: the current