From 497fb76886bd72a50736e4f4de3c6b8c7b79dd7a Mon Sep 17 00:00:00 2001 From: Myoungho Shin Date: Wed, 29 Jul 2026 22:31:24 -0700 Subject: [PATCH 1/2] fix(build): enforce httplib install export dependency --- CMakeLists.txt | 1 + 1 file changed, 1 insertion(+) diff --git a/CMakeLists.txt b/CMakeLists.txt index a44fc82..e2b70f0 100644 --- a/CMakeLists.txt +++ b/CMakeLists.txt @@ -280,6 +280,7 @@ set(HTTPLIB_COMPILE OFF CACHE BOOL "" FORCE) # satisfies the check. Turning it off fails the whole configure. The price is # cpp-httplib's headers and package files landing in the install prefix; the # fix that removes them is reworking the SDK export, not this switch. +set(HTTPLIB_INSTALL ON CACHE BOOL "" FORCE) FetchContent_MakeAvailable(httplib) find_package(OpenSSL QUIET) From 3c18cf789e435768079b211817d677aea68b85a0 Mon Sep 17 00:00:00 2001 From: Myoungho Shin Date: Wed, 29 Jul 2026 22:31:34 -0700 Subject: [PATCH 2/2] fix(logger): timestamp every non-empty transport window --- include/gpufl/core/logger/file_log_sink.cpp | 61 +++++++++++---------- include/gpufl/core/logger/file_log_sink.hpp | 6 +- tests/core/test_file_log_sink_rotation.cpp | 52 ++++++++++++++++++ 3 files changed, 89 insertions(+), 30 deletions(-) diff --git a/include/gpufl/core/logger/file_log_sink.cpp b/include/gpufl/core/logger/file_log_sink.cpp index 39a9f5a..3023411 100644 --- a/include/gpufl/core/logger/file_log_sink.cpp +++ b/include/gpufl/core/logger/file_log_sink.cpp @@ -58,7 +58,7 @@ FileLogSink::FileChannel::FileChannel(std::string name, Logger::Options opt, FileLogSink::FileChannel::~FileChannel() { close(); } void FileLogSink::FileChannel::close() { - std::lock_guard lk(mu_); + std::lock_guard lk(mu_); closeLocked(); } @@ -92,8 +92,8 @@ void FileLogSink::FileChannel::closeLocked() { bool FileLogSink::FileChannel::isOpen() const { return opened_; } std::uint64_t FileLogSink::FileChannel::currentBytes() const { - std::lock_guard lk(mu_); - return static_cast(current_bytes_); + std::lock_guard lk(mu_); + return current_bytes_; } void FileLogSink::FileChannel::ensureOpenLocked() { @@ -176,7 +176,7 @@ void FileLogSink::FileChannel::rotateLocked(RotateTrigger trigger) { // the active window, so the same index must be retried. ++next_window_index_; const std::uint64_t retired_bytes = - static_cast(current_bytes_); + current_bytes_; if (trigger == RotateTrigger::Size) { ++rotation_stats_.by_size; } else { @@ -219,7 +219,7 @@ void FileLogSink::FileChannel::exportRetired( std::chrono::steady_clock::now() - started) .count(); - std::lock_guard lk(mu_); + std::lock_guard lk(mu_); if (elapsed_ms > rotation_stats_.max_export_ms) { rotation_stats_.max_export_ms = elapsed_ms; } @@ -243,18 +243,18 @@ void FileLogSink::FileChannel::exportRetired( bool FileLogSink::FileChannel::timeDueLocked(const std::int64_t now) const { return opt_.rotate_after_ms > 0 && window_first_write_ms_ >= 0 && - (now - window_first_write_ms_) >= opt_.rotate_after_ms; + now - window_first_write_ms_ >= opt_.rotate_after_ms; } void FileLogSink::FileChannel::rotateIfDue() { - std::lock_guard lk(mu_); + std::lock_guard lk(mu_); if (!opened_) return; if (!timeDueLocked(nowMs())) return; rotateLocked(RotateTrigger::Time); } bool FileLogSink::FileChannel::write(std::string_view line) { - std::lock_guard lk(mu_); + std::lock_guard lk(mu_); if (!opened_) { GFL_LOG_ERROR("Write failed: Channel '", name_, "' is not opened"); return false; @@ -274,8 +274,13 @@ bool FileLogSink::FileChannel::write(std::string_view line) { // wall-time jumps can neither fire nor starve it. This write-path // check gives immediacy on busy channels; quiet channels are covered // by the collector beat calling rotateIfDue(). + // Time-triggered channels need `now` on every write to test the + // deadline. Other channels avoid that hot-path clock read after their + // first write; they still capture one timestamp per non-empty window so + // the immutable transport metadata is complete even when rotation is + // size-only or disabled. const std::int64_t now = - opt_.rotate_after_ms > 0 ? nowMs() : 0; + opt_.rotate_after_ms > 0 ? nowMs() : -1; const bool time_due = timeDueLocked(now); const bool size_due = opt_.rotate_bytes > 0 && @@ -311,15 +316,19 @@ bool FileLogSink::FileChannel::write(std::string_view line) { if (opt_.flush_always) { stream_.flush(); } - if (opt_.rotate_after_ms > 0 && window_first_write_ms_ < 0) { - window_first_write_ms_ = now; + if (window_first_write_ms_ < 0) { + // A size-triggered cutover may have reset the timestamp after `now` + // was conditionally sampled above. In the non-time-triggered case, + // read the monotonic clock here so the new window records its own + // first write rather than 0 or its predecessor's timestamp. + window_first_write_ms_ = now >= 0 ? now : nowMs(); } current_bytes_ += bytesToWrite; return true; } FileLogSink::RotationStats FileLogSink::FileChannel::rotationStats() const { - std::lock_guard lk(mu_); + std::lock_guard lk(mu_); return rotation_stats_; } @@ -389,7 +398,7 @@ FileLogSink::RotationStats FileLogSink::rotationStats() const { std::max(total.max_export_ms, s.max_export_ms); } { - std::lock_guard lk(retire_mu_); + std::lock_guard lk(retire_mu_); total.pending_exports = pending_exports_; total.max_pending_exports = max_pending_exports_; total.pending_export_bytes = pending_export_bytes_; @@ -477,7 +486,7 @@ void FileLogSink::checkSpoolBudget( (max_spool_bytes_ == 0 && min_free_bytes_ == 0)) { return; } - std::lock_guard lk(spool_budget_mu_); + std::lock_guard lk(spool_budget_mu_); if (spool_saturated_.load(std::memory_order_relaxed)) return; const std::int64_t now = spoolNowMs(); // Directory scans are intentionally not on the 250 ms collector cadence. @@ -532,7 +541,7 @@ void FileLogSink::enqueueRetired(FileChannel* channel, const std::uint64_t bytes, const WindowTiming timing) { if (!channel) return; - std::lock_guard lk(retire_mu_); + std::lock_guard lk(retire_mu_); if (retire_stop_) { // Never export inline here: enqueueRetired() is called while the // channel mutex is held, and exportRetired() takes that same mutex to @@ -562,7 +571,7 @@ void FileLogSink::enqueueRetired(FileChannel* channel, for (;;) { RetiredWindow item{}; { - std::unique_lock lk(retire_mu_); + std::unique_lock lk(retire_mu_); retire_cv_.wait(lk, [this] { return retire_stop_ || !retire_queue_.empty(); }); @@ -574,7 +583,7 @@ void FileLogSink::enqueueRetired(FileChannel* channel, // Outside every lock: gzip + publish retries live here. item.channel->exportRetired(item.index, item.timing); { - std::lock_guard lk(retire_mu_); + std::lock_guard lk(retire_mu_); --exports_in_flight_; if (pending_exports_ > 0) --pending_exports_; if (pending_export_bytes_ >= item.bytes) { @@ -591,7 +600,7 @@ void FileLogSink::enqueueRetired(FileChannel* channel, } void FileLogSink::waitForPendingExports() { - std::unique_lock lk(retire_mu_); + std::unique_lock lk(retire_mu_); retire_cv_.wait(lk, [this] { return retire_queue_.empty() && exports_in_flight_ == 0; }); @@ -599,7 +608,7 @@ void FileLogSink::waitForPendingExports() { void FileLogSink::stopRetirementWorker() { { - std::lock_guard lk(retire_mu_); + std::lock_guard lk(retire_mu_); retire_stop_ = true; } retire_cv_.notify_all(); @@ -630,7 +639,7 @@ void FileLogSink::close() { // see it AND keep it in the stats, because everything downstream // (an emptied `.tmp`, a finished upload) now looks like a clean // session. Reporting this onward is the open follow-up. - std::lock_guard lk(retire_mu_); + std::lock_guard lk(retire_mu_); lost_windows_ += static_cast(salvage.lost_windows); GFL_LOG_ERROR("[Logger] session '", session_dir.string(), "': ", salvage.lost_windows, @@ -675,7 +684,7 @@ void FileLogSink::write(Channel ch, std::string_view json) { if (spool_saturated_.load(std::memory_order_acquire)) { dropped_events_.fetch_add(1, std::memory_order_relaxed); dropped_bytes_.fetch_add( - static_cast(json.size() + 1), + json.size() + 1, std::memory_order_relaxed); return; } @@ -686,8 +695,7 @@ void FileLogSink::write(Channel ch, std::string_view json) { (chanSystem_ ? 1 : 0) + (chanSass_ ? 1 : 0)) : (resolveChannel(ch) ? 1u : 0u); if (planned_copies == 0) return; - const std::uint64_t event_bytes = - static_cast(json.size() + 1); + const std::uint64_t event_bytes = json.size() + 1; const std::uint64_t incoming_bytes = event_bytes > std::numeric_limits::max() / planned_copies @@ -734,11 +742,8 @@ void FileLogSink::write(Channel ch, std::string_view json) { } if (copies_written > 0) { const std::uint64_t bytes = - copies_written * static_cast(json.size() + 1); - const std::uint64_t estimated = - spool_estimated_bytes_.fetch_add( - bytes, std::memory_order_relaxed) + - bytes; + copies_written * (json.size() + 1); + spool_estimated_bytes_.fetch_add(bytes, std::memory_order_relaxed); auto available = available_bytes_estimate_.load(std::memory_order_relaxed); while (available != std::numeric_limits::max()) { diff --git a/include/gpufl/core/logger/file_log_sink.hpp b/include/gpufl/core/logger/file_log_sink.hpp index 8c57308..b2d7087 100644 --- a/include/gpufl/core/logger/file_log_sink.hpp +++ b/include/gpufl/core/logger/file_log_sink.hpp @@ -173,8 +173,10 @@ class FileLogSink final : public ILogSink { // destination silently. 0 = not seeded yet. std::size_t next_window_index_ = 0; // Monotonic time of the current window's FIRST write; -1 = the - // window is empty. Drives the rotate_after_ms trigger: an empty - // window has no age, so it can never rotate. + // window is empty. Recorded for every non-empty window so its + // immutable metadata has real timing even when time rotation is + // disabled. It also drives rotate_after_ms: an empty window has no + // age, so it can never rotate. std::int64_t window_first_write_ms_ = -1; RotationStats rotation_stats_; diff --git a/tests/core/test_file_log_sink_rotation.cpp b/tests/core/test_file_log_sink_rotation.cpp index 93203cb..bbc7b8a 100644 --- a/tests/core/test_file_log_sink_rotation.cpp +++ b/tests/core/test_file_log_sink_rotation.cpp @@ -214,6 +214,58 @@ TEST_F(FileLogSinkRotationTest, SizeTriggerStillRotatesAndRecordsSize) { EXPECT_EQ(sink.rotationStats().by_time, 0u); } +TEST_F(FileLogSinkRotationTest, + ShutdownWindowRecordsTimingWhenTimeRotationIsDisabled) { + fake_now_ms_ = 100; + { + gpufl::FileLogSink sink(options(/*rotate_after_ms=*/0)); + sink.write(gpufl::Channel::Device, R"({"event":1})"); + fake_now_ms_ = 5100; + } + + const fs::path metadata = + gpufl::windowMetadataPath(sessionDir(), "device", 1); + ASSERT_TRUE(fs::exists(metadata)); + std::ifstream input(metadata, std::ios::binary); + const std::string json( + (std::istreambuf_iterator(input)), + std::istreambuf_iterator()); + EXPECT_NE(json.find(R"("opened_mono_ms":100)"), std::string::npos); + EXPECT_NE(json.find(R"("closed_mono_ms":5100)"), std::string::npos); +} + +TEST_F(FileLogSinkRotationTest, + SizeRotatedWindowsEachRecordTheirOwnFirstWriteTimestamp) { + fake_now_ms_ = 100; + { + gpufl::FileLogSink sink(options(/*rotate_after_ms=*/0, + /*rotate_bytes=*/64)); + const std::string line(40, 'x'); + sink.write(gpufl::Channel::Device, line); + fake_now_ms_ = 200; + sink.write(gpufl::Channel::Device, line); + sink.waitForPendingExports(); + fake_now_ms_ = 300; + } + + const auto read_metadata = [](const fs::path& path) { + std::ifstream input(path, std::ios::binary); + return std::string( + (std::istreambuf_iterator(input)), + std::istreambuf_iterator()); + }; + const std::string first = read_metadata( + gpufl::windowMetadataPath(sessionDir(), "device", 1)); + const std::string second = read_metadata( + gpufl::windowMetadataPath(sessionDir(), "device", 2)); + ASSERT_FALSE(first.empty()); + ASSERT_FALSE(second.empty()); + EXPECT_NE(first.find(R"("opened_mono_ms":100)"), std::string::npos); + EXPECT_NE(first.find(R"("closed_mono_ms":200)"), std::string::npos); + EXPECT_NE(second.find(R"("opened_mono_ms":200)"), std::string::npos); + EXPECT_NE(second.find(R"("closed_mono_ms":300)"), std::string::npos); +} + TEST_F(FileLogSinkRotationTest, TimeRecordedWhenBothTriggersDue) { gpufl::FileLogSink sink(options(/*rotate_after_ms=*/5000, /*rotate_bytes=*/64));