feat(native): collector logging parity — built-in file logger + events + tests

[lotgon]

Brings the native collector's logging toward parity with the managed HSMDataCollector, for tt-aggregator2's native adapter (they miss the .NET logs).

This PR (framework + first events):

• FileLogger: async, date-rolling built-in file sink (DataCollector_<UTC-date>.txt + _error_, yyyy-MM-dd HH:mm:ss|LEVEL| message), drains on shutdown.
• hsm_collector_enable_file_logging (C ABI) + Collector::EnableFileLogging (C++) - complements SetLogger; both sinks get every message.
• Info lifecycle logs via NotifyLifecycle.

Still to add (same PR): sensor-registration / send-failure+retry (attempt#/HTTP code) / runtime queue-drop / value-rejection events, unit tests, and feature.md. Opening now to get the native build/conformance/sanitizers lanes on the framework code.

🤖 Generated with Claude Code

[github-actions]

PR #1221 Review — Native collector file logging

Overall this is a clean, well-structured addition. The FileLogger worker/queue design is sound, the drain-before-join in the destructor is correct, and the Run() loop's lock discipline (swap batch under lock, write outside, re-check stop+empty under lock) is race-free. The teardown-safety reasoning for the raw pointer in LogMessage is valid. A few points below, ordered by severity.

1. (Medium) Use-after-free window if EnableFileLogging is called after Start()

LogMessage snapshots a raw FileLogger* under logger_mutex_, releases the lock, then calls file_logger->Enqueue(...) outside the lock (hsm_collector.cpp:3581-3588). EnableFileLogging moves the previous sink into old and destroys it (drain + join) outside logger_mutex_ (hsm_collector.cpp:2683-2689). If a swap/clear runs concurrently with a LogMessage in flight, the worker's ~FileLogger can free the object while a background thread is about to Enqueue on the stale pointer → UAF/crash.

This matters because LogMessage really is reached from multiple background threads at runtime (e.g. RouteError → LogError → LogMessage, hsm_collector.cpp:3602), not just the caller's thread.

The contract ("Call before Start") does mitigate this, but note:

• The in-code comment at hsm_collector.cpp:3579-3580 only justifies the teardown case, not a mid-run swap.
• It is asymmetric with SetLogger (hsm_collector.cpp:2668-2673), which is a pure pointer swap under the lock and is memory-safe to call anytime. A caller reasonably assuming the two "install a sink" methods behave alike can crash the process.
• It also diverges from the codebase's own established pattern for the metric-source factory, whose replaced holder is deliberately retained until destruction precisely because "the factory may be in use on the scheduler thread" (see collector.hpp:253-255).

Suggestion: either enforce the precondition (reject with HSM_RESULT_INVALID_STATE when not Stopped, like other state-guarded ops), or retain the replaced FileLogger until dispose (mirroring the metric-source holder pattern) so a mid-run swap is memory-safe.

2. (Low) Empty daily files created regardless of content

On every date roll the worker opens both DataCollector_<date>.txt and DataCollector_error_<date>.txt in append mode before any qualifying line is written (hsm_collector.cpp date-change block). std::ofstream::open creates the file, so an empty _error_ file appears every UTC day even with zero errors — and an empty all-file if min_level filters everything out that day. NLog creates the file lazily on first write, so this is a small parity gap. Consider opening lazily on the first line that will actually be written to each stream.

3. (Low) Unbounded queue growth under backpressure

Enqueue always push_backs (until stop_); there is no cap. If the disk stalls or a log storm outpaces the worker, queue_ grows without bound (unbounded memory), whereas NLog's async wrapper is bounded with an overflow policy. Given errors already pass through the deduplicator this is unlikely to bite, but a bounded queue with drop-oldest + a "(N dropped)" counter would make it robust against pathological cases.

4. (Nit) Path construction

create_directories uses std::filesystem, but the file paths are built with manual string concat and a hard-coded / (directory_ + "/DataCollector_..."). Forward slash works on Windows, but using std::filesystem::path{directory_} / ("DataCollector_" + date + ".txt") would be consistent with the directory-creation call, handle a trailing separator, and normalize per-platform.

Nits / non-issues (no action needed)

• LevelName/FormatUtc bounds are fine (buf[40] vs. max 19-char format; >= ordering is correct given DEBUG=0 < INFO=1 < ERROR=2).
• Error file intentionally ignoring min_level is documented behavior and consistent with the header comment.
• Member declaration order guarantees directory_/min_level_ are initialized before worker_ starts — no construction race.

[github-actions]

Code Review — PR #1221 feat/native-collector-logging

Adds a built-in rolling file logger to the native collector (hsm_collector_enable_file_logging / Collector::EnableFileLogging) plus lifecycle-state logging. The design is clean: a background worker drains a queue, rolls files by date, drains-then-joins on shutdown, and the worker touches only its own state. Nicely documented. A few issues worth addressing before merge.

1. Use-after-free window when the sink is swapped/cleared after Start() — Medium

LogMessage reads the FileLogger* under logger_mutex_, releases the lock, then dereferences it outside the lock:

// hsm_collector.cpp:3584-3596
{
    std::lock_guard<std::mutex> guard(logger_mutex_);
    ...
    file_logger = file_logger_.get();   // raw ptr
}
...
if (file_logger != nullptr)
    InvokeIsolated([&] { file_logger->Enqueue(level, message); });  // deref outside lock

EnableFileLogging deliberately destroys the replaced sink outside the lock (hsm_collector.cpp:2684-2697): "flushed and joined outside the lock so a swap never stalls concurrent logging." That means:

• Thread A (LogMessage) reads the raw pointer P and releases the lock.
• Thread B (EnableFileLogging) swaps file_logger_ and destroys P (drain + join).
• Thread A calls P->Enqueue(...) → use-after-free.

The in-code comment justifies the raw pointer via teardown joins only — it does not cover the swap/clear path. The two comments are in tension: LogMessage assumes the sink only dies at teardown, while EnableFileLogging is documented as a runtime swap ("A second call swaps the sink; an empty directory clears it") explicitly designed to run concurrently with logging.

This is safe only under the "call before Start" contract, but nothing enforces it and the swap semantics invite runtime use. Note the raw-pointer pattern is safe for the SetLogger callback (POD pointer + user_data, no ownership) but not for an owned heap object with a lifetime. Suggested fixes: hold a std::shared_ptr<FileLogger> and copy it under the lock (keeps it alive across the Enqueue), or destroy old while still holding logger_mutex_ (accepting the stall), or document + assert that the sink is immutable once Start() has been called.

2. UTC vs. local time breaks the stated NLog parity — Medium

Every doc comment claims "parity with the managed NLog default sink," but the managed default (src/collector/HSMDataCollector/collector.nlog.config) uses ${shortdate} for the file name and ${longdate} for the timestamp — both local time by default (no universalTime="true"). The native logger uses gmtime_r/gmtime_s (FormatUtc, hsm_collector.cpp:885-901), i.e. UTC.

Consequences on any non-UTC host: the file rolls at UTC midnight instead of local midnight, and every line's timestamp is offset from the managed sink's. For an operator comparing managed vs. native logs this is a real, surprising discrepancy. Either switch to local time to match, or soften the "parity" wording and call out UTC explicitly in the public docs.

3. Layout differs from the managed sink — Low

The managed layout is ${longdate}|${uppercase:${level}}|${logger}| ${message} — i.e. date|LEVEL|LOGGER| message with sub-second precision. The native format (hsm_collector.cpp:851-852) is date|LEVEL| message with second precision only: it drops the ${logger} field and the fractional seconds. Minor, but again inconsistent with the repeated "parity" claim — worth a note in the header comment.

4. Unbounded queue — no backpressure or drop policy — Low/Medium

queue_ is an unbounded std::deque<Entry> (hsm_collector.cpp:905) and Enqueue never blocks. If the worker can't keep up (slow/full disk, stalled fsync), the queue grows without limit → unbounded memory. NLog's async wrapper defaults to a bounded queue (limit 10000, discard-oldest). Consider a cap with a drop policy (and maybe a periodic "N messages dropped" line), consistent with how the error dedup already bounds error volume.

5. Sub-threshold messages are queued and formatted, then discarded — Low (perf)

Enqueue pushes every level regardless of min_level_; filtering happens only at write time (hsm_collector.cpp:853). Since the error file only takes HSM_LOG_LEVEL_ERROR (== the max level, always ≥ any min_level_), any entry with level < min_level_ is written to neither file. With the default min_level = Info, every DEBUG message is still copied into the queue and formatted into a line string only to be dropped. Filtering at Enqueue (if (level < min_level_) return;) avoids the allocation and the queue pressure.

6. No test coverage — Nit

hsm_collector_tests.cpp exercises set_logger but the diff adds no test for enable_file_logging (date rolling, error-file routing, min-level filtering, drain-on-shutdown). Given the concurrency and rolling logic, a unit test would be valuable.

---

Nits

• directory_ + "/DataCollector_..." can produce a double slash if the caller passes a trailing slash; harmless on both platforms but std::filesystem::path would be tidier.
• If the target directory is deleted after construction, opens silently fail and messages are dropped (is_open() false) — acceptable best-effort, but undocumented.

Overall the mechanism is well-built and the shutdown/threading model is carefully reasoned. The main things to resolve are the swap-time UAF window (#1) and the UTC-vs-local parity gap (#2).

[github-actions]

PR #1221 Review — Native collector logging (built-in file sink + lifecycle/send diagnostics)

Nice, well-documented change. The FileLogger design (non-blocking enqueue, background drain, drain-then-join on destruction, worker touches only its own state) is clean, and the tests cover the two new behaviors end-to-end. One concurrency concern stands out, plus a couple of minor notes.

---

1. Potential use-after-free when EnableFileLogging swaps/clears the sink at runtime (memory safety) — High

LogMessage captures a raw pointer to the current sink under logger_mutex_, releases the lock, and only then dereferences it:

// LogMessage (hsm_collector.cpp:3581)
{
    std::lock_guard<std::mutex> guard(logger_mutex_);
    ...
    file_logger = file_logger_.get();   // raw ptr to X
}
...
if (file_logger != nullptr)
    InvokeIsolated([&] { file_logger->Enqueue(level, message); });  // used AFTER unlock

EnableFileLogging deliberately destroys the replaced sink outside the lock:

// EnableFileLogging (hsm_collector.cpp:2689)
{
    std::lock_guard<std::mutex> guard(logger_mutex_);
    old = std::move(file_logger_);      // old holds X
    file_logger_ = std::move(logger);
}
// `old`'s destructor (drain + join) runs here, outside logger_mutex_.

Interleaving from two threads:

1. Thread A (e.g. the dispatch worker logging a "Failed to send" error) reads file_logger = X under the lock, unlocks.
2. Thread B calls EnableFileLogging("") (clear) or a new directory (swap): under the lock old = X, unlock, then ~FileLogger() runs and frees X.
3. Thread A now calls X->Enqueue(...) → touches X's mutex_/queue_ after free → use-after-free / data race.

The safety comment in LogMessage only argues the teardown case ("the collector joins every thread that can call LogMessage before file_logger_ is destroyed at teardown"). That reasoning does not cover the runtime swap/clear path in EnableFileLogging, which frees the old sink while other threads may still be inside LogMessage. Note this hazard is genuinely new: SetLogger uses the same capture-then-invoke-outside-lock pattern safely only because the callback/user_data are caller-owned and never freed by the collector — the file sink is collector-owned and gets freed on swap.

This is reachable while Running: the dispatch worker calls LogMessage on send failures, lifecycle transitions log from Start/Stop threads, etc. A user clearing or repointing logging during an outage triggers it.

Suggested fixes (any one):

• Hold a std::shared_ptr<FileLogger> and copy it under the lock in LogMessage (strong ref keeps X alive across Enqueue); or
• Keep the whole Enqueue call inside the logger_mutex_ critical section (the existing "swap never stalls concurrent logging" property is lost, but Enqueue is already non-blocking so the stall is just a push_back); or
• If runtime swap/clear is genuinely out of scope, make that a hard contract and don't free the old sink concurrently.

Related: the doc comments disagree on whether runtime reconfiguration is supported. collector.hpp says "Call before Start()", while both the C header and the .cpp comment advertise "A second call swaps the sink; an empty directory clears it" and "so a swap never stalls concurrent logging" — i.e. they explicitly contemplate concurrent logging during a swap. Please reconcile these; the intended threading contract determines which fix above is right.

---

2. FormatUtc sentinel ignores the format string (minor)

if (!ok)
    return "0001-01-01";

On a gmtime failure this returns a date-only string regardless of fmt. It's fine for the filename (%Y-%m-%d), but for the log-line timestamp (%Y-%m-%d %H:%M:%S) it yields a malformed, time-less line. This only triggers on an out-of-range clock (effectively impossible in practice), so it's cosmetic — but returning a sentinel matched to the requested format (or a fixed full timestamp) would keep the line shape consistent.

---

3. Silent drop on file-open failure (acceptable, noting for the record)

If open() fails (permissions, bad path, disk full), is_open() is false and every line is silently dropped for that date until the next roll. This is documented as best-effort and the callback sink still works, so it's a reasonable choice — but a one-time diagnostic through the callback path when the file can't be opened would make misconfiguration visible instead of silently losing the file sink.

---

Things that look correct

• Drain/join ordering in ~FileLogger plus the stopping && queue_.empty() loop exit: no shutdown-log loss, and Enqueue's early stop_ return prevents post-stop growth. Good.
• The stopping snapshot taken before processing the batch is safe because stop_ is set under the mutex before notify, and Enqueue refuses new items once stop_ is set.
• Level filtering (level >= min_level_ for the all-file, == ERROR for the error file) is consistent with the enum ordering (DEBUG=0 < INFO=1 < ERROR=2).
• NotifyLifecycle logs before taking listeners_mutex_ and outside op_mutex_, so the added LogMessage introduces no lock-ordering/deadlock risk.
• New "Registered N sensor(s) on connect" and dedup'd "Failed to send N value(s): HTTP ..." diagnostics are placed correctly behind the existing HTTP #if/#endif guards.

Overall: solid feature. Finding #1 (the swap/clear UAF window, or an explicit contract that forbids it) is the one I'd want resolved before merge.