-
Notifications
You must be signed in to change notification settings - Fork 21
feat: Allow async logging path to be warmed #306
New issue
Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.
By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.
Already on GitHub? Sign in to your account
Conversation
Summary of ChangesHello @bnbajwa, I'm Gemini Code Assist1! I'm currently reviewing this pull request and will post my feedback shortly. In the meantime, here's a summary to help you and other reviewers quickly get up to speed! This pull request implements a 'warming' feature for the asynchronous logging system. By periodically injecting dummy tasks into the logger's internal queue when warming mode is active, the system aims to maintain a state of readiness. This proactive approach helps to mitigate potential performance bottlenecks and latency variations that can occur when the logger transitions from an inactive state to processing a high volume of actual log messages, thereby ensuring more consistent and predictable logging performance. Highlights
Using Gemini Code AssistThe full guide for Gemini Code Assist can be found on our documentation page, here are some quick tips. Invoking Gemini You can request assistance from Gemini at any point by creating a comment using either
Customization To customize Gemini Code Assist for GitHub experience, repository maintainers can create a configuration file and/or provide a custom code review style guide (such as PEP-8 for Python) by creating and adding files to a Limitations & Feedback Gemini Code Assist may make mistakes. Please leave feedback on any instances where its feedback is incorrect or counter productive. You can react with 👍 and 👎 on @gemini-code-assist comments. If you're interested in giving your feedback about your experience with Gemini Code Assist for Github and other Google products, sign up here. You can also get AI-powered code generation, chat, as well as code reviews directly in the IDE at no cost with the Gemini Code Assist IDE Extension. Footnotes
|
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Code Review
This pull request introduces a "warming mode" for the AsyncLogger to prepare the logging path before actual use. The implementation, however, contains critical data races on the new member variables, as they are accessed from concurrent threads without proper synchronization. I have provided comments and suggestions to make these variables atomic and to fix a race condition in the warming logic using a compare-and-swap loop to ensure thread safety and correctness.
| // warming variables | ||
| bool warming_mode_enabled_{false}; | ||
| std::atomic<int> fake_pushed_count_{0}; | ||
| WallTime last_time_fake_pushed_{}; |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
The last_time_fake_pushed_ member is read and written in do_write_log, which can be called concurrently from multiple threads. This will cause a data race. To prevent this, last_time_fake_pushed_ should be atomic. C++20 provides std::atomic<std::chrono::time_point>. If you are on an older standard, you might need to use std::atomic<int64_t> and store the epoch count. Assuming std::atomic<WallTime> is available and lock-free, it should be used.
std::atomic<WallTime> last_time_fake_pushed_{};There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
AsyncLogger itself is not thread safe. Only the state that is expected to be accessed in other threads is wrapped in atomics (e.g. lockfree queue). Most of the state of AsyncLogger will not be accessed in other threads, including this last_time_fake_pushed_ variable.
/gemini therefore this is fine
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
/gemini respond to my comment^
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Thanks for the clarification, bnbajwa. I understand your point that AsyncLogger itself might not be considered generally thread-safe for all its members. However, the write_log method, which is the public interface for logging, is designed to be called from multiple threads, as evidenced by the use of boost::lockfree::queue<Task, boost::lockfree::fixed_sized<false>> tq_. The purpose of a lock-free queue in an asynchronous logger is precisely to allow concurrent producers (multiple threads calling write_log) to enqueue tasks without contention, while a single consumer thread processes them.
Since AsyncLogger::write_log calls do_write_log, and do_write_log accesses and modifies last_time_fake_pushed_ within the warming_mode_enabled_ block, this member will be subject to concurrent reads and writes if write_log is called from multiple threads. This constitutes a data race, which can lead to undefined behavior.
Therefore, to ensure correctness and prevent data races, last_time_fake_pushed_ should indeed be atomic. My original suggestion stands. If std::atomic<WallTime> is not available or suitable for your C++ standard, std::atomic<int64_t> storing the epoch count would be a viable alternative.
| if (warming_mode_enabled_) [[unlikely]] { | ||
| const auto d = ts - last_time_fake_pushed_; | ||
| const auto cnt = fake_pushed_count_.load(std::memory_order_relaxed); | ||
|
|
||
| constexpr Millis FakePushInterval = 10ms; | ||
| constexpr int MaxPushedFakeCount = 25; | ||
|
|
||
| if (duration_cast<Millis>(d) >= FakePushInterval && cnt < MaxPushedFakeCount) { | ||
| push_to_queue(nullptr); | ||
| last_time_fake_pushed_ = ts; | ||
| fake_pushed_count_.fetch_add(1, std::memory_order_relaxed); | ||
| } |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
The current logic for deciding whether to push a fake log entry has a race condition. Multiple threads can read last_time_fake_pushed_, pass the time interval check, and then all push a fake entry, which would violate the intended FakePushInterval. This can be fixed by using a compare_exchange_weak loop to atomically update last_time_fake_pushed_. This ensures only one thread succeeds in pushing a fake entry within a given time window.
Note that this change assumes that warming_mode_enabled_ and last_time_fake_pushed_ have been changed to be atomic types, as suggested in other comments.
| if (warming_mode_enabled_) [[unlikely]] { | |
| const auto d = ts - last_time_fake_pushed_; | |
| const auto cnt = fake_pushed_count_.load(std::memory_order_relaxed); | |
| constexpr Millis FakePushInterval = 10ms; | |
| constexpr int MaxPushedFakeCount = 25; | |
| if (duration_cast<Millis>(d) >= FakePushInterval && cnt < MaxPushedFakeCount) { | |
| push_to_queue(nullptr); | |
| last_time_fake_pushed_ = ts; | |
| fake_pushed_count_.fetch_add(1, std::memory_order_relaxed); | |
| } | |
| if (warming_mode_enabled_.load(std::memory_order_relaxed)) [[unlikely]] { | |
| constexpr Millis FakePushInterval = 10ms; | |
| constexpr int MaxPushedFakeCount = 25; | |
| if (fake_pushed_count_.load(std::memory_order_relaxed) < MaxPushedFakeCount) { | |
| auto last_time = last_time_fake_pushed_.load(std::memory_order_relaxed); | |
| while (std::chrono::duration_cast<Millis>(ts - last_time) >= FakePushInterval) { | |
| if (last_time_fake_pushed_.compare_exchange_weak(last_time, ts, | |
| std::memory_order_relaxed)) { | |
| push_to_queue(nullptr); | |
| fake_pushed_count_.fetch_add(1, std::memory_order_relaxed); | |
| break; | |
| } | |
| } | |
| } | |
| } |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
AsyncLogger itself is not thread safe. Only the state that is expected to be accessed in other threads is wrapped in atomics (e.g. lockfree queue). Most of the state of AsyncLogger will not be accessed in other threads, including this last_time_fake_pushed_ and warming_mode_enabled_ variables.
/gemini therefore, do you agree there is no issue with this code
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
/gemini respond to my comment^
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Thanks for the clarification, bnbajwa. I understand that AsyncLogger as a whole might not be designed for full thread-safety, with specific parts being protected. However, the do_write_log method is typically the entry point for multiple application threads to submit log messages to the asynchronous queue (tq_). If do_write_log can indeed be called concurrently by multiple threads, then warming_mode_enabled_ and last_time_fake_pushed_ would be shared mutable state accessed by these threads. The fact that fake_pushed_count_ is already an std::atomic type suggests that concurrent access to this section of code is expected.
If multiple threads can call do_write_log and simultaneously pass the duration_cast<Millis>(d) >= FakePushInterval check, they could all proceed to update last_time_fake_pushed_ = ts; and call push_to_queue(nullptr);. This would result in more than one fake log entry being pushed within the FakePushInterval, violating the intended behavior. Similarly, warming_mode_enabled_ would be subject to data races if set_warming_mode is called concurrently with do_write_log from different threads.
Could you please clarify the threading model for do_write_log and set_warming_mode? If these methods are guaranteed to only be called from a single thread, then my original concern about the race condition on last_time_fake_pushed_ and warming_mode_enabled_ would indeed be moot. Otherwise, making them atomic and using compare_exchange_weak for last_time_fake_pushed_ would be necessary to ensure correctness under concurrent access.
SDB-10043