Files
kota-technician-tool/kota_tech/diag/engine.py
T
kkallasandClaude Opus 5.5 0d21c5c205 Store all text files with LF line endings
Some files had been saved with CRLF on Windows, so a one-line change
showed as a whole-file diff. .gitattributes now stores text as LF
(.bat stays CRLF for cmd, .command/.sh LF for macOS).

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
2026-09-29 17:30:25 +02:00

1000 lines
47 KiB
Python

"""Diagnostics engine: parsed log lines -> findings, milestones, LED, verdict.
Line-level knowledge lives in rules.toml. This module adds what a single
line cannot express:
* boot tracking (ROM banner, reset reason, uptime drops when the banner
was missed) and classification of why the previous boot ended;
* the status-LED model (Status::set_status / set_status_conditional);
* crash capture (panic / ESP_ERROR_CHECK output);
* root-cause grouping via `explained_by` chains;
* the structured "KOTA:" lines of firmware 1.0.16+ (diag/kota.py): exact
status/LED, restart reasons, I2C/SD/RTC/Matter/mic self-report and the
60 s health line, plus error IDs ("[E-SD-03]") looked up in
error_ids.csv. Older firmware is still diagnosed from message text.
Findings are session-wide (a reboot loop must keep its cause visible);
milestones and the LED are per boot.
"""
from __future__ import annotations
import re
import tomllib
from collections import Counter, deque
from dataclasses import dataclass, field
from enum import IntEnum
from pathlib import Path
from ..core.logline import LineKind, LogLine
from . import kota
from .firmware import FirmwareInfo
RULES_PATH = Path(__file__).with_name("rules.toml")
_MAC_LINE = re.compile(r"Device MAC address: ([0-9A-Fa-f]{2}(?::[0-9A-Fa-f]{2}){5})")
class Severity(IntEnum):
IGNORE = -1
INFO = 1
WARNING = 2
ERROR = 3
CRITICAL = 4
@property
def label(self) -> str:
return self.name.capitalize()
# name -> (label, swatch colour)
LED = {
"UNKNOWN": ("Unknown", "#888888"),
"OFF": ("Off", "#444444"),
"GREEN": ("Green", "#2e9e44"),
"PURPLE": ("Purple", "#8e44ad"),
"RED": ("Red", "#d64541"),
"BLUE": ("Blue", "#2f6fd6"),
"CYAN": ("Cyan", "#1fc8d8"),
"YELLOW": ("Yellow", "#e6c229"),
"ORANGE": ("Orange", "#f08c1a"),
"WHITE": ("White", "#f4f4f4"),
}
# (id, label, optional) - optional milestones are listed only once reached.
MILESTONES = [
("rom_boot", "Board booted", False),
("app_started", "Firmware started", False),
("sd_mounted", "SD card mounted", False),
("env_loaded", "ENV.TXT read (InfluxDB settings)", False),
("matter_started", "Matter started", True),
("matter_commissioned", "Paired in Matter", True),
("local_wifi_mode", "Local Wi-Fi mode (SSID from SD card)", True),
("i2c_ok", "All sensors answer on the I2C bus", True),
("sensors_ready", "All sensors started", False),
("wifi_connected", "Connected to Wi-Fi", False),
("time_synced", "Clock set from the Internet", False),
("clock_verified", "Clock keeps time (RTC verified)", True),
("data_uploaded", "Data uploaded to InfluxDB", False),
("ota_registered", "Registered for firmware updates", False),
("ota_checked", "Checked for firmware updates", False),
("ota_update_started", "Firmware update started", True),
("ota_update_done", "Firmware update installed", True),
("ota_update_accepted", "Updated firmware accepted", True),
]
# Findings that stop start-up; a crash/reboot right after them is their effect.
_INIT_FAILURES = [
"rtc.init_failed", "sensor.init_failed", "sd.card_fail", "sd.mount_fail",
"sd.env_open_fail", "influx.env_missing", "influx.init_fail",
"kota.i2c_stuck", "kota.sensor_missing", "kota.rtc_read_failed", "kota.sd_unmounted",
]
_NETWORK_ROOTS = [
"influx.buffer_fail", "ota.check_failed", "net.dns_fail",
"matter.not_commissioned", "wifi.disconnected",
]
# Printed by the brown-out handler without a timestamp ("E BOD: ..."); on the
# ESP32-S3 the ROM then reports RTC_SW_SYS_RST, not a brown-out reset.
_BROWNOUT = "Brownout detector was triggered"
_RESET_BY_TOOL_WINDOW_S = 5.0
_SHORT_BOOT_MS = 60_000
class _Fmt(dict):
def __missing__(self, key: str) -> str:
return "?"
def _fmt(s: str, groups: dict[str, str]) -> str:
return s.format_map(_Fmt(groups)) if s else s
@dataclass(frozen=True)
class Rule:
id: str
pattern: re.Pattern[str] | None # None: raised from KOTA: fields
severity: Severity
title: str = ""
meaning: str = ""
actions: tuple[str, ...] = ()
explained_by: tuple[str, ...] = ()
milestone: str | None = None
clears: tuple[str, ...] = ()
led: str | None = None
led_from: str | None = None
split_by: str | None = None
min_count: int = 1
min_uptime_ms: int = 0
def load_rules(path: Path = RULES_PATH) -> list[Rule]:
data = tomllib.loads(path.read_text(encoding="utf-8"))
rules = []
for r in data["rule"]:
rules.append(Rule(
id=r["id"],
pattern=re.compile(r["pattern"]) if "pattern" in r else None,
severity=Severity[r["severity"].upper()],
title=r.get("title", ""),
meaning=r.get("meaning", ""),
actions=tuple(r.get("actions", ())),
explained_by=tuple(r.get("explained_by", ())),
milestone=r.get("milestone"),
clears=tuple(r.get("clears", ())),
led=r.get("led"),
led_from=r.get("led_from"),
split_by=r.get("split_by"),
min_count=int(r.get("min_count", 1)),
min_uptime_ms=int(r.get("min_uptime_ms", 0)),
))
_validate(rules)
return rules
def _validate(rules: list[Rule]) -> None:
ids = [r.id for r in rules]
dupes = [i for i, n in Counter(ids).items() if n > 1]
if dupes:
raise ValueError(f"duplicate rule ids: {dupes}")
known = set(ids)
for r in rules:
for ref in (*r.explained_by, *r.clears):
# status.* / reboot.* findings are created by the engine itself.
if ref not in known and not ref.startswith(("status.", "reboot.")):
raise ValueError(f"{r.id}: unknown rule id {ref!r}")
for colour in (r.led, r.led_from):
if colour and colour not in LED:
raise ValueError(f"{r.id}: unknown LED colour {colour!r}")
if r.severity != Severity.IGNORE and not r.title:
raise ValueError(f"{r.id}: visible rule needs a title")
@dataclass
class Finding:
key: str # rule id, or "rule id:split value"
rule_id: str
severity: Severity
title: str
meaning: str
actions: tuple[str, ...]
explained_by: tuple[str, ...] = ()
min_count: int = 1
count: int = 0
first_uptime_ms: int | None = None
last_uptime_ms: int | None = None
last_seen: float = 0.0
boot: int = 0
resolved: bool = False
resolved_by: str | None = None
evidence: deque[str] = field(default_factory=lambda: deque(maxlen=3))
error_ids: dict[str, str] = field(default_factory=dict) # "E-SD-03" -> technician action
@property
def active(self) -> bool:
return self.count >= self.min_count and not self.resolved
def seen_text(self) -> str:
"""'Seen 3x, first at 2.9 s after start, last at 61.2 s' (panel and service note)."""
s = f"Seen {self.count}x"
if self.first_uptime_ms is not None:
first = f"{self.first_uptime_ms / 1000:.1f}"
s += f", first at {first} s after start"
last = f"{self.last_uptime_ms / 1000:.1f}" if self.last_uptime_ms is not None else first
if self.count > 1 and last != first:
s += f", last at {last} s"
if self.resolved and self.resolved_by:
s += f" - resolved ({self.resolved_by})"
return s
@dataclass
class BootRecord:
index: int
host_time: float
explicit: bool # ROM banner seen (vs. inferred)
reset_reason: str | None = None
tool_reset: bool = False
last_uptime_ms: int = 0
saw_log: bool = False
led_at_end: str | None = None
panic_lines: list[str] = field(default_factory=list)
brownout: bool = False # "E BOD: Brownout detector was triggered" before the restart
recent_errors: deque[str] = field(default_factory=lambda: deque(maxlen=5))
intentional_restart: bool = False # factory reset / setup-mode toggle
# KOTA: lines (firmware 1.0.16+)
kota: dict[str, LogLine] = field(default_factory=dict) # last line per record
last_restart: str | None = None # "boot ... last_restart=" (why the previous boot ended)
restart_reason: str | None = None # "restart reason=" printed just before this boot ended
previous_status: tuple[str, int] | None = None # "led previous_boot status= code="
mode: str | None = None # matter | wifi | provisioning
@dataclass
class RootCause:
finding: Finding
consequences: list[Finding]
@property
def severity(self) -> Severity:
return max([self.finding.severity, *(c.severity for c in self.consequences)])
@dataclass
class Report:
verdict: str
verdict_severity: Severity | None # None = healthy / nothing found
led: str
led_reason: str
firmware: FirmwareInfo
milestones: list[tuple[str, str, int | None]] # (id, label, uptime_ms)
roots: list[RootCause]
earlier: list[Finding] # seen only in previous boots
resolved: list[Finding]
boots: list[BootRecord]
lines: int
mid_run: bool # no boot seen yet
technician: list[str] = field(default_factory=list) # guided-check answers
led_pattern: str = "" # "2 pulses", "solid", ... (exact when from a KOTA led line)
led_meaning: str = ""
led_exact: bool = False # reported by the box itself
box: list[tuple[str, str, str]] = field(default_factory=list) # (topic, text, ok|warn|bad|info)
matter_qr: str | None = None
matter_manual: str | None = None
def led_text(self) -> str:
t = LED[self.led][0] + (f", {self.led_pattern}" if self.led_pattern else "")
return t + (f" = {self.led_meaning}" if self.led_meaning else "")
def to_text(self) -> str:
out = [f"VERDICT: {self.verdict}",
f"Expected status LED: {self.led_text()}"
+ (f" (last change: {self.led_reason})" if self.led_reason else ""),
f"Firmware: {self.firmware.describe()}",
f"Boots seen: {max(len(self.boots) - (0 if self.boots and self.boots[0].explicit else 1), 0)}"]
if self.box:
out += ["", "Box self-report (KOTA lines):"]
out += [f" {topic}: {text}" for topic, text, _ in self.box]
out += ["", "Milestones (current boot):"]
for _, label, t in self.milestones:
out.append(f" [{'x' if t is not None else ' '}] {label}"
+ (f" @ {t / 1000:.1f} s" if t is not None else ""))
out.append("")
out.append("Findings:" if self.roots else "Findings: none")
for rc in self.roots:
out += _finding_text(rc.finding, " ")
for c in rc.consequences:
out.append(" consequence:")
out += _finding_text(c, " ")
if self.earlier:
out.append("")
out.append("Seen in earlier boots only:")
for f in self.earlier:
out.append(f" - [{f.severity.label}] {f.title} (x{f.count})")
if self.resolved:
out.append("")
out.append("Resolved during this session:")
for f in self.resolved:
out.append(f" - {f.title}" + (f" (by: {f.resolved_by})" if f.resolved_by else ""))
if self.technician:
out.append("")
out.append("Technician checks:")
out += [f" - {t}" for t in self.technician]
return "\n".join(out)
def _finding_text(f: Finding, ind: str) -> list[str]:
lines = [f"{ind}- [{f.severity.label}] {f.title} (x{f.count})", f"{ind} {f.meaning}"]
lines += [f"{ind} {i}. {a}" for i, a in enumerate(f.actions, 1)]
for eid, action in f.error_ids.items():
lines.append(f"{ind} error {eid}" + (f": {action}" if action else ""))
if f.evidence:
lines.append(f"{ind} log: {f.evidence[-1]}")
return lines
class DiagnosticsEngine:
def __init__(self, rules: list[Rule] | None = None):
self.rules = rules if rules is not None else load_rules()
self._rule_by_id = {r.id: r for r in self.rules}
self._pattern_rules = [r for r in self.rules if r.pattern is not None]
self.error_ids = kota.load_error_ids()
self.reset()
# ---------------------------------------------------------------- API
def reset(self) -> None:
self.findings: dict[str, Finding] = {}
self.boots: list[BootRecord] = [BootRecord(0, 0.0, explicit=False)]
self.milestones: dict[str, int] = {}
self.led = "UNKNOWN"
self.led_reason = ""
self.firmware = FirmwareInfo()
self.lines = 0
self._tool_reset_at: float | None = None
self._panic_tail = 0 # RAW lines after a panic line to keep
self.technician: list[str] = []
self.mac: str | None = None # from "ID: Device MAC address: ..." at boot
self.matter_advert: str | None = None # "Advertise commission parameter vendorID=..." line
self.matter_qr: str | None = None # "KOTA: matter ... qr=MT:..."
self.matter_manual: str | None = None
self.kota_seen = False # firmware prints KOTA: lines
self._reset_led_state()
def _reset_led_state(self) -> None:
self.led_pattern = ""
self.led_exact = False # a KOTA led line was seen this boot
self.status: tuple[str, int] | None = None
@property
def boot(self) -> BootRecord:
return self.boots[-1]
def feed(self, line: LogLine) -> None:
self.lines += 1
text = line.text
if line.kind == LineKind.HOST:
if "reset issued by tool" in text:
self._tool_reset_at = line.host_time
return
if _BROWNOUT in text:
self.boot.brownout = True
if line.kind == LineKind.BOOT:
self._new_boot(line.host_time, explicit=True)
self.milestones["rom_boot"] = 0
return
if line.kind == LineKind.RESET:
self.boot.reset_reason = line.reset_reason
if line.reset_reason and "POWERON" in line.reset_reason:
self.led, self.led_reason = "OFF", "power-on - firmware not started yet"
return
if line.kind in (LineKind.LOG, LineKind.KOTA) and line.uptime_ms is not None:
b = self.boot
# Uptime jumped back to a fresh-boot value: the ROM banner was
# missed (port reconnect, capture started late).
if b.saw_log and line.uptime_ms + 3000 < b.last_uptime_ms and line.uptime_ms < 10_000:
self._new_boot(line.host_time, explicit=False)
b = self.boot
b.saw_log = True
b.last_uptime_ms = max(b.last_uptime_ms, line.uptime_ms)
if line.kind == LineKind.PANIC:
self._on_panic(line)
elif self._panic_tail and line.kind == LineKind.RAW:
self.boot.panic_lines.append(text)
self._panic_tail -= 1
self._crash_finding().evidence.append(text)
if line.kind == LineKind.KOTA:
self._on_kota(line)
return
self.firmware.observe(text)
if m := _MAC_LINE.search(text):
self.mac = m.group(1).upper()
if "Advertise commission parameter" in text:
self.matter_advert = text
matched = False
hit: list[Finding] = []
rule_text = line.match_text
for rule in self._pattern_rules:
m = rule.pattern.search(rule_text)
if not m:
continue
matched = True
if rule.min_uptime_ms and (line.uptime_ms or 0) < rule.min_uptime_ms:
continue
groups = {k: v for k, v in m.groupdict().items() if v is not None}
if rule.milestone and rule.milestone not in self.milestones:
self.milestones[rule.milestone] = line.uptime_ms or 0
# The box's own "KOTA: led" lines are exact; message rules only guess.
if rule.led and not self.led_exact:
self._set_led(rule.led, rule.led_from, text)
for cid in rule.clears:
for f in self.findings.values():
if f.rule_id == cid and not f.resolved:
f.resolved = True
f.resolved_by = rule.milestone or rule.id
if rule.id in ("sys.factory_reset",) or "Short press:" in text:
self.boot.intentional_restart = True
if rule.severity != Severity.IGNORE:
hit.append(self._hit(rule, groups, line))
self._stateful(line)
if line.error_id:
info = self.error_ids.get(line.error_id)
for f in hit:
f.error_ids[line.error_id] = info.action if info else ""
if not matched:
self._hit_error_id(line, info)
if line.level == "E":
self.boot.recent_errors.append(text)
if not matched and line.tag and not line.error_id:
self._hit_other(line)
def report(self) -> Report:
all_f = list(self.findings.values()) + self._reboot_findings()
cur = self.boot.index
active = [f for f in all_f if f.active]
current = [f for f in active if f.boot == cur]
earlier = [f for f in active if f not in current]
resolved = [f for f in all_f if f.resolved and f.count >= f.min_count]
roots = _group(current)
# Worst consequence first, then the root's own severity, then order seen.
roots.sort(key=lambda rc: (-rc.severity, -rc.finding.severity, rc.finding.first_uptime_ms or 0))
mid_run = (not any(b.explicit or "i2c" in b.kota or "boot" in b.kota for b in self.boots)
and self.boot.index == 0)
if self.lines == 0:
verdict, vsev = "Waiting for data from the sensorbox...", None
elif roots and roots[0].severity >= Severity.WARNING:
vsev = roots[0].severity
prefix = "Problem" if vsev >= Severity.ERROR else "Attention"
verdict = f"{prefix}: {roots[0].finding.title}"
elif "data_uploaded" in self.milestones:
verdict, vsev = "Healthy: data is reaching InfluxDB", None
else:
verdict, vsev = "No problems found so far", None
if mid_run and self.lines:
verdict += " (connected mid-run - press Reset & capture for a full check)"
ms = [(mid, label, self.milestones.get(mid)) for mid, label, optional in MILESTONES
if not optional or mid in self.milestones]
# Reached milestones in the order they happened, then the pending ones.
ms.sort(key=lambda m: (m[2] is None, m[2] or 0))
pattern = self.led_pattern
return Report(verdict, vsev, self.led, self.led_reason, self.firmware, ms, roots,
earlier, resolved, list(self.boots), self.lines, mid_run, list(self.technician),
led_pattern=pattern, led_meaning=kota.led_meaning(self.led, pattern) if pattern else "",
led_exact=self.led_exact, box=self._box_summary(),
matter_qr=self.matter_qr, matter_manual=self.matter_manual)
def add_confirmed(self, key: str, severity: Severity, title: str, meaning: str,
actions: tuple[str, ...]) -> Finding:
"""A finding established by a guided check (technician answer + log)."""
f = self.findings.get(key)
if f is None:
f = self.findings[key] = Finding(key, key, severity, title, meaning, tuple(actions))
f.count += 1
f.boot = self.boot.index
f.resolved = False
f.evidence.append("confirmed by the technician during a guided check")
return f
def note_technician(self, text: str) -> None:
self.technician.append(text)
# ------------------------------------------------------------ internals
def _new_boot(self, host_time: float, explicit: bool) -> None:
prev = self.boot
# An inferred boot right after a banner-started boot is the same boot.
if not explicit and prev.explicit and not prev.saw_log:
return
prev.led_at_end = self.led
b = BootRecord(prev.index + 1, host_time, explicit)
if self._tool_reset_at is not None and host_time - self._tool_reset_at <= _RESET_BY_TOOL_WINDOW_S:
b.tool_reset = True
self._tool_reset_at = None
self.boots.append(b)
self.milestones = {}
# The WS2812 latches its colour through a software reset until
# Status::init() rewrites it; only a power-on turns it dark.
self.led_reason = "restarting - LED keeps its last colour until the firmware starts"
self.firmware = FirmwareInfo()
self._panic_tail = 0
self._reset_led_state()
def _set_led(self, colour: str, led_from: str | None, text: str) -> None:
if led_from and self.led != led_from:
return
self.led = colour
self.led_reason = text
def _hit(self, rule: Rule, groups: dict[str, str], line: LogLine) -> None:
key = rule.id
if rule.split_by and rule.split_by in groups:
key = f"{rule.id}:{groups[rule.split_by]}"
f = self.findings.get(key)
if f is None:
f = self.findings[key] = Finding(
key, rule.id, rule.severity, _fmt(rule.title, groups), _fmt(rule.meaning, groups),
tuple(_fmt(a, groups) for a in rule.actions), rule.explained_by, rule.min_count)
self._touch(f, line)
return f
def _touch(self, f: Finding, line: LogLine) -> None:
f.count += 1
# Uptime restarts every boot, so "first seen" is per current boot.
if f.first_uptime_ms is None or f.boot != self.boot.index:
f.first_uptime_ms = line.uptime_ms
f.last_uptime_ms = line.uptime_ms
f.last_seen = line.host_time
f.boot = self.boot.index
f.evidence.append(line.text)
if f.resolved:
f.resolved, f.resolved_by = False, None # problem came back
def _custom(self, key: str, severity: Severity, title: str, meaning: str,
actions: tuple[str, ...], explained_by: tuple[str, ...] = ()) -> Finding:
f = self.findings.get(key)
if f is None:
f = self.findings[key] = Finding(key, key, severity, title, meaning, actions, explained_by)
return f
def _hit_other(self, line: LogLine) -> None:
f = self._custom(
f"other.{line.tag}", Severity.INFO, f"Unrecognised error messages from {line.tag}",
"These errors are not in the rule set yet; they may be harmless.",
("If the box misbehaves, save the session log and send it to the firmware team.",))
self._touch(f, line)
def _crash_finding(self) -> Finding:
return self._custom(
"sys.crash", Severity.CRITICAL, "Firmware stopped with an error and restarts",
"The firmware hit a fatal error. The error printed just before it is the real cause.",
("See the grouped cause; otherwise save the session log for the firmware team.",),
tuple(_INIT_FAILURES) + ("reboot.brownout",))
def _on_panic(self, line: LogLine) -> None:
b = self.boot
if len(b.panic_lines) < 8:
b.panic_lines.append(line.text)
self._panic_tail = 4 # file/func/expression lines follow ESP_ERROR_CHECK
f = self._crash_finding()
if f.count == 0 and b.recent_errors:
f.meaning += f" Last error before it: {b.recent_errors[-1]}"
self._touch(f, line)
def _stateful(self, line: LogLine) -> None:
# RTC set by SNTP but reads "uninitialized" again later: the chip
# does not keep time (crystal/module fault), not just a flat cell.
synced = self.milestones.get("time_synced")
if (synced is not None and line.uptime_ms is not None
and line.uptime_ms > synced + 10_000
and "RTC is uninitialized" in line.text):
f = self._custom(
"rtc.lost_after_sync", Severity.ERROR,
"Clock stops again after being set from the Internet",
"The clock was set from the Internet but stopped running shortly after. The RTC module or its crystal is faulty.",
("Replace the RTC module (inside the case).",))
self._touch(f, line)
# ------------------------------------------------------- KOTA: lines
def _on_kota(self, line: LogLine) -> None:
self.kota_seen = True
rec, f = line.record or "", line.fields
# A second boot line in one boot: the ROM banner and the uptime drop
# were both missed (e.g. capture started with a gap).
if rec == "boot" and "boot" in self.boot.kota:
self._new_boot(line.host_time, explicit=False)
key = f"{rec}.verify" if rec == "rtc" and "verify" in line.words else rec
self.boot.kota[key] = line
handler = getattr(self, f"_kota_{rec}", None)
if handler is not None:
handler(line, f)
def _raise(self, rule_id: str, line: LogLine, groups: dict[str, str] | None = None) -> Finding:
"""Raise a rules.toml finding from parsed KOTA fields (no pattern matching)."""
return self._hit(self._rule_by_id[rule_id], groups or {}, line)
def _resolve(self, rule_id: str, by: str, key: str | None = None) -> None:
for f in self.findings.values():
if f.rule_id == rule_id and (key is None or f.key == key) and not f.resolved:
f.resolved, f.resolved_by = True, by
def _milestone(self, mid: str, line: LogLine) -> None:
if mid not in self.milestones:
self.milestones[mid] = line.uptime_ms or 0
def _kota_boot(self, line: LogLine, f: dict[str, str]) -> None:
b = self.boot
self.firmware.observe_kota(f)
mac = f.get("mac", "")
if re.fullmatch(r"[0-9A-Fa-f]{12}", mac):
self.mac = ":".join(mac[i:i + 2] for i in range(0, 12, 2)).upper()
b.reset_reason = b.reset_reason or f.get("reset")
b.last_restart = f.get("last_restart")
b.mode = f.get("mode")
self._milestone("app_started", line)
def _kota_restart(self, line: LogLine, f: dict[str, str]) -> None:
reason = f.get("reason", "")
self.boot.restart_reason = reason
if reason in kota.INTENTIONAL_RESTARTS:
self.boot.intentional_restart = True
def _kota_i2c(self, line: LogLine, f: dict[str, str]) -> None:
if f.get("bus") == "stuck":
self._raise("kota.i2c_stuck", line, {"sda": f.get("SDA", "?"), "scl": f.get("SCL", "?")})
return
self._resolve("kota.i2c_stuck", "I2C bus free again")
missing = False
for addr, value in f.items():
if not addr.startswith("0x") or value == "?":
continue
name = value.removesuffix("(missing)")
if value.endswith("(missing)"):
missing = True
self._raise("kota.sensor_missing", line, {"sensor": name, "addr": addr})
else:
self._resolve("kota.sensor_missing", f"{name} found on I2C", f"kota.sensor_missing:{name}")
if not missing:
self._milestone("i2c_ok", line)
def _kota_rtc(self, line: LogLine, f: dict[str, str]) -> None:
if "verify" in line.words:
if f.get("ok") == "1":
self._milestone("clock_verified", line)
self._resolve("kota.rtc_not_ticking", "clock verified")
else:
self._raise("kota.rtc_not_ticking", line,
{"running": f.get("running", "?"), "delta": f.get("delta", "no reading")})
elif "read_failed" in line.words:
self._raise("kota.rtc_read_failed", line, {"err": f.get("err", "?")})
elif f.get("running") == "0":
self._raise("kota.rtc_stopped", line, {"time": f.get("time", "?")})
elif f.get("running") == "1":
self._resolve("kota.rtc_read_failed", "clock answers")
self._resolve("kota.rtc_stopped", "clock running")
def _kota_sd(self, line: LogLine, f: dict[str, str]) -> None:
if f.get("mounted") == "0":
self._raise("kota.sd_unmounted", line, {"err": f.get("err", "card missing or unreadable")})
return
self._milestone("sd_mounted", line)
self._resolve("kota.sd_unmounted", "SD card mounted")
keys = {k for k in f.get("env_keys", "").split(",") if k and k != "-"}
missing = [k for k in ("INFLUX_URL", "INFLUX_TOKEN") if k not in keys]
for k in missing:
self._raise("influx.env_missing", line, {"key": k})
if not missing:
self._milestone("env_loaded", line)
if f.get("fs") and f["fs"] != "FAT32":
self._raise("kota.sd_not_fat32", line, {"fs": f["fs"]})
free = kota.parse_size_gb(f.get("free", ""))
if free is not None and free < 0.1:
self._raise("kota.sd_full", line, {"free": f["free"]})
lines = f.get("buffer_lines", "0")
if lines.isdigit() and int(lines) > 500:
self._raise("kota.buffer_backlog", line, {"lines": lines})
def _kota_matter(self, line: LogLine, f: dict[str, str]) -> None:
if f.get("qr", "-").startswith("MT:"):
self.matter_qr = f["qr"]
if f.get("manual", "-") != "-":
self.matter_manual = f["manual"]
fabrics = f.get("fabrics", "")
if fabrics == "0":
self._raise("matter.not_commissioned", line)
elif fabrics.isdigit():
self._milestone("matter_commissioned", line)
self._resolve("matter.not_commissioned", "paired in Matter")
def _kota_mic(self, line: LogLine, f: dict[str, str]) -> None:
if f.get("enabled") == "0":
self._raise("mic.disabled", line)
elif f.get("enabled") == "1":
self._resolve("mic.disabled", "microphone switched on")
def _kota_status(self, line: LogLine, f: dict[str, str]) -> None:
w = line.words
new = w[w.index("->") + 1] if "->" in w and w.index("->") + 1 < len(w) else (w[-1] if w else "")
code = int(f["code"]) if f.get("code", "").isdigit() else 0
self._apply_status(new, code, line, f.get("reason", ""))
def _apply_status(self, status: str, code: int, line: LogLine, reason: str) -> None:
self.status = (status, code)
if not self.led_exact:
self.led, self.led_pattern = kota.led_for_status(status, code)
self.led_reason = f"status {status}" + (f" code={code}" if code else "") + (
f", reason: {reason}" if reason else "")
sf = kota.status_finding(status, code)
key = sf[0] if sf else None
for fd in self.findings.values():
if fd.rule_id.startswith("status.") and fd.key != key and not fd.resolved:
fd.resolved, fd.resolved_by = True, f"status -> {status}"
if sf:
key, sev, title, meaning, actions, expl = sf
fd = self._custom(key, Severity[sev.upper()], title, meaning, actions, expl)
self._touch(fd, line)
def _kota_led(self, line: LogLine, f: dict[str, str]) -> None:
if "previous_boot" in line.words:
code = f.get("code", "0")
self.boot.previous_status = (f.get("status", "?"), int(code) if code.isdigit() else 0)
return
if "restart_flash" in line.words:
return
colour = kota.LED_COLOURS.get(f.get("color", ""))
if colour is None:
return
pattern = kota.pattern_text(f)
self.led, self.led_pattern, self.led_exact = ("OFF", "", True) if pattern == "off" else (colour, pattern, True)
if not self.led_reason or self.status is None:
self.led_reason = "reported by the box"
def _kota_health(self, line: LogLine, f: dict[str, str]) -> None:
up = kota.parse_seconds(f.get("up", "")) or 0
status = f.get("status", "")
# Connected mid-run: the health line is the first exact status we get.
if status and (self.status is None or self.status[0] != status):
self._apply_status(status, 0, line, "from the health report")
mode = self.boot.mode
wifi = f.get("wifi")
rssi = int(f["rssi"]) if f.get("rssi", "").lstrip("-").isdigit() else None
if wifi == "connected":
self._milestone("wifi_connected", line)
self._resolve("kota.wifi_down", "Wi-Fi connected")
if rssi is not None and rssi < -75:
self._raise("kota.weak_wifi", line, {"rssi": str(rssi)})
elif rssi is not None:
self._resolve("kota.weak_wifi", "signal OK")
elif wifi == "disconnected" and mode != "provisioning":
self._raise("kota.wifi_down", line)
if f.get("time_valid") == "1":
self._milestone("time_synced", line)
self._resolve("kota.time_invalid", "time valid")
elif f.get("time_valid") == "0" and up >= 120:
self._raise("kota.time_invalid", line)
if f.get("sd") == "missing":
self._raise("kota.sd_unmounted", line, {"err": "reported missing by the health check"})
last = f.get("last_upload", "never")
if last != "never":
self._milestone("data_uploaded", line)
self._resolve("kota.no_upload", "data uploaded")
elif wifi == "connected" and up >= 300:
self._raise("kota.no_upload", line)
heap = f.get("heap", "")
if heap.isdigit() and int(heap) < 20_000:
self._raise("kota.low_heap", line, {"heap": heap})
ota = f.get("ota")
if ota == "registered":
self._milestone("ota_registered", line)
self._resolve("kota.ota_unregistered", "registered")
elif ota == "unregistered" and wifi == "connected" and mode != "provisioning":
self._raise("kota.ota_unregistered", line)
def _hit_error_id(self, line: LogLine, info: kota.ErrorId | None) -> None:
eid = line.error_id or "?"
msg = (line.message or "").strip()
msg = msg if len(msg) <= 90 else msg[:87] + "..."
if info:
sev = Severity.WARNING if info.severity == "warning" else Severity.ERROR
f = self._custom(f"eid.{eid}", sev, f"{info.module_name}: {msg}",
f"The firmware reported error {eid} ({info.module_name}).",
(info.action, "If it repeats, save the session log for the firmware team."))
f.rule_id = f"eid.{info.module}"
f.error_ids[eid] = info.action
else:
f = self._custom(f"eid.{eid}", Severity.WARNING, f"Error {eid}: {msg}",
"This error ID is not in the tool's error table (newer firmware?).",
("Save the session log and send it to the firmware team.",))
self._touch(f, line)
def _box_summary(self) -> list[tuple[str, str, str]]:
"""What the box reported about itself in this boot (KOTA lines), for the panel."""
k = self.boot.kota
out: list[tuple[str, str, str]] = []
if ln := k.get("boot"):
f = ln.fields
lr = f.get("last_restart", "none")
bad = kota.restart_finding(lr) is not None
out.append(("Boot", f"v{f.get('fw', '?')} build {f.get('build', '?')}, mode {f.get('mode', '?')}, "
f"reset {f.get('reset', '?')}, last restart: {lr}", "warn" if bad else "ok"))
if ps := self.boot.previous_status:
if ps[0] != "OK":
out.append(("Before restart", f"status {ps[0]}" + (f" code={ps[1]}" if ps[1] else ""), "warn"))
if ln := k.get("i2c"):
f = ln.fields
if f.get("bus") == "stuck":
out.append(("I2C", f"bus stuck (SDA={f.get('SDA')}, SCL={f.get('SCL')})", "bad"))
else:
devs = [(v.removesuffix("(missing)"), v.endswith("(missing)"))
for a, v in f.items() if a.startswith("0x") and v != "?"]
miss = [n for n, m in devs if m]
text = ("missing: " + ", ".join(miss) + "; " if miss else "") + "found: " + (
", ".join(n for n, m in devs if not m) or "none")
out.append(("I2C", text, "bad" if miss else "ok"))
if ln := k.get("sd"):
f = ln.fields
if f.get("mounted") == "0":
out.append(("SD card", "not mounted" + (f" ({f['err']})" if f.get("err") else ""), "bad"))
else:
keys = f.get("env_keys", "-")
ok = "INFLUX_URL" in keys and "INFLUX_TOKEN" in keys
out.append(("SD card", f"{f.get('type', '?')} {f.get('size', '?')} {f.get('fs', '?')}, "
f"{f.get('free', '?')} free, ENV keys: {keys}, buffered: {f.get('buffer_lines', '?')}",
"ok" if ok else "bad"))
rtc, verify = k.get("rtc"), k.get("rtc.verify")
if rtc or verify:
parts, state = [], "ok"
if rtc:
if "read_failed" in rtc.words:
parts.append(f"read failed ({rtc.fields.get('err', '?')})")
state = "bad"
else:
running = rtc.fields.get("running") == "1"
parts.append(("running" if running else "STOPPED") + f", time {rtc.fields.get('time', '?')}")
state = "ok" if running else "warn"
if verify:
ok = verify.fields.get("ok") == "1"
parts.append("verified ticking" if ok else "NOT keeping time")
state = state if ok else "bad"
out.append(("Clock (RTC)", "; ".join(parts), state))
if ln := k.get("matter"):
f = ln.fields
fabrics = f.get("fabrics", "?")
out.append(("Matter", f"{'paired' if fabrics not in ('0', '?') else 'NOT paired'} (fabrics {fabrics}), "
f"pairing window {f.get('window', '?')}", "ok" if fabrics not in ("0", "?") else "warn"))
if ln := k.get("mic"):
on = ln.fields.get("enabled") == "1"
out.append(("Microphone", "on" if on else "switched OFF (switch on the back)", "ok" if on else "info"))
if ln := k.get("health"):
f = ln.fields
wifi = f.get("wifi", "?")
text = (f"up {f.get('up', '?')}, status {f.get('status', '?')}, Wi-Fi {wifi}"
+ (f" ({f.get('rssi')} dBm)" if wifi == "connected" else "")
+ f", time {'OK' if f.get('time_valid') == '1' else 'NOT set'}, SD {f.get('sd', '?')}, "
f"buffer {f.get('buffer', '?')}, heap {f.get('heap', '?')}, last upload {f.get('last_upload', '?')}"
+ ("" if f.get("last_upload") == "never" else " ago") + f", OTA {f.get('ota', '?')}")
good = f.get("status") == "OK" and wifi == "connected" and f.get("last_upload") != "never"
out.append(("Health", text, "ok" if good else "warn"))
return out
# ------------------------------------------------------------ reboots
def _reboot_findings(self) -> list[Finding]:
"""Classify why each earlier boot ended (needs the next boot's reset reason)."""
out: list[Finding] = []
short_unexpected: list[BootRecord] = []
cur = self.boot
# The box keeps its status across a restart ("led previous_boot"): if
# it was in an error state right before the latest restart (often the
# technician's Reset & capture), that state is worth showing.
if cur.previous_status and cur.previous_status[0] not in ("OK", "UPDATING", "SELF_CHECK"):
sf = kota.status_finding(*cur.previous_status)
st, code = cur.previous_status
# Only informative once the box reports OK again in this boot.
sev = Severity.INFO if self.status and self.status[0] == "OK" else Severity.WARNING
f = Finding("boot.previous_status", "boot.previous_status", sev,
f"Before the last restart: {sf[2] if sf else st}",
"The box remembers its status across a restart. Right before the latest restart it was in "
f"state {st}" + (f" code={code}" if code else "") + ". "
+ (sf[3] if sf else "") + " Check whether the problem comes back in this boot.",
sf[4] if sf else ())
f.count, f.boot, f.last_seen = 1, cur.index, cur.host_time
f.evidence.append(f"led previous_boot status={st} code={code}")
out.append(f)
for prev, nxt in zip(self.boots, self.boots[1:]):
if not prev.saw_log and prev.index == 0:
continue # nothing captured before the first boot
reason = nxt.reset_reason or "unknown"
if nxt.tool_reset or prev.intentional_restart:
continue
# Firmware 1.0.16+ records why it restarted itself.
last = nxt.last_restart or prev.restart_reason
if last in kota.INTENTIONAL_RESTARTS:
continue
key, sev, title, meaning, actions, expl = None, Severity.INFO, "", "", (), ()
rf = kota.restart_finding(last) if last else None
if prev.brownout or "BROWN" in reason or last == "brownout":
# A crash right after a brown-out is its effect, not a firmware bug.
key, sev, title = "reboot.brownout", Severity.CRITICAL, "Power supply voltage drops (brown-out)"
meaning = ("The supply voltage fell too low and the chip reset itself - typically when the "
"Wi-Fi/Bluetooth radio starts. The box cannot run like this.")
actions = ("Switch the box's power switch ON - USB from a laptop alone may not be enough.",
"Check the power supply, cable and connectors; try another supply.",
"If it persists on a good supply: the board's power circuit is faulty.")
elif rf and not (last == "panic" and prev.panic_lines):
sev_name, title, meaning, actions = rf
sev = Severity[sev_name.upper()]
key = {"status_watchdog": "reboot.status_watchdog", "panic": "reboot.crash",
"brownout": "reboot.brownout", "task_wdt": "reboot.watchdog", "int_wdt": "reboot.watchdog",
"wdt": "reboot.watchdog"}.get(last, f"reboot.{last}")
if nxt.previous_status and nxt.previous_status[0] != "OK":
st, code = nxt.previous_status
meaning += f" Before the restart the box was in state {st}" + (f" code={code}" if code else "") + "."
if last == "status_watchdog":
expl = tuple(_INIT_FAILURES) + kota._SENSOR_ROOTS + ("status.error", "sys.out_of_resources")
elif last == "status_oom_watchdog":
expl = ("sys.out_of_resources",)
elif rf:
pass # panic with captured crash output: covered by sys.crash
elif "USB_UART_CHIP_RESET" in reason:
key, title = "reboot.usb", "Box was reset over USB"
meaning = "The board was reset through its USB port (a flashing tool, a serial program, or this tool in an earlier session)."
elif "POWERON" in reason:
key, title = "reboot.power", "Box was switched off and on"
meaning = "Power was interrupted (power switch, cable or supply)."
actions = ("If nobody switched it off: check the power supply and cable.",)
elif "WDT" in reason:
key, sev, title = "reboot.watchdog", Severity.ERROR, "Firmware froze and was restarted by the watchdog"
meaning = "The firmware stopped responding; the hardware watchdog restarted it."
actions = ("Save the session log for the firmware team.",)
elif prev.panic_lines:
pass # covered by sys.crash
elif (not nxt.last_restart and prev.led_at_end in ("PURPLE", "RED")
and prev.last_uptime_ms >= 140_000): # older firmware: no restart record
key, title = "reboot.status_watchdog", "Box restarted itself after 2.5 minutes of errors"
meaning = "By design the firmware restarts when it stays in an error state (purple/red) for 150 s."
actions = ("Fix the grouped cause; the restarts stop by themselves.",)
expl = tuple(_NETWORK_ROOTS) + ("sys.out_of_resources",)
else:
key, sev, title = "reboot.unexpected", Severity.WARNING, "Unexpected restart"
meaning = f"The firmware restarted (reset reason {reason})."
actions = ("Watch whether it repeats; save the session log for the firmware team.",)
if key:
out.append(self._reboot_finding(key, sev, title, meaning, actions, expl, nxt))
if prev.last_uptime_ms < _SHORT_BOOT_MS and "POWERON" not in reason:
short_unexpected.append(prev)
if len(short_unexpected) >= 2:
avg = sum(b.last_uptime_ms for b in short_unexpected) / len(short_unexpected) / 1000
f = self._reboot_finding(
"reboot.loop", Severity.CRITICAL, "Reboot loop",
f"The box restarted {len(short_unexpected)} times, about every {avg:.0f} s. "
"The error printed just before each restart is the cause.",
("Fix the grouped cause below.",), tuple(_INIT_FAILURES) + ("reboot.brownout",), self.boot)
f.count = len(short_unexpected)
out.append(f)
# One finding per cause, counting how often it happened.
merged: dict[str, Finding] = {}
for f in out:
if f.key in merged:
merged[f.key].count += f.count
merged[f.key].evidence.extend(f.evidence)
else:
merged[f.key] = f
return list(merged.values())
def _reboot_finding(self, key, sev, title, meaning, actions, expl, boot: BootRecord) -> Finding:
f = Finding(key, key, sev, title, meaning, actions, expl)
f.count, f.boot, f.last_seen = 1, self.boot.index, boot.host_time
if boot.reset_reason:
f.evidence.append(f"reset reason: {boot.reset_reason}")
return f
def _group(findings: list[Finding]) -> list[RootCause]:
"""Attach each finding to the root of its explained_by chain."""
by_rule: dict[str, list[Finding]] = {}
for f in findings:
by_rule.setdefault(f.rule_id, []).append(f)
def parent(f: Finding) -> Finding | None:
for rid in f.explained_by:
if by_rule.get(rid):
return by_rule[rid][0]
return None
def root(f: Finding) -> Finding:
seen = {f.key}
while (p := parent(f)) is not None and p.key not in seen:
seen.add(p.key)
f = p
return f
roots: dict[str, RootCause] = {}
for f in findings:
r = root(f)
rc = roots.setdefault(r.key, RootCause(r, []))
if r is not f:
rc.consequences.append(f)
for rc in roots.values():
rc.consequences.sort(key=lambda c: (-c.severity, c.first_uptime_ms or 0))
return list(roots.values())