Tracers whose settings change start over on reload #50

Merged
jcoffey-dev merged 1 commits from fix/tracer-live-reload into main 2026-09-25 03:57:53 +00:00
Owner

Problem

In a cluster rehearsal, a Log tracer was moved to another directory. The write came back with x:settingsReload: {"applied": true}, but the tracer kept writing to the old file until a restart.

Telemetry::update (crates/common/src/telemetry/mod.rs) only refreshed the events, level and lossiness of a tracer that was already running. The tracer's own settings stayed as they were when it was built: path, prefix, rotation and format for Log; endpoint, headers and exporters for OpenTelemetry; URL, key and headers for webhooks.

Change

Detecting a change. Each tracer now carries a hash of the registry object it was built from (TelemetrySubscriber::settings). The hash leaves out enable, level, lossy and events, since those change in place. On reload:

Tracer What happens
New started
Removed stopped
Same settings updated in place, as before
Changed settings started over

Only tracers this server started are stopped. Upstream removed every collector subscriber that wasn't in the settings, which also cut off live-tracing streams on each reload.

The swap loses and duplicates nothing. The new tracer registers under the running one's id, and the collector (trc::ipc::collector, Update::RegisterSubscriber) swaps them between two collection passes:

  • Every event collected before the swap went to the old tracer. Every event after it goes to the new one.
  • The old tracer's pending batch is sent first. If its channel is full, the leftover moves to the new tracer rather than being dropped.
  • Dropping the old subscriber closes its channel. Its task writes what is queued, then ends.

Per tracer kind:

Kind Handling
Log A tracer started over on the same files (rotation or format changed) waits for the old one to finish, so lines don't interleave. Different files don't wait.
Webhook The task kept a sender of its own channel for retries, so it never ended, even after removal. Retries now use a weak sender. Pending events are posted when the channel closes.
OpenTelemetry Pending logs and spans are exported when the channel closes instead of dropped. A span that was open across the swap is exported by the new tracer with the events it saw after the swap. Its earlier events still went out as log records.
Console, journal Nothing is kept between batches.
Trace history Built from the tracing store, which takes a restart. It is never started over.

No kind needs a restart, so x:settingsReload doesn't gain a restart flag. A failed webhook delivery that comes back after its webhook was replaced is dropped: it has nowhere to go. That's the only case where the swap can lose events.

Tests

system::tracer_reload::tracer_reload_tests (new):

  1. Creates a Log tracer over JMAP for one event type, and checks it writes to its directory.
  2. Changes the tracer's path over JMAP while 2000 numbered events are emitted.
  3. After the reload, checks that events land in the new file and not the old one.
  4. Checks that each numbered event is in exactly one of the two files. Four runs split them 151/1849, 1601/399, 1601/399 and 1551/449.
  5. Checks that a destroyed tracer writes nothing.

On main, the new file never appears.

nstest3.sh <worktree> RocksDb system::tracer_reload    ok (4 runs)
nstest3.sh <worktree> RocksDb system::auto_reload      ok
nstest3.sh <worktree> RocksDb system::reload::         ok
nstest3.sh <worktree> RocksDb system::monitoring::monitoring_tests -- --ignored   ok (live tracing)
## Problem In a cluster rehearsal, a Log tracer was moved to another directory. The write came back with `x:settingsReload: {"applied": true}`, but the tracer kept writing to the old file until a restart. `Telemetry::update` (`crates/common/src/telemetry/mod.rs`) only refreshed the events, level and lossiness of a tracer that was already running. The tracer's own settings stayed as they were when it was built: path, prefix, rotation and format for Log; endpoint, headers and exporters for OpenTelemetry; URL, key and headers for webhooks. ## Change **Detecting a change.** Each tracer now carries a hash of the registry object it was built from (`TelemetrySubscriber::settings`). The hash leaves out enable, level, lossy and events, since those change in place. On reload: | Tracer | What happens | |---|---| | New | started | | Removed | stopped | | Same settings | updated in place, as before | | Changed settings | started over | Only tracers this server started are stopped. Upstream removed every collector subscriber that wasn't in the settings, which also cut off live-tracing streams on each reload. **The swap loses and duplicates nothing.** The new tracer registers under the running one's id, and the collector (`trc::ipc::collector`, `Update::RegisterSubscriber`) swaps them between two collection passes: - Every event collected before the swap went to the old tracer. Every event after it goes to the new one. - The old tracer's pending batch is sent first. If its channel is full, the leftover moves to the new tracer rather than being dropped. - Dropping the old subscriber closes its channel. Its task writes what is queued, then ends. **Per tracer kind:** | Kind | Handling | |---|---| | Log | A tracer started over on the same files (rotation or format changed) waits for the old one to finish, so lines don't interleave. Different files don't wait. | | Webhook | The task kept a sender of its own channel for retries, so it never ended, even after removal. Retries now use a weak sender. Pending events are posted when the channel closes. | | OpenTelemetry | Pending logs and spans are exported when the channel closes instead of dropped. A span that was open across the swap is exported by the new tracer with the events it saw after the swap. Its earlier events still went out as log records. | | Console, journal | Nothing is kept between batches. | | Trace history | Built from the tracing store, which takes a restart. It is never started over. | No kind needs a restart, so `x:settingsReload` doesn't gain a restart flag. A failed webhook delivery that comes back after its webhook was replaced is dropped: it has nowhere to go. That's the only case where the swap can lose events. ## Tests `system::tracer_reload::tracer_reload_tests` (new): 1. Creates a Log tracer over JMAP for one event type, and checks it writes to its directory. 2. Changes the tracer's `path` over JMAP while 2000 numbered events are emitted. 3. After the reload, checks that events land in the new file and not the old one. 4. Checks that each numbered event is in exactly one of the two files. Four runs split them 151/1849, 1601/399, 1601/399 and 1551/449. 5. Checks that a destroyed tracer writes nothing. On `main`, the new file never appears. ``` nstest3.sh <worktree> RocksDb system::tracer_reload ok (4 runs) nstest3.sh <worktree> RocksDb system::auto_reload ok nstest3.sh <worktree> RocksDb system::reload:: ok nstest3.sh <worktree> RocksDb system::monitoring::monitoring_tests -- --ignored ok (live tracing) ```
jcoffey-dev added 1 commit 2026-09-25 03:53:15 +00:00
Tracers whose settings change start over on reload
ci / fork-checks (pull_request) Successful in 47s
ci / build (pull_request) Successful in 3m49s
a891667149
A cluster rehearsal moved a Log tracer to another directory: the write
was reported x:settingsReload applied:true, but the tracer kept writing
to the old file until a restart. Telemetry::update only refreshed each
running tracer's events, level and lossiness; a tracer's own settings
(path, prefix, rotation, format, endpoint, headers, ...) stayed as built.

Each tracer now carries a hash of the registry object it was built
from, less the fields that change in place. The reload compares it with
the running tracer's: unchanged ones are updated in place as before,
changed ones are started over, new ones started and removed ones
stopped. Only tracers this server started are removed; upstream removed
every subscriber not in the settings, which also cut off live-tracing
streams on each reload.

Starting over is a swap in the collector, so no event is lost or
written twice: a subscriber registered under a running one's id
replaces it between two collection passes. The old one's batch is sent
first (what its full channel can't take moves to the new one), and
dropping it closes its channel, so its task writes what is queued and
ends. Per tracer kind:

- Log: a tracer started over on the same files (rotation or format
  changed) waits for the old one to finish, so lines don't interleave.
- Webhook: the task held a sender of its own channel for retries, so
  it never ended; retries now use a weak sender, and pending events are
  posted when the channel closes.
- OpenTelemetry: pending logs and spans are exported when the channel
  closes instead of dropped, and a span that was open across the swap
  is exported by the new tracer with the events it saw.
- Console and journal: nothing kept between batches.
- Trace history: built from the tracing store, which takes a restart,
  so it is never started over.

No kind needs a restart, so x:settingsReload doesn't gain one.

system::tracer_reload::tracer_reload_tests (new): a Log tracer created
over JMAP writes to its directory; its path is changed over JMAP while
2000 numbered events are emitted; after the reload, events land in the
new file and not the old one, each numbered event is in exactly one of
the two files, and a destroyed tracer writes nothing. On main the new
file never appears.
jcoffey-dev merged commit 51b159a1a2 into main 2026-09-25 03:57:53 +00:00
jcoffey-dev deleted branch fix/tracer-live-reload 2026-09-25 03:57:53 +00:00
Sign in to join this conversation.
No Reviewers
No labels
1 Participants
Notifications
Due Date
No due date set.
Dependencies

No dependencies set.

Reference: inbuxa/inbuxa-server#50