power: add van-nvme-watch — pages on NVMe I/O-timeout/reset recurrence
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.
This commit is contained in:
Andreas Wrede
@@ -0,0 +1,261 @@
|
||||
#!/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)
|
||||
Reference in New Issue
Block a user