Andreas Wrede
e7a82126f2
Tails journalctl -kf for the "nvme nvmeN: I/O tag ... timeout, reset controller" signature that crashed and corrupted the root fs on 2026-08-02 (and recurred 2026-08-04, that time self-healing). Watches a short grace window to tell a clean self-heal from an escalation (repeated timeout or a following ext4 error) before paging via the existing Pushover credentials, with a live SMART/superblock snapshot in the alert body.
262 lines
9.8 KiB
Python
262 lines
9.8 KiB
Python
#!/usr/bin/env python3
|
|
"""van-nvme-watch — pages when the NVMe root hits an I/O-timeout/reset event.
|
|
|
|
This exact kernel signature ("nvme nvmeN: I/O tag ... timeout, reset
|
|
controller") crashed and corrupted the NVMe root on 2026-08-02, then recurred
|
|
2026-08-04 and self-healed. Root cause is still unconfirmed (suspected
|
|
USB/PCIe host-bandwidth contention during heavy interface churn), so this
|
|
just watches for it recurring rather than trying to prevent it.
|
|
|
|
Tails `journalctl -kf` (event-driven, not polled) rather than sysfs like
|
|
van-thermal, since there's no sensor to sample — only a log line to catch.
|
|
On a match it watches a short grace window for either a clean controller
|
|
re-init (self-healed) or a follow-up ext4 error / a second timeout (escalating)
|
|
before paging, and includes a live SMART + superblock snapshot in the message
|
|
so the phone alert already answers "is the filesystem actually at risk".
|
|
|
|
Publishes /run/van-nvme-watch/state.json (last event, same convention as
|
|
van-failover/van-thermal). Pushover credentials shared with van-battery/
|
|
van-thermal (/etc/van-battery/pushover.json, 0600). Stdlib only.
|
|
"""
|
|
|
|
import json
|
|
import os
|
|
import queue
|
|
import re
|
|
import socket
|
|
import subprocess
|
|
import sys
|
|
import threading
|
|
import time
|
|
import urllib.parse
|
|
import urllib.request
|
|
from datetime import datetime, timezone
|
|
from pathlib import Path
|
|
|
|
CONFIG_PATH = os.environ.get("VAN_NVME_WATCH_CONFIG", "/etc/van-nvme-watch/config.json")
|
|
STATE_DIR = Path("/run/van-nvme-watch")
|
|
STATE_PATH = STATE_DIR / "state.json"
|
|
HOST = socket.gethostname()
|
|
|
|
DEFAULTS = {
|
|
"nvme_device": "nvme0", # controller name as it appears in dmesg / smartctl target
|
|
"fs_device": "/dev/nvme0n1p2", # for the superblock snapshot
|
|
"grace_period": 20, # seconds to watch for escalation after a timeout line
|
|
"cooldown": 300, # minimum seconds between Pushover sends
|
|
"credentials_path": "/etc/van-battery/pushover.json",
|
|
}
|
|
|
|
# The exact crash/recurrence signature, kept nvme-scoped and loose enough to
|
|
# catch variant opcodes/tags/queue ids without matching unrelated nvme lines.
|
|
TIMEOUT_RE = re.compile(r"nvme (nvme\d+): .*\b(?:timeout|reset controller)\b", re.IGNORECASE)
|
|
# Signs the event is more than a clean self-heal: an actual filesystem error,
|
|
# or forced read-only remount, following the reset.
|
|
ESCALATION_RE = re.compile(
|
|
r"EXT4-fs error|EXT4-fs.*remount.*read-only|Remounting filesystem read-only|"
|
|
r"Buffer I/O error|I/O error, dev nvme",
|
|
re.IGNORECASE,
|
|
)
|
|
|
|
PLACEHOLDERS = {"", "REPLACE_ME", "your-token-here", "your-user-key-here"}
|
|
|
|
|
|
def log(msg, level="info"):
|
|
pri = {"info": "<6>", "warn": "<4>", "crit": "<2>"}.get(level, "<6>")
|
|
print(pri + msg, flush=True)
|
|
|
|
|
|
def load_creds(cfg):
|
|
try:
|
|
c = json.loads(Path(cfg["credentials_path"]).read_text())
|
|
token, user = str(c.get("token", "")).strip(), str(c.get("user", "")).strip()
|
|
if token in PLACEHOLDERS or user in PLACEHOLDERS:
|
|
return None
|
|
return token, user
|
|
except FileNotFoundError:
|
|
return None
|
|
except Exception as e:
|
|
log(f"credentials {cfg['credentials_path']} unreadable ({e})", "warn")
|
|
return None
|
|
|
|
|
|
def pushover(cfg, title, message, priority=0, attempts=3, retry_delay=15):
|
|
creds = load_creds(cfg)
|
|
if not creds:
|
|
log(f"pushover skipped (no credentials): {title} — {message}", "warn")
|
|
return False
|
|
token, user = creds
|
|
data = urllib.parse.urlencode({
|
|
"token": token, "user": user, "title": title,
|
|
"message": message, "priority": priority,
|
|
}).encode()
|
|
req = urllib.request.Request("https://api.pushover.net/1/messages.json", data=data)
|
|
for attempt in range(1, attempts + 1):
|
|
try:
|
|
with urllib.request.urlopen(req, timeout=10) as resp:
|
|
ok = resp.status == 200
|
|
if not ok:
|
|
log(f"pushover HTTP {resp.status}", "warn")
|
|
return ok
|
|
except Exception as e:
|
|
last = attempt == attempts
|
|
log(f"pushover send failed ({attempt}/{attempts}): {e}", "warn")
|
|
if not last:
|
|
time.sleep(retry_delay)
|
|
return False
|
|
|
|
|
|
def load_config():
|
|
cfg = dict(DEFAULTS)
|
|
try:
|
|
with open(CONFIG_PATH) as f:
|
|
cfg.update(json.load(f))
|
|
except FileNotFoundError:
|
|
log(f"config {CONFIG_PATH} not found, using built-in defaults")
|
|
except Exception as e:
|
|
log(f"config {CONFIG_PATH} unreadable ({e}), using built-in defaults", "warn")
|
|
return cfg
|
|
|
|
|
|
def snapshot_health(cfg):
|
|
"""Best-effort SMART + superblock snapshot for the alert body — answers
|
|
"did this one actually hurt the filesystem" without needing to SSH in."""
|
|
info = {}
|
|
try:
|
|
out = subprocess.run(["smartctl", "-a", f"/dev/{cfg['nvme_device']}"],
|
|
capture_output=True, text=True, timeout=15).stdout
|
|
for key, pattern in (
|
|
("smart_health", r"SMART overall-health self-assessment test result:\s*(\S+)"),
|
|
("smart_critical_warning", r"Critical Warning:\s*(\S+)"),
|
|
("smart_media_errors", r"Media and Data Integrity Errors:\s*(\d+)"),
|
|
):
|
|
m = re.search(pattern, out)
|
|
info[key] = m.group(1) if m else "?"
|
|
except Exception as e:
|
|
info["smart_error"] = str(e)
|
|
try:
|
|
out = subprocess.run(["tune2fs", "-l", cfg["fs_device"]],
|
|
capture_output=True, text=True, timeout=15).stdout
|
|
m = re.search(r"Filesystem state:\s*(\S+)", out)
|
|
info["fs_state"] = m.group(1) if m else "?"
|
|
except Exception as e:
|
|
info["fs_state_error"] = str(e)
|
|
return info
|
|
|
|
|
|
def write_state(payload):
|
|
STATE_DIR.mkdir(parents=True, exist_ok=True)
|
|
tmp = STATE_PATH.with_suffix(".tmp")
|
|
tmp.write_text(json.dumps(payload))
|
|
tmp.replace(STATE_PATH)
|
|
|
|
|
|
def journal_reader(q):
|
|
"""Runs forever in a background thread, pushing new kernel log lines onto
|
|
q. journalctl itself can exit (journald restart, etc.) — respawn it."""
|
|
while True:
|
|
try:
|
|
proc = subprocess.Popen(
|
|
["journalctl", "-kf", "-n", "0", "-o", "cat"],
|
|
stdout=subprocess.PIPE, stderr=subprocess.DEVNULL,
|
|
text=True, bufsize=1)
|
|
for line in proc.stdout:
|
|
q.put(line.rstrip("\n"))
|
|
proc.wait()
|
|
log(f"journalctl exited (code {proc.returncode}), restarting in 5s", "warn")
|
|
except Exception as e:
|
|
log(f"journalctl reader error: {e}, restarting in 5s", "warn")
|
|
time.sleep(5)
|
|
|
|
|
|
def finalize(cfg, pending, escalated, reason, alert_state):
|
|
"""Wrap up a pending event: snapshot health, log, publish state, and
|
|
Pushover (subject to cooldown). alert_state is a {"last_alert": monotonic}
|
|
box shared across calls so the cooldown persists across events."""
|
|
health = snapshot_health(cfg)
|
|
outcome = "ESCALATED" if escalated else "self-healed"
|
|
icon = "🚨" if escalated else "⚠️"
|
|
priority = 1 if escalated else 0
|
|
|
|
lines = [f"first: {pending['line']}"]
|
|
if pending.get("count", 1) > 1:
|
|
lines.append(f"repeated {pending['count']}x within the grace window")
|
|
if pending.get("escalation_line"):
|
|
lines.append(f"then: {pending['escalation_line']}")
|
|
lines.append(f"fs state: {health.get('fs_state', '?')} | "
|
|
f"SMART: {health.get('smart_health', '?')}, "
|
|
f"critical_warning={health.get('smart_critical_warning', '?')}, "
|
|
f"media_errors={health.get('smart_media_errors', '?')}")
|
|
message = "\n".join(lines)
|
|
|
|
log(f"nvme event {outcome} ({reason}): {message}", "crit" if escalated else "warn")
|
|
|
|
write_state({
|
|
"updated": datetime.now(timezone.utc).isoformat(timespec="seconds"),
|
|
"device": pending["device"],
|
|
"count": pending.get("count", 1),
|
|
"escalated": escalated,
|
|
"reason": reason,
|
|
"first_line": pending["line"],
|
|
"escalation_line": pending.get("escalation_line"),
|
|
"health": health,
|
|
})
|
|
|
|
if time.monotonic() - alert_state["last_alert"] >= cfg["cooldown"]:
|
|
pushover(cfg, f"{icon} {HOST}: NVMe timeout — {outcome}", message, priority=priority)
|
|
alert_state["last_alert"] = time.monotonic()
|
|
else:
|
|
log("pushover suppressed (cooldown)", "warn")
|
|
|
|
|
|
def main():
|
|
cfg = load_config()
|
|
log(f"van-nvme-watch up: tailing journalctl -k for nvme timeout/reset events "
|
|
f"(grace period {cfg['grace_period']}s, cooldown {cfg['cooldown']}s)")
|
|
|
|
q = queue.Queue()
|
|
threading.Thread(target=journal_reader, args=(q,), daemon=True).start()
|
|
|
|
pending = None
|
|
alert_state = {"last_alert": 0.0}
|
|
|
|
while True:
|
|
if pending is not None:
|
|
remaining = pending["deadline"] - time.monotonic()
|
|
if remaining <= 0:
|
|
finalize(cfg, pending, False, "grace period elapsed", alert_state)
|
|
pending = None
|
|
continue
|
|
try:
|
|
line = q.get(timeout=remaining)
|
|
except queue.Empty:
|
|
continue
|
|
else:
|
|
line = q.get()
|
|
|
|
if pending is None:
|
|
m = TIMEOUT_RE.search(line)
|
|
if m:
|
|
pending = {"device": m.group(1), "line": line, "count": 1,
|
|
"deadline": time.monotonic() + cfg["grace_period"]}
|
|
log(f"nvme timeout detected: {line}", "warn")
|
|
continue
|
|
|
|
if TIMEOUT_RE.search(line):
|
|
pending["count"] += 1
|
|
if pending["count"] >= 2:
|
|
finalize(cfg, pending, True, "repeated timeouts", alert_state)
|
|
pending = None
|
|
continue
|
|
|
|
if ESCALATION_RE.search(line):
|
|
pending["escalation_line"] = line
|
|
finalize(cfg, pending, True, "filesystem error followed", alert_state)
|
|
pending = None
|
|
|
|
|
|
if __name__ == "__main__":
|
|
try:
|
|
main()
|
|
except KeyboardInterrupt:
|
|
sys.exit(0)
|