Skip to content

fix(logging): quiet the default log and stop colouring syslog - #108

Merged
mrjeeves merged 1 commit into
mainfrom
claude/allmystuff-cecsupport-auto-updates-r6rjxi
Jul 30, 2026
Merged

fix(logging): quiet the default log and stop colouring syslog#108
mrjeeves merged 1 commit into
mainfrom
claude/allmystuff-cecsupport-auto-updates-r6rjxi

Conversation

@mrjeeves

Copy link
Copy Markdown
Owner

Why

A field server reached 74 GB of /var/log/syslog in about a month and hit ENOSPC:

rsyslogd: file '/var/log/syslog'[7] write error … OS error: No space left on device
ubuntu myownmesh[793]: #033[2m2026-07-29T09:12:59Z#033[0m #033[32m INFO#033[0m signaling: client disconnected #033[3mip#033[0m#033[2m=#033[0m127.0.0.1 #033[3mactive#033[0m#033[2m=#033[0m21
ubuntu myownmesh[793]: #033[2m…#033[0m #033[32m INFO#033[0m signaling: client connected … active=22

Two causes, both in how the daemon writes rather than what it does.

1. ANSI colour written into a non-TTY

tracing_subscriber enables ANSI unconditionally — it does not check for a terminal. Under systemd that stdout is captured by journald/rsyslog, so every line reached syslog wrapped in escape sequences (visible above). That is ~40–60 wasted bytes on every line of a daemon that logs continuously, and it breaks grep against what you can actually read.

Colour is now gated on std::io::stdout().is_terminal() — a terminal still gets colour, a service gets plain text.

2. Per-connection tracing at INFO

  • The signaling relay logged a line on every client connect and disconnect. The sample box holds 21–22 clients and flaps constantly.
  • The WebRTC negotiation path logged ~12 stage lines per peer per attempt (create_offer / create_answer / set_remote_description / ensure_peer_session).

Those were INFO on an explicit, documented premise — that they "fire once per connect attempt — negligible in a healthy log". That premise is the bug. A mesh that is renegotiating is exactly the one that floods, so the daemon logs hardest precisely when it is sickest, and the disk that fills takes the diagnosis with it. On a relay holding 20+ peers this was the dominant term.

They are DEBUG now. The default log is boring on purpose: startup, control-socket commands, network state changes, warnings and errors.

The debugging workflow is unchanged in substance. MYOWNMESH_LOG_EXTRA=myownmesh_core=debug,myownmesh_signaling=debug — which just serve-trace already sets — restores every one of those lines verbatim. docs/DEBUGGING-CONNECTIONS.md now says so explicitly, so nobody has to rediscover where they went.

What was deliberately left alone

Nothing that reports a real state change was touched:

  • Connection tracing (conn_trace) — already correctly gated on a ctl trace subscriber or MYOWNMESH_CONN_TRACE, and it already diffs only discrete fields so RTT churn doesn't trigger it. It was not a contributor.
  • Interface/primary-IP transitions, relay connect/recover, primary signaling recovered, mesh/identity startup, control-socket commands.
  • Every warn! / error! path.

Testing

cargo test --workspace green, cargo clippy --workspace --all-targets clean, cargo fmt --all --check clean.

One flake seen along the way: myownmesh --lib failed 1/20 on a first run and then passed 20/20 on five consecutive reruns. It's in control/ipc/services — code this PR doesn't touch (the only change in that crate is to main.rs, a binary, not the lib) — so it's pre-existing and unrelated. Flagging it rather than burying it.

Not addressed here

The underlying reason that box logs so much is that a signaling client disconnects and reconnects every ~32 seconds, forever (active oscillating 21↔22). That churn is what multiplies every other line. Per direction on the issue, this PR only quiets the logs and does not chase the flap.


Generated by Claude Code

A field server reached 74 GB of /var/log/syslog in about a month and hit
ENOSPC. Two causes, both in how the daemon writes rather than what it does.

ANSI colour into a non-TTY. `tracing_subscriber` enables ANSI
unconditionally — it does not check for a terminal. Under systemd that
stdout is captured by journald/rsyslog, so every line landed as:

  ubuntu myownmesh[793]: #33[2m2026-…#33[0m #33[32m INFO#033[0m signaling: …

That is ~40-60 wasted bytes per line forever, and grep stops matching what
you can read. Colour is now gated on `stdout().is_terminal()`.

Per-connection tracing at INFO. The signaling relay logged a line on every
client connect and disconnect, and the WebRTC negotiation path logged ~12
stage lines per peer per attempt (create_offer / create_answer /
set_remote_description / ensure_peer_session). Those were INFO on the
premise that they "fire once per connect attempt — negligible in a healthy
log". That premise is the bug: a mesh that is renegotiating is exactly the
one that floods, so the daemon logged hardest precisely when it was
sickest — and the disk that fills takes the diagnosis with it. On a relay
holding 20+ clients this was the dominant term.

They are DEBUG now. The default log is boring on purpose: startup, control
socket commands, network state changes, errors. The debugging workflow is
unchanged in substance — `MYOWNMESH_LOG_EXTRA=myownmesh_core=debug,
myownmesh_signaling=debug` (what `just serve-trace` already sets) restores
every one of those lines verbatim. Documented in DEBUGGING-CONNECTIONS.md
so nobody has to rediscover where they went.

Nothing that reports a real state change was touched: connection tracing
(already gated on a subscriber), interface/IP transitions, relay recovery,
and every warn/error path are as they were.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01FMPNLjvNYQCeR3xGfdDUCg
@mrjeeves
mrjeeves merged commit 9b5b486 into main Jul 30, 2026
10 checks passed
@mrjeeves
mrjeeves deleted the claude/allmystuff-cecsupport-auto-updates-r6rjxi branch July 30, 2026 13:37
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