Skip to content

Add buffered async file logging#2478

Merged
ten9876 merged 3 commits into
aethersdr:mainfrom
jensenpat:aether/issue-2471-async-logging
May 9, 2026
Merged

Add buffered async file logging#2478
ten9876 merged 3 commits into
aethersdr:mainfrom
jensenpat:aether/issue-2471-async-logging

Conversation

@jensenpat

Copy link
Copy Markdown
Collaborator

Summary

Implements the first foundation milestone for lower-overhead AetherSDR logging from issue #2471.

  • Adds AsyncLogWriter, a dedicated logging thread owned by LogManager.
  • Keeps the Qt message-handler producer path small: timestamp, type, category, raw message, enqueue, return.
  • Moves log formatting, PII redaction, stderr mirroring, and file I/O onto the logging thread.
  • Uses a bounded queue with debug/info drops first and a later coalesced drop summary line.
  • Batches file writes and flushes periodically, on shutdown, and after warning/critical/fatal batches.
  • Preserves the existing line shape, category filtering, timestamped active log file, and aethersdr.log latest-log symlink behavior.
  • Makes clearLog() deterministic by sending a writer-thread clear command that drains prior writes, truncates the active file, then resumes subsequent writes.
  • Flushes pending async log data before support bundle log collection.

Notes

This intentionally does not add event classification, a new taxonomy, or UI settings. It also does not touch radio command ordering, timers, slice behavior, panadapter behavior, or command sequencing code.

The redaction logic is preserved and carried forward onto the writer thread, with a small tightening for quoted IPv4 addresses and colon-separated MAC addresses observed during runtime verification.

Validation

  • Built exactly with:
    • env -u CPLUS_INCLUDE_PATH cmake --build build-ninja --parallel 22
  • Ran registered tests:
    • ctest --test-dir build-ninja --output-on-failure
  • Launched the built macOS app bundle offscreen and verified:
    • timestamped logs are created in the same config log directory
    • aethersdr.log points to the latest timestamped log
    • default discovery/connection/protocol debug lines still appear
    • log format remains [HH:mm:ss.zzz] DBG aether.protocol: message
    • runtime logs redact IPv4 addresses, radio serial numbers, and MAC addresses
  • Ran a throwaway AsyncLogWriter probe to verify:
    • token redaction
    • IPv4/serial/MAC redaction
    • clearLog() truncates prior buffered writes and preserves subsequent writes

👨🏼‍💻 Generated with OpenAI Codex (GPT-5.5 Pro 4/23) and tested by @jensenpat

Co-authored-by: Codex <noreply@openai.com>
@aethersdr-agent

Copy link
Copy Markdown
Contributor

Hey @jensenpat — thanks for working on this, the async log writer is a nice direction. 👍

I took a look at the CI failure on b4d6dc6. Quick read on what's happening:

What failed

  • check-windows — passed
  • build (Linux) — failed at the Build step
  • analyze (cpp) (CodeQL, Linux) — failed at the same Build step

The Linux-only failure pattern, plus a Configure step that succeeded, points at a link-time issue rather than a code issue.

Likely cause: missing pthread link on the four test executables

src/core/AsyncLogWriter.cpp uses std::thread, std::mutex, and std::condition_variable. On Linux with GCC, those need -pthread at compile and link time — without it you get undefined reference to pthread_create / pthread_join etc. On Windows the Win32 thread implementation is built in, so MSVC links cleanly, which matches what we're seeing.

In the CMakeLists.txt change, AsyncLogWriter.cpp was added as a source to four test targets:

  • ole_compound_file_test (line ~1275)
  • meter_model_test (line ~1330)
  • transmit_model_apd_test (line ~1348)
  • transmit_model_test (line ~1386)

…but none of those four targets link pthread. The main AetherSDR target already does (it picks up pthread via the DFNR/MQTT branches around CMakeLists.txt:1050 and :1107), and iambic_keyer_test shows the established pattern for tests:

if(UNIX)
    target_link_libraries(iambic_keyer_test PRIVATE pthread)
endif()

Suggested fix

Add the same if(UNIX) block after each of the four target_link_libraries(...) calls — e.g. for meter_model_test:

target_link_libraries(meter_model_test PRIVATE Qt6::Core)
if(UNIX)
    target_link_libraries(meter_model_test PRIVATE pthread)
endif()

…and the same for ole_compound_file_test, transmit_model_apd_test, and transmit_model_test. (Using Threads::Threads via find_package(Threads) would be more portable, but matching the existing in-repo style is probably the right call here.)

Notes

  • This is purely a build-system gap from adding a new threaded source to existing test targets, not a problem with the AsyncLogWriter design or your main.cpp refactor — both look clean to me on a read-through.
  • Because the failure was at link time on the test targets, the main AetherSDR binary itself almost certainly compiled fine; it's just that the test stage falls in the same CI step.
  • No Copilot review comments visible on the PR yet, so nothing to cross-reference there.

Once you push the pthread fix, the Linux build and CodeQL analyze should both go green. Holler if I've misread the symptom and the actual error is something else — I was working from the check-run summary rather than the raw build log.

🤖 Generated with Claude Code

@jensenpat jensenpat marked this pull request as ready for review May 8, 2026 20:03
@jensenpat jensenpat requested a review from ten9876 as a code owner May 8, 2026 20:03
jensenpat and others added 2 commits May 8, 2026 13:07
Co-authored-by: Codex <noreply@openai.com>
Co-authored-by: Codex <noreply@openai.com>

@aethersdr-agent aethersdr-agent Bot left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Thanks @jensenpat — this is a clean, well-structured implementation. The producer path stays small, the worker thread owns formatting/redaction/I-O, the bounded-queue drop policy is sensible (debug/info first, reserve for high-priority, coalesced summary line), and shutdown is properly drained via a sync point. Scope is exactly what the description claims; the supporting CMake test additions (pthread + AsyncLogWriter source) make sense.

A few observations worth a look before merge:

  1. IPv4 regex behavior change for quoted version strings. The previous redactPii had (?<![v"]) to skip version strings like v0.9.2.1 and "0.9.2.1". The new regex in src/core/AsyncLogWriter.cpp:46 keeps the v-prefix protection via \b (since v is a word char), but "0.9.2.1" will now match (\b triggers between " and 0) and be redacted as *.*.*. 1. The PR description mentions "a small tightening for quoted IPv4 addresses" — if that's intentional, fine, but it's worth a quick check that no existing log line shape produces a quoted four-part version that you'd rather see verbatim. (E.g., anything qDebug() << QString("0.9.2.1") style.)

  2. logFileSize() const now blocks on the writer. LogManager::logFileSize() calls flushLog(), which posts a Flush sync-point and waits up to kFlushIntervalMs for the writer to drain. If anything on the GUI thread polls this for a status display, it can stall the UI by ~250 ms. Worth confirming the only caller is SupportBundle (which already does its own flush) — if any GUI surface reads it, consider making logFileSize() return the on-disk size without the implicit flush, and let callers flush explicitly when they need accuracy.

  3. LogManager::clearLog() race during shutdown. if (m_writer.isRunning()) m_writer.clearLog() — if shutdown sneaks in between the isRunning() check and clearLog(), the writer's enqueueControlAndWait returns false silently and the file isn't cleared (no fallback to the synchronous truncate path). It's a narrow window only at teardown, so probably benign, but you could collapse it by making clearLog() return bool and falling through to the QFile path on failure.

  4. Minor: flushAfterBatch and the timer/size-based flush branches duplicate the same "flush+fflush+restart timer" sequence. Pulling that into a small flushFile() lambda would tighten run() a bit. Not a blocker.

The lifecycle wiring in main.cpp (uninstall handler before shutdownLogging, leaked LogManager* to survive late teardown) and the SupportBundle pre-flush look correct. Counters/queue stats are a nice touch for future diagnostics.

LGTM with the IPv4-quoted-version question worth a sanity check.

@ten9876 ten9876 merged commit e8f27c7 into aethersdr:main May 9, 2026
5 checks passed
@ten9876

ten9876 commented May 9, 2026

Copy link
Copy Markdown
Collaborator

Claude here — really clean foundation milestone, jensenpat. Producer-consumer split with the high-priority reserve + drop-summary coalescing is exactly the production-grade pattern (spdlog/glog shape), and the lifetime hardening (heap-allocated singleton + explicit shutdown ordering with qInstallMessageHandler(nullptr) before shutdownLogging) addresses the late-teardown reentrancy that the old code was already hedging against with the heap-allocated regex objects. The two redaction tightenings (IPv4 negative-lookbehind for ver= prefixes, colon-separator MAC pattern) caught real cases the previous regex would miss. Format preservation means existing log analysis tooling keeps working unchanged. CI ran fully on Windows too. Two follow-ups filed (#2497 unit tests, #2498 rotation) — both are tracker hygiene, not blockers. Merged.

73, Jeremy KK7GWY & Claude (AI dev partner)

aethersdr-agent Bot added a commit that referenced this pull request May 16, 2026
Pins down the public-API behavior of AsyncLogWriter so future tightening
of the PII redaction regexes (#2478) cannot regress without a test
failing. Cases mirror the suggested set in the issue:

- Line shape preservation ([HH:mm:ss.zzz] LVL cat: msg\n) for every
  QtMsgType label
- IPv4 redaction, ver= exemption, and lock-in that quoted four-octet
  IPs are still redacted (per triage: quoting is not authentication of
  intent). The original "0.9.8" case was dropped as non-applicable
  (three octets never match the regex) and replaced with the explicit
  three-octet pass-through assertion.
- Radio serial, id_token, MAC dash, and MAC colon redaction
- clearLog truncates pre-clear lines and preserves post-clear lines
- shutdown drains the queue (no loss on graceful stop)
- Drop accounting under burst load (asserts inequalities since the
  worker drains concurrently; per triage open-question #2)
- High-priority reserve keeps a critical line alive under a debug
  burst, and droppedHighPriorityLines stays at 0
- Stderr mirroring matches the file contents byte-for-byte when
  mirrorToStderr=true

Test uses only the public API (no test-only hooks added to
AsyncLogWriter), and routes the log path through QTemporaryDir so the
suite does not litter /tmp.

Blast radius: risk_score=0.000, 0 high-risk affected (AsyncLogWriter
itself has self_betweenness=0; pure additive test + CMakeLists entry).
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

2 participants