KrzyszurandClaude Opus 5.5
66cb804102
New guided check "Sensor data in the database (InfluxDB)", also the last step of the Quick check on the green path. It queries InfluxDB (read token) for the newest point per measurement of the box and tells apart: sensor data arrives / status arrives without sensor data / offline now / never seen / check not possible. Polls every 30 s for up to 4 minutes. With a stopped RTC in the log it concludes that sensor readings are lost (stamped 1 Jan 2000): box A4:CB:8F:C9:47:3C sent only device_status and microphone. - service/influx.py: query, CSV parsing, classification (no new deps) - guides: new step type "influx" (host answers via influx_result) - Settings > InfluxDB access (or KOTA_INFLUX_TOKEN); token never logged - service status mapping for tech.influx.* findings Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
337 lines
12 KiB
Python
337 lines
12 KiB
Python
"""Guided troubleshooting: runner + engine with simulated technician
|
|
answers, simulated board output and a fake clock."""
|
|
|
|
from pathlib import Path
|
|
|
|
import pytest
|
|
|
|
from kota_tech.core.logfile import read_log_file
|
|
from kota_tech.core.logline import parse_line
|
|
from kota_tech.diag.engine import DiagnosticsEngine, Severity
|
|
from kota_tech.diag.guides import LED_ANSWERS, GuideRunner, load_guides, recommended
|
|
|
|
FIX = Path(__file__).parent / "fixtures"
|
|
BOOT = ["ESP-ROM:esp32s3-20210327", "rst:0x1 (POWERON),boot:0x8 (SPI_FAST_FLASH_BOOT)",
|
|
"I (1299) app_init: Project name: kota-sensorboard",
|
|
"I (1317) app_init: ELF file SHA256: 45fa9d5b9..."]
|
|
|
|
|
|
class Clock:
|
|
def __init__(self):
|
|
self.t = 1000.0
|
|
|
|
def __call__(self):
|
|
return self.t
|
|
|
|
|
|
@pytest.fixture
|
|
def rig():
|
|
engine, clock, actions, log = DiagnosticsEngine(), Clock(), [], []
|
|
runner = GuideRunner(engine, on_action=lambda a: actions.append(a) or True,
|
|
on_log=log.append, clock=clock)
|
|
|
|
def board(*lines):
|
|
for ln in lines:
|
|
parsed = parse_line(ln)
|
|
engine.feed(parsed)
|
|
runner.feed(parsed)
|
|
|
|
return engine, runner, clock, actions, board, log
|
|
|
|
|
|
def _bench(engine):
|
|
for ln in read_log_file(FIX / "live_boot_A4CB8FC946F8_fw1.0.txt"):
|
|
engine.feed(ln)
|
|
|
|
|
|
def test_all_guides_load_and_validate():
|
|
guides = load_guides()
|
|
assert "quick" in guides and len(guides) >= 8
|
|
led = guides["quick"].steps["led"]
|
|
assert set(led.route) == set(LED_ANSWERS) # every colour has a route
|
|
|
|
|
|
def test_recommendations_follow_findings(rig):
|
|
engine, *_ = rig
|
|
_bench(engine)
|
|
ids = [g.id for g in recommended(load_guides(), engine)]
|
|
assert ids[0] == "quick"
|
|
assert ids.index("network") < ids.index("clock") # root order preserved
|
|
assert "mic" in ids
|
|
|
|
|
|
def test_purple_uncommissioned_box_skips_to_pairing_and_follows_it_live(rig):
|
|
engine, runner, clock, _, board, log = rig
|
|
_bench(engine) # log: not commissioned, LED purple
|
|
runner.start("quick")
|
|
runner.answer("PURPLE")
|
|
# "Was it paired before?" is skipped: the log already shows it is not.
|
|
assert runner.step.id == "pair_intro"
|
|
runner.proceed()
|
|
assert runner.view().waiting and runner.step.id == "pair_start"
|
|
board("I (90000) MAIN: Commissioning session started")
|
|
assert runner.step.id == "pair_wifi"
|
|
board("I (95000) MAIN: Commissioning complete")
|
|
assert runner.step.id == "pair_time"
|
|
board("I (99000) SNTP: Time synchronized: Sat Sep 26 16:00:00 2026")
|
|
assert runner.step.id == "pair_upload"
|
|
board("I (120000) INFLUX: HTTP request performed, status code: 204")
|
|
assert runner.end.id == "online" and runner.end.severity == "ok"
|
|
assert any("Paired" in t or "paired" in t for t in engine.technician)
|
|
assert "matter.not_commissioned" not in {rc.finding.rule_id for rc in engine.report().roots}
|
|
assert any(l.startswith("technician:") for l in log)
|
|
|
|
|
|
def test_pairing_timeout_asks_what_the_app_shows(rig):
|
|
engine, runner, clock, _, board, _ = rig
|
|
_bench(engine)
|
|
runner.start("network")
|
|
runner.proceed() # pair_intro -> pair_start
|
|
clock.t += 301
|
|
runner.tick()
|
|
assert runner.step.id == "not_found"
|
|
runner.answer("1")
|
|
assert runner.end.id == "ble_not_found"
|
|
f = engine.findings["tech.network.ble_not_found"]
|
|
assert f.severity == Severity.ERROR and f.active
|
|
|
|
|
|
def test_led_mismatch_is_recorded(rig):
|
|
engine, runner, *_ = rig
|
|
_bench(engine) # log implies PURPLE
|
|
runner.start("quick")
|
|
runner.answer("GREEN")
|
|
f = engine.findings["tech.led_mismatch"]
|
|
assert "Green" in f.title and "Purple" in f.title
|
|
assert runner.step.id == "heartbeat"
|
|
|
|
|
|
def test_led_match_records_nothing(rig):
|
|
engine, runner, *_ = rig
|
|
_bench(engine)
|
|
runner.start("quick")
|
|
runner.answer("PURPLE")
|
|
assert "tech.led_mismatch" not in engine.findings
|
|
|
|
|
|
def test_blue_reseat_fixed_after_power_cycle(rig):
|
|
engine, runner, clock, _, board, _ = rig
|
|
board(*BOOT, "E (3511) MAIN: Failed to initialize RTC: ESP_ERR_TIMEOUT")
|
|
runner.start("quick")
|
|
runner.answer("BLUE")
|
|
runner.proceed()
|
|
runner.proceed() # -> verify (technician power-cycles)
|
|
assert runner.step.id == "verify"
|
|
board(*BOOT, "I (14800) temperature_sensor: Range [20°C ~ 100°C], error < 2°C")
|
|
assert runner.end.id == "i2c_fixed"
|
|
|
|
|
|
def test_blue_still_failing_then_module(rig):
|
|
engine, runner, clock, _, board, _ = rig
|
|
board(*BOOT, "E (3511) MAIN: Failed to initialize RTC: ESP_ERR_TIMEOUT")
|
|
runner.start("rtc_i2c")
|
|
runner.proceed()
|
|
runner.proceed()
|
|
board(*BOOT, "E (3511) MAIN: Failed to initialize RTC: ESP_ERR_TIMEOUT")
|
|
assert runner.step.id == "damaged"
|
|
runner.answer("1")
|
|
assert runner.end.id == "rtc_module"
|
|
|
|
|
|
def test_white_skips_portal_question_on_v1_firmware(rig):
|
|
engine, runner, clock, _, board, _ = rig
|
|
board(*BOOT) # known v1.0: no setup portal
|
|
runner.start("white")
|
|
runner.answer("1") # nobody held the button
|
|
assert runner.step.id == "sd_reseat"
|
|
|
|
|
|
def test_white_asks_portal_question_on_unknown_firmware(rig):
|
|
engine, runner, clock, _, board, _ = rig
|
|
board("ESP-ROM:esp32s3-20210327", "I (1317) app_init: ELF file SHA256: 0123456789...")
|
|
runner.start("white")
|
|
runner.answer("1")
|
|
assert runner.step.id == "portal"
|
|
|
|
|
|
def test_red_routes_to_failing_sensor_and_names_it(rig):
|
|
engine, runner, clock, _, board, _ = rig
|
|
board(*BOOT, "E (14000) MAIN: Failed to initialize SEN66: ESP_ERR_TIMEOUT")
|
|
runner.start("sensors")
|
|
assert runner.step.id == "reseat"
|
|
assert "SEN66" in runner.view().text
|
|
runner.proceed()
|
|
board(*BOOT, "E (14000) MAIN: Failed to initialize SEN66: ESP_ERR_TIMEOUT")
|
|
assert runner.end.id == "sensor_replace"
|
|
|
|
|
|
def test_reboot_loop_resets_board_then_routes_by_cause(rig):
|
|
engine, runner, clock, actions, board, _ = rig
|
|
runner.start("reboot_loop")
|
|
assert actions == ["reset"]
|
|
board(*BOOT, "E (1519) SD_CARD: Failed to initialize the card (ESP_ERR_TIMEOUT). x")
|
|
clock.t += 46
|
|
runner.tick()
|
|
assert runner.guide.id == "white"
|
|
|
|
|
|
def test_reset_action_failure_is_shown(rig):
|
|
engine = DiagnosticsEngine()
|
|
runner = GuideRunner(engine, on_action=lambda a: False, clock=Clock())
|
|
runner.start("reboot_loop")
|
|
assert "connect" in runner.view().note.lower()
|
|
|
|
|
|
def test_mic_switch_flip_verified_without_restart(rig):
|
|
engine, runner, clock, actions, board, _ = rig
|
|
_bench(engine)
|
|
runner.start("mic")
|
|
assert runner.step.id == "switch"
|
|
assert "above the power switch" in runner.view().text
|
|
runner.answer("0") # flipped the external switch
|
|
assert actions == [] # the firmware re-reads it; no reset
|
|
board("I (95000) MICROPHONE: Read 300000 bytes in 4936 ms")
|
|
assert runner.end.id == "mic_on"
|
|
|
|
|
|
def test_mic_switch_no_effect_in_both_positions(rig):
|
|
engine, runner, clock, actions, board, _ = rig
|
|
_bench(engine)
|
|
runner.start("mic")
|
|
runner.answer("0")
|
|
board("W (95000) MICROPHONE: Microphone is in shutdown state, skipping sample collection")
|
|
assert runner.step.id == "flip_back"
|
|
runner.answer("0")
|
|
board("W (105000) MICROPHONE: Microphone is in shutdown state, skipping sample collection")
|
|
assert runner.end.id == "mic_switch_faulty"
|
|
|
|
|
|
def test_mic_clap_test_detects_dead_mic(rig):
|
|
engine, runner, clock, _, board, _ = rig
|
|
board(*BOOT, *["I (20036) MICROPHONE: Sum SQ: 0.000000, RMS pressure: 0.000000, "
|
|
"Normalized: 0.000000, dB peak: -inf"] * 2)
|
|
runner.start("mic")
|
|
assert runner.step.id == "clap"
|
|
board("I (30036) MICROPHONE: Sum SQ: 0.000000, RMS pressure: 0.000000, Normalized: 0.000000, dB peak: -inf")
|
|
clock.t += 46
|
|
runner.tick()
|
|
assert runner.end.id == "mic_faulty"
|
|
|
|
|
|
def test_mic_clap_test_passes_on_sound(rig):
|
|
engine, runner, clock, _, board, _ = rig
|
|
runner.start("mic")
|
|
board("I (30036) MICROPHONE: Sum SQ: 12.5, RMS pressure: 0.02, Normalized: 0.1, dB peak: 71.3")
|
|
assert runner.end.id == "mic_ok"
|
|
|
|
|
|
def test_back_never_reenters_a_wait(rig):
|
|
engine, runner, clock, actions, board, _ = rig
|
|
runner.start("sensors") # route -> capture (wait, resets board)
|
|
assert runner.step.id == "capture" and actions == ["reset"]
|
|
clock.t += 46
|
|
runner.tick() # -> which_again -> end:red_unclear
|
|
runner.back()
|
|
assert actions == ["reset"] # no second reset
|
|
|
|
|
|
def test_skip_wait_and_report_contains_technician_checks(rig):
|
|
engine, runner, clock, _, board, _ = rig
|
|
runner.start("update")
|
|
runner.proceed() # technician skips the wait
|
|
assert runner.end.id == "update_slow"
|
|
text = engine.report().to_text()
|
|
assert "Technician checks:" in text and "Update is taking very long" in text
|
|
|
|
|
|
# ------------------------------------------------------------ InfluxDB check
|
|
RTC_STOPPED = [*BOOT, "I (2945) KOTA: rtc running=0 time=2000-01-01T00:00:00"]
|
|
|
|
|
|
@pytest.fixture
|
|
def influx_rig(rig):
|
|
engine, runner, clock, actions, board, log = rig
|
|
return engine, runner, clock, actions, board
|
|
|
|
|
|
def test_influx_ok_ends_healthy(influx_rig):
|
|
engine, runner, clock, actions, board = influx_rig
|
|
runner.start("influx")
|
|
assert actions == ["influx"] and runner.view().waiting
|
|
runner.influx_result("ok", "Sensor data arrives in InfluxDB", ["Device status: 1 min ago"])
|
|
assert runner.end.id == "data_ok"
|
|
assert any("InfluxDB: Sensor data arrives" in t for t in engine.technician)
|
|
|
|
|
|
def test_influx_polls_until_sensors_arrive(influx_rig):
|
|
engine, runner, clock, actions, board = influx_rig
|
|
runner.start("influx")
|
|
runner.influx_result("sensors_missing", "Status arrives, sensor data does not: SEN66")
|
|
assert runner.end is None and "Checking again" in runner.view().note
|
|
clock.t += 10
|
|
runner.tick()
|
|
assert actions == ["influx"] # not yet
|
|
clock.t += 25
|
|
runner.tick()
|
|
assert actions == ["influx", "influx"] # polled again after poll_s
|
|
runner.tick()
|
|
assert actions == ["influx", "influx"] # no second query while one is pending
|
|
runner.influx_result("ok", "Sensor data arrives in InfluxDB")
|
|
assert runner.end.id == "data_ok"
|
|
|
|
|
|
def test_influx_repeated_answer_is_noted_once(influx_rig):
|
|
engine, runner, clock, actions, board = influx_rig
|
|
runner.start("influx")
|
|
for _ in range(3):
|
|
runner.influx_result("silent", "No recent data in InfluxDB")
|
|
clock.t += 31
|
|
runner.tick()
|
|
assert sum("InfluxDB:" in t for t in engine.technician) == 1
|
|
|
|
|
|
def test_influx_sensors_missing_with_stopped_clock(influx_rig):
|
|
engine, runner, clock, actions, board = influx_rig
|
|
board(*RTC_STOPPED)
|
|
runner.start("influx")
|
|
runner.influx_result("sensors_missing", "Status arrives, sensor data does not")
|
|
clock.t += 300 # past timeout_s
|
|
runner.tick()
|
|
assert runner.end.id == "sensors_clock"
|
|
f = engine.findings["tech.influx.sensors_clock"]
|
|
assert f.severity == Severity.ERROR and f.active
|
|
|
|
|
|
def test_influx_sensors_missing_without_log_cause(influx_rig):
|
|
engine, runner, clock, actions, board = influx_rig
|
|
runner.start("influx")
|
|
clock.t += 250
|
|
runner.influx_result("sensors_missing", "Status arrives, sensor data does not")
|
|
assert runner.end.id == "sensors_missing"
|
|
|
|
|
|
def test_influx_unavailable_and_stale_results(rig):
|
|
engine, runner, clock, actions, board, log = rig
|
|
runner._on_action = lambda a: False # no token / host cannot query
|
|
runner.start("influx")
|
|
assert runner.end.id == "unavailable"
|
|
runner.influx_result("ok", "late answer") # ignored: step already left
|
|
assert runner.end.id == "unavailable"
|
|
|
|
|
|
def test_influx_skip_uses_last_result(influx_rig):
|
|
engine, runner, clock, actions, board = influx_rig
|
|
runner.start("influx")
|
|
runner.influx_result("silent", "No recent data in InfluxDB")
|
|
runner.proceed()
|
|
assert runner.end.id == "silent"
|
|
|
|
|
|
def test_quick_check_green_ends_with_influx_check(influx_rig):
|
|
engine, runner, clock, actions, board = influx_rig
|
|
board(*BOOT)
|
|
runner.start("quick")
|
|
runner.answer("GREEN")
|
|
runner.answer("0") # heartbeat blinking
|
|
assert runner.guide.id == "influx" and actions == ["influx"]
|