Skip to content

loggerd: degrade gracefully on log storage failure instead of aborting - #309

Open
PeterPhuTran wants to merge 1 commit into
FrogAi:MAKE-PRS-HEREfrom
PeterPhuTran:nvme-storage-resilience
Open

loggerd: degrade gracefully on log storage failure instead of aborting#309
PeterPhuTran wants to merge 1 commit into
FrogAi:MAKE-PRS-HEREfrom
PeterPhuTran:nvme-storage-resilience

Conversation

@PeterPhuTran

@PeterPhuTran PeterPhuTran commented Jul 10, 2026

Copy link
Copy Markdown

Fix engagement-blocking "Process Not Running: loggerd" when log storage fails mid-drive

Symptom

On a comma three with a Samsung 980 NVMe, the first drive after a full power-off
regularly shows "Process Not Running: loggerd" for the entire drive. Because
processNotRunning is NO_ENTRY + SOFT_DISABLE, this blocks engagement and
force-disengages openpilot ~3s after it appears. A warm restart "fixes" it until
the next cold power-on.

Root cause chain (fully instrumented on-device)

  1. ~49 seconds after a cold power-on, the Samsung 980 intermittently drops off
    the PCIe bus with a burst of I/O errors — same fingerprint every time:
    [   49.029089] blk_update_request: I/O error, dev nvme0n1, sector 9136
    [   49.029501] Buffer I/O error on dev nvme0n1, logical block 0, lost sync page write
    
    SMART shows zero media errors — a transport/controller failure, not dying flash.
    Warm reboots never trigger it (0/4); cold power-ons do, intermittently. Field
    instrumentation has since ruled OUT the drive's APST power-state feature as the
    mechanism (bursts occur with APST disabled); the exact trigger remains under
    investigation. Related: comma three with NVMe: loggerd crash commaai/openpilot#34742, NVMe Drive Permissions Error on Bootup. commaai/openpilot#35842.
  2. ext4 on /data/media takes error hits and can remount read-only for the rest
    of the power session.
  3. loggerd hits a caller-side assert() on its next disk op → SIGABRT (apport
    core captured) → the manager does not restart it → processNotRunning persists
    all drive.

Fix — loggerd degrades gracefully instead of aborting

Protects against any storage failure, whatever the underlying hardware cause:

  • ZstdFileWriter latches a write_error_ flag on open/write failure and becomes a
    no-op — mirroring the existing graceful pattern in VideoWriter::write.
  • LoggerState::next() returns false instead of asserting; the segment counter
    still advances
    so encoderd segment sync is preserved.
  • logger_rotate() treats a failed rotation as one bounded retry per segment (~60s):
    loggerd self-heals if storage recovers mid-route.
  • VideoWriter tolerates open/header failures via a disable() helper (also fixes a
    latent unconditional fclose(NULL) in its destructor).
  • Encoder streams keep draining while degraded, so IPC queues never back up.
  • bootlog exits cleanly if the log root is unavailable.

Net effect: storage failure costs that drive's logs — not openpilot engagement.

Validation

  • Simulated (on the affected device): storage broken at startup → 100+s alive
    with bounded retries (stock SIGABRTs); healthy-path regression → 3 clean segments;
    mid-recording failure via ENOSPC → survives with one latched error per writer,
    self-heals within one rotation after space returns.
  • Field (boot-instrumented, ~48h): two real NVMe bursts captured in the wild
    (21 and 30 I/O-error lines at the ~49s signature, dozens of ext4 error lines).
    With this patch: zero crashes, zero alerts, complete routes logged through both
    sessions
    (3-segment and 42-segment routes, full-size rlogs). Before this patch,
    the identical event produced a SIGABRT core dump and an engagement-blocking alert
    for the rest of the drive.
  • New degraded-mode case in tests/test_logger.cc.

Follow-ups (separate PRs)

🤖 Generated with Claude Code

loggerd previously assert()ed on every disk operation (segment directory
creation, log file open, compressed write, video container header write),
so any storage failure - e.g. an NVMe dropping off the PCIe bus and the
ext4 log volume remounting read-only - killed loggerd with SIGABRT. The
manager does not restart it, so selfdrived raises processNotRunning for
the rest of the drive, which blocks engagement (NO_ENTRY) and force-
disengages (SOFT_DISABLE).

Logging now degrades instead of crashing:
- ZstdFileWriter latches a write_error_ flag on open/write failure and
  becomes a no-op (mirrors the existing VideoWriter::write behavior)
- LoggerState::next() returns false on failure; the segment counter still
  advances so encoderd segment sync is preserved
- logger_rotate() treats a failed rotation as one bounded retry per
  segment (~60s) - loggerd self-heals if storage recovers mid-route
- VideoWriter tolerates open/header failures via a new disable() helper
  and no longer aborts (also fixes an unconditional fclose(NULL) in the
  destructor); frames keep draining so IPC queues never back up
- bootlog skips cleanly when the log root is not writable

Data is dropped while degraded (one LOGE per failed rotation); everything
else about the drive keeps working.

Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
@github-actions

Copy link
Copy Markdown

Thanks for contributing! A maintainer will review your pull request soon.

@PeterPhuTran

Copy link
Copy Markdown
Author

Validation update — resilience fix verified on hardware (V2: simulated storage failure)

Built this PR branch on the affected comma three (arm64) and ran three scenarios against the patched loggerd:

1. Storage broken at startup (log root unwritable): ran 100+ seconds with no abort — one LOGE pair per rotation (the bounded ~60s retry working as designed), bootlog skips cleanly with exit 0. On stock, this exact scenario SIGABRTs at startup (apport core dump on file).

2. Healthy-path regression: normal recording, 3 clean segments with real rlog/qlog content, rotations on schedule, zero errors.

3. Mid-recording storage failure + recovery (filesystem driven to write-failure mid-segment — exercises the same short-write path as the field EIO/read-only remount):

segment rlog what happened
0 40 KB healthy recording
1 0 B storage failed mid-segment — loggerd stayed alive, exactly one latched error per writer, no log spam
2 73 KB storage restored — self-healed at the next rotation, recording resumed

Process alive end-to-end. On stock, the first failed write in segment 1 is an assert() → SIGABRT → "Process Not Running: loggerd" → NO_ENTRY + SOFT_DISABLE for the remainder of the drive.

The patched binaries are now the daily-driver loggerd on this device, and the APST mitigation applies at every boot — will report cold-boot field results (dmesg fingerprints) as they accumulate.

One note for on-device builders: common/params.cc reproducibly segfaults clang at -O2 on-device (works at -O1 with a raised stack limit) — unrelated to this PR, mentioning in case anyone else compiles on the comma three.

PeterPhuTran added a commit to PeterPhuTran/openpilot that referenced this pull request Jul 10, 2026
Field incident on 2026-07-10 (same device as FrogAi#309): updated logged a
130KB 'git diff output' record for a dirty working tree; logmessaged
crashed publishing it to the 256KB logMessage msgq (msgq asserts
3*msg_size <= queue_size, so anything over ~85KB is fatal while
logmessaged's own guard only rejects >2MB). Being unflagged, it stayed
dead for the rest of the session - permanent processNotRunning alert
and total swaglog loss (the crash of the logging daemon is the one
crash it can never log).

logmessaged is exactly the kind of always_run, non-safety process this
flag exists for.

Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
@PeterPhuTran

Copy link
Copy Markdown
Author

Field update after ~48h and 14 instrumented boots — one confirmation and one honest correction.

The resilience fix is now field-proven. Boot instrumentation captured two real NVMe dropout bursts in the wild (overnight cold power-ons, 21 and 30 I/O-error lines at the signature ~49s mark, dozens of ext4 error lines each). Result with this PR's loggerd running: zero crashes, zero processNotRunning alerts, and complete routes logged straight through both sessions (a 3-segment and a 42-segment route, full-size rlogs). Before this patch, the identical event produced a SIGABRT core dump and an engagement-blocking alert for the rest of the drive.

Correction on the APST commit: both field bursts occurred with APST already disabled (applied at boot+14s, bursts at ~49s) — so the nvme set-feature mitigation does not prevent the dropout, and the mechanism claim in that commit doesn't hold up. The drive drops off the bus ~49s after cold power-on regardless of APST state; the loggerd hardening in this PR is what actually protects users. I'm happy to drop the launch-script commit from this PR so it carries only the validated fix — say the word and I'll update the branch.

@PeterPhuTran
PeterPhuTran force-pushed the nvme-storage-resilience branch from 4a851ef to a9db669 Compare July 11, 2026 21:00
@PeterPhuTran PeterPhuTran changed the title Fix engagement-blocking loggerd crash when NVMe storage fails (Samsung APST cold-boot bug) loggerd: degrade gracefully on log storage failure instead of aborting Jul 11, 2026
@PeterPhuTran

Copy link
Copy Markdown
Author

Done — dropped the APST commit and updated the PR title/body accordingly. This PR is now solely the field-validated loggerd resilience fix (single commit). The hardware trigger investigation continues separately; whatever the cause turns out to be, this fix keeps a storage failure from ever blocking engagement.

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.

1 participant