Skip to content

fix(util): bound opencode.log by trimming its head in place - #47676

Merged
Hona merged 4 commits into
anomalyco:v2from
Hona:log-trim
Sep 6, 2026
Merged

fix(util): bound opencode.log by trimming its head in place#47676
Hona merged 4 commits into
anomalyco:v2from
Hona:log-trim

Conversation

@Hona

@Hona Hona commented Sep 6, 2026

Copy link
Copy Markdown
Member

opencode.log is appended forever with no rotation since #31310. Long-lived installs end up with a 500 MB–1 GB file, which also defeats the desktop debug export (#47672).

Per discussion with @thdxr: keep one file, no rotation, just trim it.

  • Once the file exceeds LOG_MAX_BYTES (50 MB) the head is dropped so LOG_KEEP_BYTES (25 MB) remain.
  • The cut is rounded forward to the next \n, found by scanning raw bytes in 64 KiB chunks from the cut offset (no decoding), so the kept tail always starts on a complete line.
  • Runs from fileLogger as a scoped fiber: immediately on boot, then every LOG_TRIM_INTERVAL (1 hour). A stat per hour is the steady-state cost.
  • All three knobs are exported constants in packages/util/src/observability/logging.ts.
flowchart LR
  A[stat] -->|size ≤ 50 MB| Z[done]
  A -->|size > 50 MB| B["scan from size − 25 MB for first \n"]
  B --> C["stream [lineStart, EOF) → write at offset 0"]
  C --> D["ftruncate(written)"]
Loading

Compaction is in place on an r+ handle rather than temp-file + rename. Every opencode process on the machine (TUI, CLI, desktop's server) appends to the same file with O_APPEND; they keep writing to the compacted file, whereas a rename would strand them on the unlinked inode and lose their output.

const handle = yield* fs.open(target, { flag: "r+" })
const start = yield* lineStart(handle, size - keep)
yield* handle.seek(0, "start")
const written = yield* fs.stream(target, { offset: start, chunkSize: LOG_TRIM_CHUNK }).pipe(
  Stream.runFoldEffect(() => 0, (total, chunk) => handle.writeAll(chunk).pipe(Effect.as(total + chunk.length))),
)
yield* handle.truncate(written)

Against a real 60 MB tail of a 1 GB opencode.log: 62,914,560 → 26,214,178 bytes in 99 ms, first kept byte is timestamp=, tail byte-identical.

Copilot AI lite review requested due to automatic review settings September 6, 2026 22:05

Copilot AI 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.

Copilot was unable to review this pull request because the user who requested the review has reached their quota limit.

@Hona

Hona commented Sep 6, 2026

Copy link
Copy Markdown
Member Author

Addressed in 2573ba9.

1. Cross-process trims — valid, and not theoretical: the same opencode.log on my machine shows up to six distinct run= IDs writing in the same minute (TUI, CLI one-shots, server, and both servers during handoff). Added an atomic mkdir lock beside the log (opencode.log.trim). The size check now happens inside the lock. If the lock is held the trimmer skips this round and the next hourly tick retries; a lock older than LOG_TRIM_LOCK_STALE_MS (5 min) is removed but that round still yields. Reproduced the wipe scenario with 8 concurrent trimmers on a real 1.07 GB log: 1,069,701,619 → 26,214,223 bytes, not emptied, 0 malformed lines, no lock left behind.

2. Appender vs. truncate — accepted as a known trade-off and documented in a comment on trim. The window is the gap between the final zero-byte read and ftruncate, a few ms once per ~25 MB of logging. Closing it means wrapping every Logger.toFile write in the same lock, which is a reimplementation of Effect's file logger for a debug log. Not worth it.

@Hona

Hona commented Sep 6, 2026

Copy link
Copy Markdown
Member Author

c8eef47.

1. Interruption-safe acquisition — done. The mkdir now runs inside Effect.acquireRelease, so it is uninterruptible and the release is registered atomically; release is a no-op when acquisition returned false. Added a test with a FileSystem whose makeDirectory completes on disk and then sleeps before returning; interrupting the fiber during that sleep left the lock behind on the previous commit and leaves nothing now.

2. Stale-lock removal race — declining. Preconditions: a process dies inside a sub-second trim (leaving a stale lock), then ≥3 processes tick within the same few milliseconds ≥5 minutes later, with the file over 50 MB at that instant. The consequence is the same bounded tail loss already documented on trim, not a wipe (the size check runs after acquisition). A breaker protocol would be a second hand-rolled lock in this package next to EffectFlock; if it ever matters, the right fix is to reuse EffectFlock once the observability layer can depend on Global/FSUtil. Documented in a comment on breakStaleLock.

@Hona
Hona enabled auto-merge (squash) September 6, 2026 22:45
@Hona
Hona disabled auto-merge September 6, 2026 23:16
@Hona
Hona merged commit f334377 into anomalyco:v2 Sep 6, 2026
7 of 8 checks passed
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