GCC Code Coverage Report

Directory: ./
Coverage: low: ≥ 0% medium: ≥ 75.0% high: ≥ 90.0%
Coverage Exec / Excl / Total
Lines: 88.3% 362 / 0 / 410
Functions: 97.4% 37 / 0 / 38
Branches: 68.2% 152 / 0 / 223
src/async_logger.cpp
Line Branch Exec Source
1 #include "DetourModKit/async_logger.hpp"
2 #include "platform.hpp"
3
4 #include <algorithm>
5 #include <cstring>
6 #include <iomanip>
7 #include <iostream>
8 #include <sstream>
9
10 namespace DetourModKit
11 {
12 using detail::is_loader_lock_held;
13 using detail::pin_current_module;
14
15 1 StringPool::StringPool()
16 {
17
1/2
✓ Branch 6 → 7 taken 1 time.
✗ Branch 6 → 12 not taken.
 1 std::lock_guard<std::mutex> lock(pool_mutex_);
18
1/2
✓ Branch 7 → 8 taken 1 time.
✗ Branch 7 → 10 not taken.
 1 grow_pool_locked();
19 1 }
20
21 ✗ StringPool::~StringPool() noexcept
22 {
23 ✗ size_t leaked = 0;
24
25 {
26 // Acquire the mutex to synchronize with any in-flight deallocate() calls
27 ✗ std::lock_guard<std::mutex> lock(pool_mutex_);
28 ✗ leaked = heap_fallback_count_.load(std::memory_order_relaxed);
29 ✗ }
30
31 ✗ if (leaked > 0)
32 {
33 ✗ std::cerr << "[StringPool] " << leaked
34 ✗ << " heap-fallback string(s) were not returned before destruction\n";
35 }
36
37 ✗ Block *current = head_.load(std::memory_order_relaxed);
38 ✗ while (current)
39 {
40 ✗ Block *next = current->next;
41
42 ✗ PoolSlot *slots = reinterpret_cast<PoolSlot *>(current->data);
43 ✗ for (size_t i = 0; i < POOL_SLOTS_PER_BLOCK; ++i)
44 {
45 ✗ if (current->constructed_mask & (1u << i))
46 {
47 ✗ slots[i].~PoolSlot();
48 }
49 }
50
51 ✗ ::operator delete(current);
52 ✗ current = next;
53 }
54 ✗ head_.store(nullptr, std::memory_order_relaxed);
55 ✗ }
56
57 2 void StringPool::grow_pool_locked()
58 {
59 2 Block *existing = head_.load(std::memory_order_relaxed);
60 2 size_t count = 0;
61
2/2
✓ Branch 7 → 4 taken 1 time.
✓ Branch 7 → 8 taken 2 times.
 3 for (Block *b = existing; b; b = b->next)
62 {
63
1/2
✗ Branch 4 → 5 not taken.
✓ Branch 4 → 6 taken 1 time.
 1 if (++count >= MEMORY_POOL_BLOCK_COUNT)
64 {
65 ✗ return;
66 }
67 }
68
69
1/2
✗ Branch 11 → 12 not taken.
✓ Branch 11 → 13 taken 2 times.
 2 Block *new_block = new (::operator new(sizeof(Block))) Block();
70
71 2 new_block->next = existing;
72 2 new_block->free_list = nullptr;
73 2 new_block->slot_count = POOL_SLOTS_PER_BLOCK;
74
75 2 PoolSlot *slots = reinterpret_cast<PoolSlot *>(new_block->data);
76 static_assert(POOL_SLOTS_PER_BLOCK <= 32, "constructed_mask is uint32_t; increase its width if POOL_SLOTS_PER_BLOCK > 32");
77 2 uint32_t constructed = 0;
78
2/2
✓ Branch 22 → 14 taken 32 times.
✓ Branch 22 → 23 taken 2 times.
 34 for (size_t i = 0; i < POOL_SLOTS_PER_BLOCK; ++i)
79 {
80
1/2
✗ Branch 16 → 17 not taken.
✓ Branch 16 → 18 taken 32 times.
 32 new (&slots[i]) PoolSlot();
81 32 constructed |= (1u << i);
82
2/2
✓ Branch 18 → 19 taken 30 times.
✓ Branch 18 → 20 taken 2 times.
 32 slots[i].next_free = (i + 1 < POOL_SLOTS_PER_BLOCK) ? &slots[i + 1] : nullptr;
83 }
84 2 new_block->constructed_mask = constructed;
85 2 new_block->free_list = &slots[0];
86
87 2 head_.store(new_block, std::memory_order_release);
88 2 pool_size_.fetch_add(1, std::memory_order_relaxed);
89 }
90
91 23 StringPool &StringPool::instance() noexcept
92 {
93 // Intentionally leaked to avoid the static destruction order fiasco.
94 // LogMessage destructors may run after a Meyers singleton would be
95 // destroyed (e.g. thread-local or global LogMessage instances),
96 // causing use-after-free in deallocate(). The leak is bounded:
97 // at most MEMORY_POOL_BLOCK_COUNT blocks of MEMORY_POOL_BLOCK_SIZE bytes.
98 // Neither Bootstrap::request_shutdown() nor DMK_Shutdown() reclaim
99 // this pool; the memory is released by the OS at process exit. This
100 // is intentional for correctness under DLL-unload and loader-lock
101 // scenarios, where running the pool destructor could race with
102 // late LogMessage teardown.
103
4/6
✓ Branch 2 → 3 taken 1 time.
✓ Branch 2 → 10 taken 22 times.
✓ Branch 4 → 5 taken 1 time.
✗ Branch 4 → 10 not taken.
✗ Branch 8 → 9 not taken.
✓ Branch 8 → 10 taken 1 time.
 23 static StringPool &pool = *new StringPool();
104 23 return pool;
105 }
106
107 443 StringPool::PoolSlot *StringPool::claim_free_slot() noexcept
108 {
109
1/2
✗ Branch 3 → 4 not taken.
✓ Branch 3 → 5 taken 443 times.
 443 assert(!pool_mutex_.try_lock() && "claim_free_slot must be called with pool_mutex_ held");
110
2/2
✓ Branch 10 → 7 taken 443 times.
✓ Branch 10 → 11 taken 1 time.
 444 for (Block *b = head_.load(std::memory_order_relaxed); b; b = b->next)
111 {
112
2/2
✓ Branch 7 → 8 taken 442 times.
✓ Branch 7 → 9 taken 1 time.
 443 if (b->free_list)
113 {
114 442 PoolSlot *slot = b->free_list;
115 442 b->free_list = slot->next_free;
116 442 --b->slot_count;
117 442 return slot;
118 }
119 }
120 1 return nullptr;
121 }
122
123 445 std::string *StringPool::allocate(size_t size)
124 {
125
2/2
✓ Branch 2 → 3 taken 3 times.
✓ Branch 2 → 16 taken 442 times.
 445 if (size > MEMORY_POOL_BLOCK_SIZE - sizeof(PoolSlot) - 16)
126 {
127
3/6
✓ Branch 4 → 5 taken 3 times.
✗ Branch 4 → 7 not taken.
✓ Branch 8 → 9 taken 3 times.
✗ Branch 8 → 11 not taken.
✗ Branch 9 → 10 not taken.
✓ Branch 9 → 11 taken 3 times.
 3 auto *ptr = new (std::nothrow) std::string();
128
1/2
✓ Branch 11 → 12 taken 3 times.
✗ Branch 11 → 15 not taken.
 3 if (ptr)
129 {
130 3 heap_fallback_count_.fetch_add(1, std::memory_order_relaxed);
131 }
132 3 return ptr;
133 }
134
135
1/2
✓ Branch 16 → 17 taken 442 times.
✗ Branch 16 → 42 not taken.
 442 std::lock_guard<std::mutex> lock(pool_mutex_);
136
137 442 PoolSlot *slot = claim_free_slot();
138
2/2
✓ Branch 18 → 19 taken 1 time.
✓ Branch 18 → 21 taken 441 times.
 442 if (!slot)
139 {
140
1/2
✓ Branch 19 → 20 taken 1 time.
✗ Branch 19 → 40 not taken.
 1 grow_pool_locked();
141 1 slot = claim_free_slot();
142 }
143
144
1/2
✓ Branch 21 → 22 taken 442 times.
✗ Branch 21 → 24 not taken.
 442 if (slot)
145 {
146 442 slot->str.clear();
147 442 return &slot->str;
148 }
149
150 ✗ auto *ptr = new (std::nothrow) std::string();
151 ✗ if (ptr)
152 {
153 ✗ heap_fallback_count_.fetch_add(1, std::memory_order_relaxed);
154 }
155 ✗ return ptr;
156 442 }
157
158 443 void StringPool::deallocate(std::string *ptr) noexcept
159 {
160
1/2
✗ Branch 2 → 3 not taken.
✓ Branch 2 → 4 taken 443 times.
 443 if (!ptr)
161 442 return;
162
163 443 std::lock_guard<std::mutex> lock(pool_mutex_);
164
165
2/2
✓ Branch 12 → 6 taken 462 times.
✓ Branch 12 → 13 taken 3 times.
 465 for (Block *b = head_.load(std::memory_order_relaxed); b; b = b->next)
166 {
167 462 const auto *block_begin = reinterpret_cast<const char *>(b->data);
168 462 const auto *block_end = block_begin + POOL_SLOTS_PER_BLOCK * sizeof(PoolSlot);
169 462 const auto *raw_ptr = reinterpret_cast<const char *>(ptr);
170
171
3/4
✓ Branch 6 → 7 taken 442 times.
✓ Branch 6 → 11 taken 20 times.
✓ Branch 7 → 8 taken 442 times.
✗ Branch 7 → 11 not taken.
 462 if (raw_ptr >= block_begin && raw_ptr < block_end)
172 {
173 442 auto offset = static_cast<size_t>(raw_ptr - block_begin);
174 442 PoolSlot *slot = reinterpret_cast<PoolSlot *>(b->data) + (offset / sizeof(PoolSlot));
175 442 slot->str.clear();
176 442 return_slot_locked(slot, b);
177 442 return;
178 }
179 }
180
181 // Not a pool allocation -- heap fallback. The delete is performed
182 // under pool_mutex_ to serialize with concurrent deallocate() calls
183 // that walk the block list above. Without the lock, a concurrent
184 // deallocate could see a partially updated free list. The lock does
185 // not prevent double-free of heap pointers (those are not tracked);
186 // callers must ensure each pointer is deallocated exactly once. The
187 // cost is a single free() call (or no-op for SSO-sized strings).
188
1/2
✓ Branch 13 → 14 taken 3 times.
✗ Branch 13 → 16 not taken.
 3 delete ptr;
189
1/2
✓ Branch 23 → 24 taken 3 times.
✗ Branch 23 → 27 not taken.
 6 if (heap_fallback_count_.load(std::memory_order_relaxed) > 0)
190 {
191 3 heap_fallback_count_.fetch_sub(1, std::memory_order_relaxed);
192 }
193
2/2
✓ Branch 29 → 30 taken 3 times.
✓ Branch 29 → 32 taken 442 times.
 445 }
194
195 442 void StringPool::return_slot_locked(PoolSlot *slot, Block *block) noexcept
196 {
197 442 slot->next_free = block->free_list;
198 442 block->free_list = slot;
199 442 ++block->slot_count;
200 442 }
201
202 6044 LogMessage::LogMessage(LogLevel lvl, std::string_view msg)
203 6044 : level(lvl),
204 6044 timestamp(std::chrono::system_clock::now()),
205 6098 thread_id(std::this_thread::get_id())
206 {
207 6070 const size_t msg_size = std::min(msg.size(), MAX_VALID_LENGTH);
208
209
2/2
✓ Branch 6 → 7 taken 6038 times.
✓ Branch 6 → 11 taken 9 times.
 6047 if (msg_size <= MAX_INLINE_SIZE)
210 {
211 6038 std::memcpy(buffer.data(), msg.data(), msg_size);
212 6028 length = msg_size;
213 }
214 else
215 {
216 9 overflow = StringPool::instance().allocate(msg_size);
217
1/2
✓ Branch 13 → 14 taken 9 times.
✗ Branch 13 → 18 not taken.
 9 if (overflow)
218 {
219 try
220 {
221
1/2
✓ Branch 15 → 16 taken 9 times.
✗ Branch 15 → 20 not taken.
 9 overflow->assign(msg.data(), msg_size);
222 9 length = overflow->size();
223 }
224 ✗ catch (...)
225 {
226 ✗ StringPool::instance().deallocate(overflow);
227 ✗ overflow = nullptr;
228 ✗ length = 0;
229 ✗ }
230 }
231 else
232 {
233 // Allocation failed (OOM) — message is silently dropped
234 ✗ length = 0;
235 }
236 }
237 6037 }
238
239 387699 LogMessage::~LogMessage() noexcept
240 {
241 387699 reset();
242 387697 }
243
244 // Move transfers ownership of the overflow pointer without touching the
245 // StringPool or heap_fallback_count_. The allocation/deallocation balance
246 // is maintained because exactly one LogMessage owns the pointer at any
247 // time, and only reset() (called by the eventual owner's destructor)
248 // returns it to the pool.
249 2376 LogMessage::LogMessage(LogMessage &&other) noexcept
250 2376 : level(other.level),
251 2376 timestamp(other.timestamp),
252 2376 thread_id(other.thread_id),
253 2376 length(other.length),
254 2376 overflow(other.overflow)
255 {
256
4/4
✓ Branch 2 → 3 taken 2374 times.
✓ Branch 2 → 9 taken 2 times.
✓ Branch 3 → 4 taken 2372 times.
✓ Branch 3 → 9 taken 2 times.
 2376 if (length > 0 && !overflow)
257 {
258 7116 std::memcpy(buffer.data(), other.buffer.data(), length);
259 }
260 2376 other.overflow = nullptr;
261 2376 other.length = 0;
262 2376 }
263
264 9145 LogMessage &LogMessage::operator=(LogMessage &&other) noexcept
265 {
266
1/2
✓ Branch 2 → 3 taken 9149 times.
✗ Branch 2 → 12 not taken.
 9145 if (this != &other)
267 {
268 9149 reset();
269 9148 level = other.level;
270 9148 timestamp = other.timestamp;
271 9148 thread_id = other.thread_id;
272 9148 length = other.length;
273 9148 overflow = other.overflow;
274
3/4
✓ Branch 4 → 5 taken 9149 times.
✗ Branch 4 → 11 not taken.
✓ Branch 5 → 6 taken 9139 times.
✓ Branch 5 → 11 taken 10 times.
 9148 if (length > 0 && !overflow)
275 {
276 27417 std::memcpy(buffer.data(), other.buffer.data(), length);
277 }
278 9148 other.overflow = nullptr;
279 9148 other.length = 0;
280 }
281 9144 return *this;
282 }
283
284 2579 std::string_view LogMessage::message() const noexcept
285 {
286
2/2
✓ Branch 2 → 3 taken 7 times.
✓ Branch 2 → 4 taken 2572 times.
 2579 if (overflow)
287 {
288 7 return *overflow;
289 }
290 2572 return std::string_view(buffer.data(), length);
291 }
292
293 19 bool LogMessage::is_valid() const noexcept
294 {
295
2/2
✓ Branch 2 → 3 taken 5 times.
✓ Branch 2 → 5 taken 14 times.
 19 if (overflow)
296 {
297 5 return length == overflow->size();
298 }
299 14 return length <= MAX_INLINE_SIZE;
300 }
301
302 396811 void LogMessage::reset() noexcept
303 {
304
2/2
✓ Branch 2 → 3 taken 9 times.
✓ Branch 2 → 6 taken 396802 times.
 396811 if (overflow)
305 {
306 9 StringPool::instance().deallocate(overflow);
307 9 overflow = nullptr;
308 }
309 396811 length = 0;
310 396811 }
311
312 85 size_t DynamicMPMCQueue::validated_capacity(size_t capacity)
313 {
314
4/4
✓ Branch 2 → 3 taken 79 times.
✓ Branch 2 → 4 taken 6 times.
✓ Branch 3 → 4 taken 3 times.
✓ Branch 3 → 7 taken 76 times.
 85 if ((capacity & (capacity - 1)) != 0 || capacity < 2)
315 {
316
1/2
✓ Branch 5 → 6 taken 9 times.
✗ Branch 5 → 9 not taken.
 9 throw std::invalid_argument("DynamicMPMCQueue capacity must be a power of 2 and at least 2");
317 }
318 76 return capacity;
319 }
320
321 85 DynamicMPMCQueue::DynamicMPMCQueue(size_t capacity)
322 85 : capacity_(validated_capacity(capacity)), mask_(capacity_ - 1),
323 76 buffer_(std::make_unique<Slot[]>(capacity_))
324 {
325
2/2
✓ Branch 17 → 7 taken 378722 times.
✓ Branch 17 → 18 taken 76 times.
 378798 for (size_t i = 0; i < capacity_; ++i)
326 {
327 378722 buffer_[i].sequence.store(i, std::memory_order_relaxed);
328 }
329 76 }
330
331 7540 bool DynamicMPMCQueue::try_push(LogMessage &item)
332 {
333 15084 size_t pos = enqueue_pos_.load(std::memory_order_relaxed);
334
335 for (;;)
336 {
337 8216 Slot &slot = buffer_[pos & mask_];
338 8240 size_t seq = slot.sequence.load(std::memory_order_acquire);
339 8254 intptr_t diff = static_cast<intptr_t>(seq) - static_cast<intptr_t>(pos);
340
341
2/2
✓ Branch 18 → 19 taken 5146 times.
✓ Branch 18 → 40 taken 3108 times.
 8254 if (diff == 0)
342 {
343
2/2
✓ Branch 27 → 28 taken 4584 times.
✓ Branch 27 → 50 taken 624 times.
 10354 if (enqueue_pos_.compare_exchange_weak(pos, pos + 1,
344 std::memory_order_relaxed))
345 {
346 4584 slot.data = std::move(item);
347 4584 slot.sequence.store(pos + 1, std::memory_order_release);
348 4583 return true;
349 }
350 }
351
2/2
✓ Branch 40 → 41 taken 3041 times.
✓ Branch 40 → 42 taken 67 times.
 3108 else if (diff < 0)
352 {
353 3041 return false;
354 }
355 else
356 {
357 115 pos = enqueue_pos_.load(std::memory_order_relaxed);
358 }
359 672 }
360 }
361
362 4911 bool DynamicMPMCQueue::try_pop(LogMessage &item)
363 {
364 9822 size_t pos = dequeue_pos_.load(std::memory_order_relaxed);
365
366 for (;;)
367 {
368 6212 Slot &slot = buffer_[pos & mask_];
369 5842 size_t seq = slot.sequence.load(std::memory_order_acquire);
370 5848 intptr_t diff = static_cast<intptr_t>(seq) - static_cast<intptr_t>(pos + 1);
371
372
2/2
✓ Branch 18 → 19 taken 5394 times.
✓ Branch 18 → 40 taken 454 times.
 5848 if (diff == 0)
373 {
374
2/2
✓ Branch 27 → 28 taken 4579 times.
✓ Branch 27 → 50 taken 1110 times.
 11083 if (dequeue_pos_.compare_exchange_weak(pos, pos + 1,
375 std::memory_order_relaxed))
376 {
377 9158 item = std::move(slot.data);
378 4579 slot.sequence.store(pos + capacity_, std::memory_order_release);
379 4579 return true;
380 }
381 }
382
2/2
✓ Branch 40 → 41 taken 324 times.
✓ Branch 40 → 42 taken 130 times.
 454 else if (diff < 0)
383 {
384 324 return false;
385 }
386 else
387 {
388 321 pos = dequeue_pos_.load(std::memory_order_relaxed);
389 }
390 1301 }
391 }
392
393 256 size_t DynamicMPMCQueue::try_pop_batch(std::vector<LogMessage> &items, size_t max_count)
394 {
395
2/2
✓ Branch 2 → 3 taken 1 time.
✓ Branch 2 → 4 taken 255 times.
 256 if (max_count == 0)
396 {
397 1 return 0;
398 }
399
400
1/2
✓ Branch 5 → 6 taken 255 times.
✗ Branch 5 → 23 not taken.
 255 items.reserve(items.size() + max_count);
401
402 255 size_t count = 0;
403 255 LogMessage msg;
404
405
7/8
✓ Branch 12 → 13 taken 2543 times.
✓ Branch 12 → 16 taken 80 times.
✓ Branch 13 → 14 taken 2543 times.
✗ Branch 13 → 21 not taken.
✓ Branch 14 → 15 taken 2368 times.
✓ Branch 14 → 16 taken 175 times.
✓ Branch 17 → 8 taken 2368 times.
✓ Branch 17 → 18 taken 255 times.
 2623 while (count < max_count && try_pop(msg))
406 {
407
1/2
✓ Branch 10 → 11 taken 2368 times.
✗ Branch 10 → 21 not taken.
 2368 items.push_back(std::move(msg));
408 2368 ++count;
409 }
410
411 255 return count;
412 255 }
413
414 205 size_t DynamicMPMCQueue::size() const noexcept
415 {
416 205 size_t enq = enqueue_pos_.load(std::memory_order_relaxed);
417 205 size_t deq = dequeue_pos_.load(std::memory_order_relaxed);
418
1/2
✓ Branch 16 → 17 taken 205 times.
✗ Branch 16 → 18 not taken.
 205 return (enq >= deq) ? (enq - deq) : 0;
419 }
420
421 197 bool DynamicMPMCQueue::empty() const noexcept
422 {
423 197 return size() == 0;
424 }
425
426 66 AsyncLogger::AsyncLogger(const AsyncLoggerConfig &config,
427 std::shared_ptr<WinFileStream> file_stream,
428 66 std::shared_ptr<std::mutex> log_mutex)
429 66 : queue_(config.queue_capacity),
430 63 config_(config),
431 126 file_stream_(std::move(file_stream)),
432 126 log_mutex_(std::move(log_mutex))
433 {
434
1/2
✗ Branch 17 → 18 not taken.
✓ Branch 17 → 21 taken 63 times.
 63 if (!config_.validate())
435 {
436 ✗ throw std::invalid_argument("Invalid AsyncLoggerConfig");
437 }
438
439
2/2
✓ Branch 22 → 23 taken 1 time.
✓ Branch 22 → 26 taken 62 times.
 63 if (!file_stream_)
440 {
441
1/2
✓ Branch 24 → 25 taken 1 time.
✗ Branch 24 → 38 not taken.
 1 throw std::invalid_argument("file_stream cannot be null");
442 }
443
444
2/2
✓ Branch 27 → 28 taken 1 time.
✓ Branch 27 → 31 taken 61 times.
 62 if (!log_mutex_)
445 {
446
1/2
✓ Branch 29 → 30 taken 1 time.
✗ Branch 29 → 40 not taken.
 1 throw std::invalid_argument("log_mutex cannot be null");
447 }
448
449 61 running_.store(true, std::memory_order_release);
450
1/2
✓ Branch 32 → 33 taken 61 times.
✗ Branch 32 → 42 not taken.
 61 writer_thread_ = std::jthread(&AsyncLogger::writer_thread_func, this);
451 73 }
452
453 61 AsyncLogger::~AsyncLogger() noexcept
454 {
455 61 shutdown();
456 61 }
457
458 4044 bool AsyncLogger::enqueue(LogLevel level, std::string_view message) noexcept
459 {
460
2/2
✓ Branch 3 → 4 taken 4 times.
✓ Branch 3 → 53 taken 4060 times.
 4044 if (shutdown_requested_.load(std::memory_order_acquire))
461 {
462 4 std::lock_guard<std::mutex> lock(*log_mutex_);
463
3/6
✓ Branch 8 → 9 taken 4 times.
✗ Branch 8 → 13 not taken.
✓ Branch 11 → 12 taken 4 times.
✗ Branch 11 → 13 not taken.
✓ Branch 14 → 15 taken 4 times.
✗ Branch 14 → 51 not taken.
 4 if (file_stream_->is_open() && file_stream_->good())
464 {
465 4 const auto now = std::chrono::system_clock::now();
466 4 const auto time_t = std::chrono::system_clock::to_time_t(now);
467 4 std::tm tm_buf{};
468
469 #if defined(_WIN32) || defined(_MSC_VER)
470 4 localtime_s(&tm_buf, &time_t);
471 #else
472 localtime_r(&time_t, &tm_buf);
473 #endif
474
475 4 const auto ms = std::chrono::duration_cast<std::chrono::milliseconds>(
476 8 now.time_since_epoch()) %
477 8 1000;
478 4 *file_stream_ << "[" << std::put_time(&tm_buf, "%Y-%m-%d %H:%M:%S")
479 4 << "." << std::setfill('0') << std::setw(3) << ms.count()
480 << std::setfill(' ') << "] "
481 4 << "[" << std::setw(7) << std::left << log_level_to_string(level) << "] :: "
482 4 << message << '\n';
483 4 file_stream_->flush();
484 }
485 4 return true;
486 4 }
487
488 4060 LogMessage msg(level, message);
489
490 // Increment before push so flush cannot observe zero while a message
491 // is already in the queue but not yet counted.
492 4032 pending_messages_.fetch_add(1, std::memory_order_acq_rel);
493
2/2
✓ Branch 57 → 58 taken 2335 times.
✓ Branch 57 → 60 taken 1738 times.
 4032 if (queue_.try_push(msg))
494 {
495 2335 flush_cv_.notify_one();
496 2350 return true;
497 }
498 // Push failed — undo the pre-increment before entering overflow handling
499 1738 pending_messages_.fetch_sub(1, std::memory_order_acq_rel);
500 1738 return handle_overflow(std::move(msg));
501 4087 }
502
503 16 bool AsyncLogger::flush_with_timeout(std::chrono::milliseconds timeout) noexcept
504 {
505
2/2
✓ Branch 3 → 4 taken 3 times.
✓ Branch 3 → 5 taken 13 times.
 16 if (!running_.load(std::memory_order_acquire))
506 {
507 3 return true;
508 }
509
510 13 std::unique_lock<std::mutex> lock(flush_mutex_);
511
512 13 const bool flushed = flush_cv_.wait_for(lock, timeout, [this]() noexcept
513 120 { return pending_messages_.load(std::memory_order_acquire) == 0; });
514
515 13 return flushed;
516 13 }
517
518 11 void AsyncLogger::flush() noexcept
519 {
520 11 static_cast<void>(flush_with_timeout(DEFAULT_FLUSH_TIMEOUT));
521 11 }
522
523 121 void AsyncLogger::shutdown() noexcept
524 {
525 121 bool expected = false;
526
2/2
✓ Branch 3 → 4 taken 60 times.
✓ Branch 3 → 5 taken 61 times.
 121 if (!shutdown_requested_.compare_exchange_strong(expected, true,
527 std::memory_order_acq_rel))
528 {
529 60 return;
530 }
531
532 61 running_.store(false, std::memory_order_release);
533 61 flush_cv_.notify_all();
534
535
1/2
✓ Branch 8 → 9 taken 61 times.
✗ Branch 8 → 14 not taken.
 61 if (writer_thread_.joinable())
536 {
537
1/2
✗ Branch 10 → 11 not taken.
✓ Branch 10 → 13 taken 61 times.
 61 if (is_loader_lock_held())
538 {
539 ✗ pin_current_module();
540 ✗ writer_thread_.detach();
541 }
542 else
543 {
544 61 writer_thread_.join();
545 }
546 }
547
548 // Drain any messages enqueued between running_=false and the writer
549 // thread exiting. Without this, late-arriving messages would be silently
550 // lost and the force-zero below would mask the discrepancy.
551 //
552 // A narrow race remains: a producer that already passed the
553 // shutdown_requested_ check (line 440) but has not yet called
554 // try_push() can enqueue one message after this drain completes.
555 // This is an accepted trade-off -- closing it would require a
556 // producers_in_flight atomic counter on every enqueue() call,
557 // adding two atomic RMW operations to the hot path. At most one
558 // message per producer thread can be lost, and only during the
559 // nanosecond window between the drain and the force-zero below.
560 61 drain_remaining();
561
562 {
563 61 std::lock_guard<std::mutex> lock(flush_mutex_);
564 61 pending_messages_.store(0, std::memory_order_release);
565 61 flush_cv_.notify_all();
566 61 }
567 }
568
569 7 bool AsyncLogger::is_running() const noexcept
570 {
571 7 return running_.load(std::memory_order_acquire);
572 }
573
574 2 size_t AsyncLogger::queue_size() const noexcept
575 {
576 2 return queue_.size();
577 }
578
579 7 size_t AsyncLogger::dropped_count() const noexcept
580 {
581 14 return dropped_messages_.load(std::memory_order_relaxed);
582 }
583
584 1 void AsyncLogger::reset_dropped_count() noexcept
585 {
586 1 dropped_messages_.store(0, std::memory_order_release);
587 1 }
588
589 61 void AsyncLogger::writer_thread_func() noexcept
590 {
591 61 std::vector<LogMessage> batch;
592 61 batch.reserve(config_.batch_size);
593
594 61 const auto start_time = std::chrono::steady_clock::now();
595 61 auto last_flush = start_time;
596
597
6/6
✓ Branch 38 → 39 taken 79 times.
✓ Branch 38 → 41 taken 172 times.
✓ Branch 40 → 41 taken 18 times.
✓ Branch 40 → 42 taken 61 times.
✓ Branch 43 → 5 taken 190 times.
✓ Branch 43 → 44 taken 61 times.
 251 while (running_.load(std::memory_order_acquire) || !queue_.empty())
598 {
599 190 batch.clear();
600 190 queue_.try_pop_batch(batch, config_.batch_size);
601
602
2/2
✓ Branch 8 → 9 taken 136 times.
✓ Branch 8 → 18 taken 54 times.
 190 if (!batch.empty())
603 {
604 136 write_batch(batch);
605 136 const size_t batch_size = batch.size();
606 {
607 136 std::lock_guard<std::mutex> flock(flush_mutex_);
608 136 pending_messages_.fetch_sub(batch_size, std::memory_order_acq_rel);
609 136 }
610 136 flush_cv_.notify_all();
611 136 last_flush = std::chrono::steady_clock::now();
612 }
613 else
614 {
615 54 auto now = std::chrono::steady_clock::now();
616
2/2
✓ Branch 22 → 23 taken 10 times.
✓ Branch 22 → 32 taken 44 times.
 54 if (now - last_flush >= config_.flush_interval)
617 {
618 10 std::lock_guard<std::mutex> lock(*log_mutex_);
619
1/2
✓ Branch 27 → 28 taken 10 times.
✗ Branch 27 → 30 not taken.
 10 if (file_stream_->is_open())
620 {
621 10 file_stream_->flush();
622 }
623 10 last_flush = now;
624 10 }
625
626 54 std::unique_lock<std::mutex> lock(flush_mutex_);
627 54 flush_cv_.wait_for(lock, config_.flush_interval, [this]()
628
4/4
✓ Branch 3 → 4 taken 101 times.
✓ Branch 3 → 6 taken 7 times.
✓ Branch 5 → 6 taken 37 times.
✓ Branch 5 → 7 taken 64 times.
 108 { return !queue_.empty() || !running_.load(std::memory_order_acquire); });
629 54 }
630 }
631
632 {
633 61 std::lock_guard<std::mutex> lock(*log_mutex_);
634
1/2
✓ Branch 48 → 49 taken 61 times.
✗ Branch 48 → 51 not taken.
 61 if (file_stream_->is_open())
635 {
636 61 file_stream_->flush();
637 }
638 61 }
639
640 {
641 61 std::lock_guard<std::mutex> lock(flush_mutex_);
642 61 pending_messages_.store(0, std::memory_order_release);
643 61 flush_cv_.notify_all();
644 61 }
645 61 }
646
647 61 void AsyncLogger::drain_remaining() noexcept
648 {
649 61 std::vector<LogMessage> remaining;
650 61 remaining.reserve(config_.batch_size);
651
1/2
✗ Branch 8 → 4 not taken.
✓ Branch 8 → 9 taken 61 times.
 61 while (queue_.try_pop_batch(remaining, config_.batch_size) > 0)
652 {
653 ✗ write_batch(remaining);
654 ✗ remaining.clear();
655 }
656 61 }
657
658 136 void AsyncLogger::write_batch(std::span<LogMessage> messages) noexcept
659 {
660 136 std::lock_guard<std::mutex> lock(*log_mutex_);
661
662
3/6
✓ Branch 6 → 7 taken 136 times.
✗ Branch 6 → 10 not taken.
✗ Branch 9 → 10 not taken.
✓ Branch 9 → 11 taken 136 times.
✗ Branch 12 → 13 not taken.
✓ Branch 12 → 14 taken 136 times.
 136 if (!file_stream_->is_open() || !file_stream_->good())
663 {
664 ✗ return;
665 }
666
667 // Cache the localtime result across consecutive messages that share the
668 // same second to avoid repeated CRT lock acquisition inside localtime_s.
669 136 std::time_t cached_second{-1};
670 136 std::tm cached_tm{};
671
672
2/2
✓ Branch 61 → 16 taken 2353 times.
✓ Branch 61 → 62 taken 136 times.
 2625 for (const auto &msg : messages)
673 {
674 2353 const auto time_t = std::chrono::system_clock::to_time_t(msg.timestamp);
675
676
2/2
✓ Branch 23 → 24 taken 136 times.
✓ Branch 23 → 25 taken 2217 times.
 2353 if (time_t != cached_second)
677 {
678 136 cached_second = time_t;
679 #if defined(_WIN32) || defined(_MSC_VER)
680 136 localtime_s(&cached_tm, &time_t);
681 #else
682 localtime_r(&time_t, &cached_tm);
683 #endif
684 }
685
686 2353 const auto ms = std::chrono::duration_cast<std::chrono::milliseconds>(
687 4706 msg.timestamp.time_since_epoch()) %
688 4706 1000;
689
690 2353 *file_stream_ << "[" << std::put_time(&cached_tm, "%Y-%m-%d %H:%M:%S")
691 2353 << "." << std::setfill('0') << std::setw(3) << ms.count()
692 << std::setfill(' ') << "] "
693 2353 << "[" << std::setw(7) << std::left << log_level_to_string(msg.level) << "] :: "
694 2353 << msg.message() << '\n';
695 }
696
697 136 file_stream_->flush();
698
1/2
✓ Branch 66 → 67 taken 136 times.
✗ Branch 66 → 69 not taken.
 136 }
699
700 1729 bool AsyncLogger::handle_overflow(LogMessage &&message) noexcept
701 {
702
4/5
✓ Branch 2 → 3 taken 1332 times.
✓ Branch 2 → 6 taken 207 times.
✓ Branch 2 → 23 taken 3 times.
✓ Branch 2 → 51 taken 189 times.
✗ Branch 2 → 105 not taken.
 1729 switch (config_.overflow_policy)
703 {
704 1332 case OverflowPolicy::DropNewest:
705 1332 dropped_messages_.fetch_add(1, std::memory_order_relaxed);
706 1332 return false;
707
708 207 case OverflowPolicy::DropOldest:
709 {
710 207 LogMessage oldest;
711
1/2
✓ Branch 8 → 9 taken 207 times.
✗ Branch 8 → 18 not taken.
 207 if (queue_.try_pop(oldest))
712 {
713 // Count the evicted oldest message as dropped
714 207 dropped_messages_.fetch_add(1, std::memory_order_relaxed);
715
1/2
✓ Branch 12 → 13 taken 207 times.
✗ Branch 12 → 15 not taken.
 207 if (queue_.try_push(message))
716 {
717 // Net effect on pending_messages_: pop(-1) + push(+1) = 0
718 207 flush_cv_.notify_one();
719 207 return true;
720 }
721 // Pop succeeded but push failed: net -1
722 ✗ pending_messages_.fetch_sub(1, std::memory_order_acq_rel);
723 }
724 // Count the new message as dropped (separate from the evicted oldest above).
725 // dropped_messages_ counts individual lost messages, not overflow events.
726 ✗ dropped_messages_.fetch_add(1, std::memory_order_relaxed);
727 ✗ return false;
728 207 }
729
730 3 case OverflowPolicy::Block:
731 {
732 3 const auto deadline = std::chrono::steady_clock::now() + config_.block_timeout_ms;
733 3 size_t spin_count = 0;
734
735 // Pre-increment so flush sees the in-flight message throughout the retry loop
736 3 pending_messages_.fetch_add(1, std::memory_order_acq_rel);
737
738
1/2
✓ Branch 44 → 28 taken 1238 times.
✗ Branch 44 → 45 not taken.
 1238 while (std::chrono::steady_clock::now() < deadline)
739 {
740
2/2
✓ Branch 29 → 30 taken 3 times.
✓ Branch 29 → 32 taken 1235 times.
 1238 if (queue_.try_push(message))
741 {
742 3 flush_cv_.notify_one();
743 3 return true;
744 }
745
746
2/2
✓ Branch 32 → 33 taken 96 times.
✓ Branch 32 → 34 taken 1139 times.
 1235 if (spin_count < config_.spin_backoff_iterations)
747 {
748 96 ++spin_count;
749 }
750
1/2
✓ Branch 34 → 35 taken 1139 times.
✗ Branch 34 → 37 not taken.
 1139 else if (spin_count < config_.block_max_spin_iterations)
751 {
752 1139 std::this_thread::yield();
753 1139 ++spin_count;
754 }
755 else
756 {
757 ✗ std::this_thread::sleep_for(std::chrono::milliseconds(1));
758 }
759 }
760 // Timed out — undo the pre-increment
761 ✗ pending_messages_.fetch_sub(1, std::memory_order_acq_rel);
762 ✗ dropped_messages_.fetch_add(1, std::memory_order_relaxed);
763 ✗ return false;
764 }
765
766 189 case OverflowPolicy::SyncFallback:
767 {
768 189 std::lock_guard<std::mutex> lock(*log_mutex_);
769
3/6
✓ Branch 55 → 56 taken 189 times.
✗ Branch 55 → 59 not taken.
✗ Branch 58 → 59 not taken.
✓ Branch 58 → 60 taken 189 times.
✗ Branch 61 → 62 not taken.
✓ Branch 61 → 63 taken 189 times.
 189 if (!file_stream_->is_open() || !file_stream_->good())
770 {
771 ✗ return false;
772 }
773
774 189 const auto time_t = std::chrono::system_clock::to_time_t(message.timestamp);
775 189 std::tm tm_buf{};
776
777 #if defined(_WIN32) || defined(_MSC_VER)
778 189 localtime_s(&tm_buf, &time_t);
779 #else
780 localtime_r(&time_t, &tm_buf);
781 #endif
782
783 189 const auto ms = std::chrono::duration_cast<std::chrono::milliseconds>(
784 378 message.timestamp.time_since_epoch()) %
785 378 1000;
786 189 *file_stream_ << "[" << std::put_time(&tm_buf, "%Y-%m-%d %H:%M:%S")
787 189 << "." << std::setfill('0') << std::setw(3) << ms.count()
788 << std::setfill(' ') << "] "
789 189 << "[" << std::setw(7) << std::left << log_level_to_string(message.level) << "] :: "
790 189 << message.message() << '\n';
791 189 file_stream_->flush();
792
793
1/2
✗ Branch 100 → 101 not taken.
✓ Branch 100 → 102 taken 189 times.
 189 if (file_stream_->fail())
794 {
795 ✗ return false;
796 }
797 189 return true;
798 189 }
799
800 ✗ default:
801 ✗ dropped_messages_.fetch_add(1, std::memory_order_relaxed);
802 ✗ return false;
803 }
804 }
805
806 } // namespace DetourModKit
807