Add the logging system#36
Conversation
|
Warning Review limit reached
More reviews will be available in 18 minutes and 39 seconds. Learn how PR review limits work. Your organization has used up its prepaid credits, and credit purchases are no longer available. Enable the review add-on in the billing tab to keep reviews running — you're only billed for reviews past your plan's rate limits ($0.25/file). ⌛ How to resolve this issue?After more reviews become available, a review can be triggered using the To avoid repeated limits, reduce automatic review volume by pausing incremental auto-reviews earlier, using label-based review opt-in, excluding WIP or generated PR titles, or requesting reviews manually when the PR is ready. If your team needs uninterrupted high-volume reviews, an organization admin can enable usage-based credits. 🚦 How do rate limits work?CodeRabbit enforces per-developer PR review limits for each organization. Most developers receive the normal plan refill rate. For paid Pro and Pro+ PR reviews, CodeRabbit uses adaptive limits for sustained high-volume activity. When a developer's recent PR review activity reaches the 95th percentile or higher among CodeRabbit users, the refill rate gradually slows as usage increases. The highest same-day bursts are limited more strictly. Please see our Fair Usage Limits Policy for further information. ℹ️ Review info⚙️ Run configurationConfiguration used: defaults Review profile: CHILL Plan: Pro Run ID: 📒 Files selected for processing (4)
📝 WalkthroughWalkthroughA new Changescore.logging Async Module
Sequence Diagram(s)sequenceDiagram
rect rgba(173, 216, 230, 0.5)
Note over Caller,Queue: Producer side (any thread)
participant Caller as log() template
participant enqueue_log as internal::enqueue_log
participant Queue as Ring Buffer
end
rect rgba(144, 238, 144, 0.5)
Note over Worker,Sinks: Consumer side (worker thread)
participant Worker as worker_loop
participant Sinks as ILogSink list
end
Caller->>Caller: std::format_to_n into stack buffer
Caller->>enqueue_log: verbosity, category, source_location, text
enqueue_log->>enqueue_log: check g_accepting_logs + verbosity threshold
enqueue_log->>Queue: CAS acquire slot, fill LogMessage metadata
alt queue full
Queue-->>enqueue_log: messages_dropped++, return
else slot acquired
Queue-->>Worker: notify condition_variable
end
Worker->>Queue: dequeue LogMessage (sequence CAS)
Worker->>Sinks: write(LogMessage) per sink snapshot
Worker->>Worker: messages_written++, dispatched++
sequenceDiagram
participant Caller as fatal() template
participant execute_fatal as internal::execute_fatal
participant Stdout as stdout
participant Sinks as All registered ILogSinks
participant Hook as internal::fatal_hook
Caller->>Caller: std::format_to_n into stack buffer
Caller->>execute_fatal: category, location, text
execute_fatal->>Stdout: fprintf formatted fatal line
execute_fatal->>Sinks: write(LogMessage) under sink I/O mutex
execute_fatal->>Sinks: flush() under sink I/O mutex
execute_fatal->>Hook: invoke fatal_hook()
execute_fatal->>execute_fatal: std::abort()
Estimated code review effort🎯 4 (Complex) | ⏱️ ~60 minutes Suggested reviewers
Poem
🚥 Pre-merge checks | ✅ 4 | ❌ 1❌ Failed checks (1 warning)
✅ Passed checks (4 passed)
✏️ Tip: You can configure your own custom pre-merge checks in the settings. ✨ Finishing Touches🧪 Generate unit tests (beta)
Thanks for using CodeRabbit! It's free for OSS, and your support helps us grow. If you like it, consider giving us a shout-out. Comment |
![coderabbitai[bot]](https://avatars.githubusercontent.com/in/347564?s=60&v=4){kind=small}
There was a problem hiding this comment.
Actionable comments posted: 5
🧹 Nitpick comments (1)
Engine/cpp/runtime/core/logging/logging.test.cpp (1)
247-265: ⚡ Quick winMake
fatal_hookrestoration exception-safe.This test mutates global process state and restores it manually; if control exits unexpectedly before Line 264, later tests inherit the wrong hook.
Suggested fix
- draco::core::logging::internal::fatal_hook = [] { throw FatalTestException{}; }; + auto previous_fatal_hook = draco::core::logging::internal::fatal_hook; + struct FatalHookRestore final + { + void (**slot)(); + void (*old_value)(); + ~FatalHookRestore() { *slot = old_value; } + } fatal_hook_restore{&draco::core::logging::internal::fatal_hook, previous_fatal_hook}; + + draco::core::logging::internal::fatal_hook = [] { throw FatalTestException{}; }; @@ - draco::core::logging::internal::fatal_hook = [] { std::abort(); }; shutdown();🤖 Prompt for AI Agents
Verify each finding against current code. Fix only still-valid issues, skip the rest with a brief reason, keep changes minimal, and validate. In `@Engine/cpp/runtime/core/logging/logging.test.cpp` around lines 247 - 265, The fatal_hook is manually restored after the test logic, but if an exception is thrown before reaching the restoration line at the end, the global state remains corrupted for subsequent tests. Wrap the fatal_hook assignment at the beginning of the test in a RAII pattern or scope guard that guarantees the hook is restored to its original state (std::abort) even if exceptions occur during the LOG_FATAL call or any other operation within the test scope. Ensure the restoration happens automatically when exiting the test scope, rather than relying on manual restoration at a specific line.
🤖 Prompt for all review comments with AI agents
Verify each finding against current code. Fix only still-valid issues, skip the
rest with a brief reason, keep changes minimal, and validate.
Inline comments:
In `@Engine/cpp/runtime/core/logging/logging.cpp`:
- Around line 444-451: The timestamp format at line 444 uses second-level
precision which causes filename collisions when multiple log rolls occur within
the same second, causing the std::ios::trunc flag at line 451 to overwrite
previously rotated logs. Add higher precision to the timestamp (such as
milliseconds or microseconds) or implement a counter-based collision avoidance
mechanism in the new_path construction at line 450 to ensure each rolled log
file gets a unique filename even when rolls happen within the same second.
- Around line 195-219: The init() function creates a new worker thread and
assigns it to g_worker_thread without checking if a thread is already running.
To prevent std::terminate errors from repeated init() calls, add a guard before
the thread creation line that checks if g_worker_thread is joinable; if it is,
return early from the init() function to prevent reassigning an active thread.
The check should happen before g_worker_thread is assigned the new
std::thread(worker_loop).
- Around line 162-169: The worker thread loop (where sink->write(msg) is called
around line 166-169), the flush() function (lines 258-260), and the fatal()
function (lines 368-369) all invoke sink I/O operations without synchronization,
creating a data race when using std::ofstream-backed sinks. Add a new mutex
(separate from the existing g_sink_update_mutex which only protects sink list
modifications) to serialize all sink I/O operations. Lock this mutex around the
sink->write() call in the worker thread dequeue loop, around the flush
operations in the flush() function, and around the sink operations in the
fatal() function to ensure thread-safe access to the sink objects across all
three call sites.
In `@Engine/cpp/runtime/core/logging/logging.test.cpp`:
- Around line 288-306: The test has two issues: the ifstream object infile
opened at the file validation section is never closed before attempting to
remove the file at the end of the test, which causes cross-platform failures on
Windows where open files cannot be deleted; additionally, the hardcoded
test_output.log path can cause collisions when tests run in parallel. Fix this
by ensuring the infile stream is closed before file removal (either by wrapping
the file reading operations in a separate scope or explicitly calling
infile.close()) and by replacing the hardcoded test_path string with a unique
temporary file path using std::filesystem mechanisms to generate a unique name
per test run.
In `@Engine/cpp/runtime/core/logging/macros.h`:
- Around line 3-12: The SET_CATEGORY_VERBOSITY macro uses
std::memory_order_relaxed which is declared in the <atomic> header, but the
header file does not include it. Add `#include` <atomic> at the top of the file
near the existing `#include` <format> to ensure the header is self-sufficient and
all dependencies are properly declared, preventing potential compilation issues
for callers that may not have included <atomic> before using these macros.
---
Nitpick comments:
In `@Engine/cpp/runtime/core/logging/logging.test.cpp`:
- Around line 247-265: The fatal_hook is manually restored after the test logic,
but if an exception is thrown before reaching the restoration line at the end,
the global state remains corrupted for subsequent tests. Wrap the fatal_hook
assignment at the beginning of the test in a RAII pattern or scope guard that
guarantees the hook is restored to its original state (std::abort) even if
exceptions occur during the LOG_FATAL call or any other operation within the
test scope. Ensure the restoration happens automatically when exiting the test
scope, rather than relying on manual restoration at a specific line.
🪄 Autofix (Beta)
Fix all unresolved CodeRabbit comments on this PR:
- Push a commit to this branch (recommended)
- Create a new PR with the fixes
ℹ️ Review info
⚙️ Run configuration
Configuration used: defaults
Review profile: CHILL
Plan: Pro
Run ID: 2530ce9c-7b86-4ae8-8d00-4f2021e58a00
📒 Files selected for processing (8)
Engine/cpp/runtime/CMakeLists.txtEngine/cpp/runtime/core/CMakeLists.txtEngine/cpp/runtime/core/core.cppmEngine/cpp/runtime/core/io/image_loader.cppEngine/cpp/runtime/core/logging/logging.cppEngine/cpp/runtime/core/logging/logging.cppmEngine/cpp/runtime/core/logging/logging.test.cppEngine/cpp/runtime/core/logging/macros.h
Co-authored-by: coderabbitai[bot] <136622811+coderabbitai[bot]@users.noreply.github.com>
There was a problem hiding this comment.
Actionable comments posted: 4
Caution
Some comments are outside the diff and can’t be posted inline due to platform limitations.
⚠️ Outside diff range comments (1)
Engine/cpp/runtime/core/logging/logging.cpp (1)
198-226:⚠️ Potential issue | 🟡 Minor | ⚡ Quick winConcurrent
init()calls can triggerstd::terminate.The
joinable()guard at line 200 is not thread-safe. If two threads callinit()simultaneously, both may pass the guard before either assigns tog_worker_thread. When the second thread assigns a newstd::threadtog_worker_thread, the destructor of the first thread (which is joinable) is invoked, causingstd::terminate.If concurrent
init()is not a supported usage pattern, document this clearly. Otherwise, protect with a mutex or usestd::call_once.🛡️ Suggested fix using std::call_once
+static std::once_flag g_init_flag; + +static void init_impl() +{ + g_start_time = std::chrono::steady_clock::now(); + // ... rest of initialization + g_worker_thread = std::thread(worker_loop); +} + void init() { - if (g_worker_thread.joinable()) { - return; - } - // ... initialization code ... - g_worker_thread = std::thread(worker_loop); + std::call_once(g_init_flag, init_impl); }🤖 Prompt for AI Agents
Verify each finding against current code. Fix only still-valid issues, skip the rest with a brief reason, keep changes minimal, and validate. In `@Engine/cpp/runtime/core/logging/logging.cpp` around lines 198 - 226, The joinable() check in the init() function is not thread-safe and can result in multiple threads passing the guard and attempting to initialize g_worker_thread simultaneously, causing std::terminate when the second thread's assignment destroys the first thread object. Replace the joinable() guard with a static std::once_flag and wrap the entire initialization logic (from g_start_time assignment through g_worker_thread assignment) inside a std::call_once block to ensure thread-safe one-time initialization of the logging system regardless of concurrent init() calls.
🤖 Prompt for all review comments with AI agents
Verify each finding against current code. Fix only still-valid issues, skip the
rest with a brief reason, keep changes minimal, and validate.
Inline comments:
In `@Engine/cpp/runtime/core/logging/logging.cpp`:
- Around line 362-363: In the execute_fatal function where strncpy is called to
copy text into msg.text, the length parameter should be limited to not exceed
the actual size of the source string. Replace the strncpy call to use
std::min(text.size(), MaxLogMessageLength - 1) as the length parameter instead
of just MaxLogMessageLength - 1. This ensures we never attempt to read past the
bounds of the text string, matching the fix applied to enqueue_log.
- Around line 344-345: The std::strncpy call in the logging message construction
reads from text.data() which is a std::string_view and is not guaranteed to be
null-terminated, risking out-of-bounds reads past the view's actual size.
Replace the strncpy call with memcpy, passing the explicit size from text.size()
and calculating the length to copy as the minimum of text.size() and
(MaxLogMessageLength - 1) to ensure you only copy the actual contents of the
string_view without reading past its boundaries, then explicitly set the null
terminator at the end as currently done.
In `@Engine/cpp/runtime/core/logging/logging.cppm`:
- Around line 98-103: The fatal hook declarations fatal_hook and execute_fatal
are currently exported as part of the public module API within the export
namespace, which unintentionally exposes them for runtime override and weakens
fail-fast guarantees. Move the internal namespace block containing fatal_hook
and execute_fatal declarations out of the export namespace section so they are
no longer part of the exported module surface, or alternatively gate these
declarations behind a test-only API macro to restrict their visibility to
testing code only.
- Around line 4-7: Add explicit includes for symbols that are directly used in
the logging module interface but currently missing from the header section.
Include the `<concepts>` header to support the use of `std::constructible_from`
and include the `<utility>` header to support the use of `std::forward`
throughout the module. These symbols are used in the interface definitions but
relying on transitive includes from other headers like `<format>` is
non-portable and can cause compilation failures across different toolchain
combinations.
---
Outside diff comments:
In `@Engine/cpp/runtime/core/logging/logging.cpp`:
- Around line 198-226: The joinable() check in the init() function is not
thread-safe and can result in multiple threads passing the guard and attempting
to initialize g_worker_thread simultaneously, causing std::terminate when the
second thread's assignment destroys the first thread object. Replace the
joinable() guard with a static std::once_flag and wrap the entire initialization
logic (from g_start_time assignment through g_worker_thread assignment) inside a
std::call_once block to ensure thread-safe one-time initialization of the
logging system regardless of concurrent init() calls.
🪄 Autofix (Beta)
Fix all unresolved CodeRabbit comments on this PR:
- Push a commit to this branch (recommended)
- Create a new PR with the fixes
ℹ️ Review info
⚙️ Run configuration
Configuration used: defaults
Review profile: CHILL
Plan: Pro
Run ID: b101be71-74b6-41d5-9c3b-54ff8a905856
📒 Files selected for processing (4)
Docs/LoggingSinks.mdEngine/cpp/runtime/core/logging/logging.cppEngine/cpp/runtime/core/logging/logging.cppmEngine/cpp/runtime/core/logging/logging.test.cpp
✅ Files skipped from review due to trivial changes (1)
- Docs/LoggingSinks.md
🚧 Files skipped from review as they are similar to previous changes (1)
- Engine/cpp/runtime/core/logging/logging.test.cpp
Shakai-Dev
force-pushed
the
logging-pr
branch
2 times, most recently
from
d9b90b6 to
a0c7815
Compare
| void log(LogVerbosity verbosity, const LogCategory& category, LogFormatString<std::type_identity_t<Args>...> fmt, Args&&... args) noexcept | ||
| { | ||
| char buffer[MaxLogMessageLength]; | ||
| auto result = std::format_to_n(buffer, MaxLogMessageLength - 1, fmt.fmt, std::forward<Args>(args)...); |
There was a problem hiding this comment.
We should probably filter before formatting since otherwise a disabled log would still call std::format_to_n, which could lead to performance problems.
| [[noreturn]] void fatal(const LogCategory& category, LogFormatString<std::type_identity_t<Args>...> fmt, Args&&... args) | ||
| { | ||
| char buffer[MaxLogMessageLength]; | ||
| auto result = std::format_to_n(buffer, MaxLogMessageLength - 1, fmt.fmt, std::forward<Args>(args)...); |
There was a problem hiding this comment.
This one is actually fine because we need fatal to happen, no matter what.
| }; | ||
|
|
||
| template<typename... Args> | ||
| void log(LogVerbosity verbosity, const LogCategory& category, LogFormatString<std::type_identity_t<Args>...> fmt, Args&&... args) noexcept |
There was a problem hiding this comment.
We probably cannot do this right now, but we will want to strip this out for certain builds for shipping so we have absolutely no calls to this.
Side note: We probably want a compile-time value or something for "verbosity" for this specific occasion. if constexpr (Verbosity bla bla bla) in the namespace internal that can do a runtime filter.
| mutable std::atomic<i32> override_verbosity{ -1 }; | ||
| }; | ||
|
|
||
| struct LogMessage |
There was a problem hiding this comment.
These fields are populated on every log, but no sinks reads thread_id or location - Is this intentional?
|
|
||
| m_impl->stream << str; | ||
| m_impl->current_size += str.size(); | ||
| m_impl->stream.flush(); |
There was a problem hiding this comment.
We don't want to flush on every write. It could back up the queue. We should probably flush the same way FileSink does. See: logging.cpp:L428,434
| } | ||
| } | ||
|
|
||
| internal::fatal_hook(); |
There was a problem hiding this comment.
We lose the messages in the queue right before the crash here. We might want to get those drained and written out first because it could end up losing valuable tracing info.
|
|
||
| static u32 get_thread_id() | ||
| { | ||
| return static_cast<u32>(std::hash<std::thread::id>{}(std::this_thread::get_id())); |
There was a problem hiding this comment.
Use the platform-specific thread id. Cache it in a thread_local, so it's only computed once instead of per log.
...Hmm, I also had a thought here. We probably want something in platform that has the thread id and we call from that to this place. Curious about your thoughts @JoltedJon and @OldDev78
There was a problem hiding this comment.
An implementation-aware thread_id part could be moved to platform indeed, but thread-local caching still belongs here.
|
|
||
| FileSink::FileSink(const std::filesystem::path& path) : m_impl(std::make_unique<Impl>()) | ||
| { | ||
| m_impl->stream.open(path, std::ios::out | std::ios::app); |
There was a problem hiding this comment.
The file sinks silently fail if the parent directory does not exist or the file cannot be opened.
| auto parent = base_path.parent_path(); | ||
|
|
||
| std::filesystem::path new_path = parent / (stem + "_" + ss.str() + ext); | ||
| stream.open(new_path, std::ios::out | std::ios::trunc); |
There was a problem hiding this comment.
The file sinks silently fail if the parent directory does not exist or the file cannot be opened.
There was a problem hiding this comment.
Just address @mcdubhghlas comments, and it can be merged.
Optionally, consider adding constexpr flags exports here or in platform to allow ruling out portions of code in the implementation. We actually could use those in more places too.
4 participants
Summary by CodeRabbit
Release Notes
New Features
Tests
Documentation