Skip to content

Daemon reconnect noise rotates the tray diagnostics out of the log #7

Description

@HackPoint

What

Release logging was just enabled so that a tray failure leaves evidence. But the daemon's
reconnect loop logs at warn!, and the log is capped at 256 KB with RotationStrategy::KeepOne
so when the daemon cannot bind its port it produces enough output to rotate the file away in about
half an hour, taking the startup and tray diagnostics with it.

That defeats the point of the change. The diagnostics exist to survive until someone asks for them;
a retry loop that evicts them means the log is empty exactly when the user finally reports the
problem.

Evidence

Measured on a machine where a stray daemon held 127.0.0.1:9999, so the app's own daemon could not
bind and retried every 2 seconds:

  • 2,470 bytes in 20 seconds = 434 KB/hour
  • max_file_size(256 * 1024) with KeepOne (lumenator/src-tauri/src/lib.rs, the
    tauri_plugin_log builder) → rotates every ~35 minutes
  • Killing the process holding the port stopped it dead: 0 bytes in the following 15 seconds, which
    confirms the loop was the whole source

The lines come from the daemon's stderr being forwarded at warn! in the sidecar reader, which was
raised from info! deliberately so the default release level (Warn) would show daemon problems at
all. Both facts are correct on their own; together they are the defect.

The port conflict itself was a stray development process, not a product bug — but a genuine one
happens whenever an upgrade leaves an orphaned daemon behind, which is the case the DaemonChild
kill-on-exit path already exists to handle.

Acceptance criteria

  • A repeating daemon connection failure cannot rotate away the startup and tray lines within an
    hour.
  • The first occurrence of a bind failure is still logged at warn! — it is a real problem and
    must be visible at the default level.
  • Subsequent identical failures are rate-limited, demoted, or collapsed, so the volume is
    bounded rather than proportional to uptime.
  • LUMEN_LOG=debug still shows every attempt, for someone actively debugging.
  • A test covers the throttling decision as a pure function, in the way
    lumen_core::faults::record_throttled already throttles repeated fault kinds — reuse it if it
    fits rather than adding a second mechanism.

How to test

# Occupy the port so the daemon cannot bind, reproducing the loop.
python3 -c "import socket,time; s=socket.socket(); s.setsockopt(1,2,1); s.bind(('127.0.0.1',9999)); s.listen(1); time.sleep(600)" &
BLOCKER=$!

: > ~/Library/Logs/io.speedata.lumen/Lumen.log
open -a Lumen
sleep 5
BEFORE=$(wc -c < ~/Library/Logs/io.speedata.lumen/Lumen.log)
sleep 20
AFTER=$(wc -c < ~/Library/Logs/io.speedata.lumen/Lumen.log)
echo "growth: $(( (AFTER - BEFORE) * 180 / 1024 )) KB/hour"

# The startup line must still be present after a sustained period of failure.
grep -c "STARTUP: Lumen" ~/Library/Logs/io.speedata.lumen/Lumen.log

kill $BLOCKER

Before the fix: roughly 434 KB/hour, and STARTUP disappears once the file rotates. After: growth
bounded well under the 256 KB cap per hour, and the STARTUP count stays at 1.

Metadata

Metadata

Assignees

No one assigned

    Labels

    bugSomething isn't working

    Projects

    No projects

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions