diff --git a/CONTEXT.md b/CONTEXT.md index 4f03cf6..453e93b 100644 --- a/CONTEXT.md +++ b/CONTEXT.md @@ -120,6 +120,10 @@ _Avoid_: trial, test mode Returning automatically to the previous firmware when new firmware resets or crashes during Probation. _Avoid_: revert, downgrade (a downgrade is installing an older version on purpose) +**Safe Mode**: +What the firmware starts instead of everything else after 3 crash restarts in a row: Wi-Fi and Firmware Updates (and the Debug Console in a Debug Build), so it can be fixed without a cable. A normal restart leaves it. +_Avoid_: recovery mode, failsafe + **Debug Build**: A firmware built with the remote debugging aids compiled in (`+debug` in its version). Release builds have none of them. _Avoid_: dev build, test build (a test build is one made to fail on purpose, such as a crashing update) @@ -139,6 +143,7 @@ _Avoid_: telnet, remote shell - Every transmission is bounded by the **Region** and its **Duty Cycle Budget**. - Past 90% SD usage, **Logs** stop being written; the remaining space is kept for **Captures**. Nothing is deleted without the user's confirmation. - A **Firmware Update** installs an **Update File**; the new firmware runs on **Probation**, and fails back by **Rollback**. +- **Rollback** covers new firmware; **Safe Mode** covers confirmed firmware that keeps crashing. - A **Node** may be in several **Channels**. A **Direct Message** targets exactly one **Node**. ## Flagged ambiguities diff --git a/README.md b/README.md index 66eb8c1..71eb25a 100644 --- a/README.md +++ b/README.md @@ -74,6 +74,9 @@ To install from the SD card instead, copy the `.ota` file from `.pio/build/cardp | `tasks` | FreeRTOS tasks: state, priority, lowest free stack, CPU share | | `reboot` / `boot other` | Restart, or restart into the other app slot (a manual Rollback) | | `log level <0-5>` | ESP-IDF log level | +| `crash` | The last crash: which firmware, why, task, PC and backtrace (from the core dump in flash) | +| `coredump erase` | Forgets the core dump | +| `crash abort` / `crash wdt` | Debug Builds: crash on purpose, or hang the main loop until the watchdog fires | | `help` | Lists the commands | `scripts/flash.sh` stops a running serial log first, since it would hold the port. @@ -88,4 +91,14 @@ scripts/rdbg.py info # one command and its reply scripts/rdbg.py -b tasks # the same, after the backlog (boot messages and so on) ``` -Every command above works there too. The token is in `~/.config/roro9stack/debug-token`, made by the first build; keep developing on Debug Builds, so the firmware a Rollback returns to always has the console. +Every command above works there too, plus a few handled by the PC side or the console's own task: + +```sh +scripts/rdbg.py crash # the last crash, its backtrace decoded against that exact build's ELF +scripts/rdbg.py coredump # fetch the core dump and decode it all (registers, every task) with esp-coredump +scripts/rdbg.py reset # restart at once, even if the main loop is stuck +``` + +Every build keeps its ELF in `.pio/elves/` (version and digest in the name) for that; `scripts/decode_backtrace.sh ` decodes any backtrace by hand. + +After 3 crash restarts in a row the firmware starts in **Safe Mode** (ADR 0005): only Wi-Fi, Firmware Updates and the Debug Console, so a fix can be pushed as usual. `reboot` leaves it. The token is in `~/.config/roro9stack/debug-token`, made by the first build; keep developing on Debug Builds, so the firmware a Rollback returns to always has the console. diff --git a/docs/adr/0005-safe-mode-crash-reports-watchdog.md b/docs/adr/0005-safe-mode-crash-reports-watchdog.md new file mode 100644 index 0000000..64cf099 --- /dev/null +++ b/docs/adr/0005-safe-mode-crash-reports-watchdog.md @@ -0,0 +1,13 @@ +# Safe Mode, crash reports and a watched main loop, in every build + +Rollback protects against new firmware that fails Probation. It does nothing for firmware that was confirmed and crashes later: a corrupt setting, a server that sends something unexpected, a bug that takes an hour to show. Without a cable, such a device would restart forever. Three measures, in release and Debug Builds alike, keep it reachable: + +- **Safe Mode.** The firmware counts starts that follow a crash (panic or watchdog) in NVS, first thing at boot. After 3 in a row, it starts only the clock, Wi-Fi, the Update Service and, in a Debug Build, the Debug Console: no Apps, no IRC, no SD card, and a screen that says so with the address to push an update to. Any normal restart (a `reboot`, an update), or a minute of uptime, resets the count. +- **Crash reports.** The same boot record keeps which version was running, so after a crash the firmware knows which one crashed, even when a Rollback has switched slots since. ESP-IDF already writes a core dump to its flash partition on a panic; after the restart the firmware prints its summary (task, PC, reason, backtrace) and raises a Notification. The `crash` command shows it again later. In a Debug Build, `scripts/rdbg.py crash` decodes the backtrace and `scripts/rdbg.py coredump` fetches the whole dump for `esp-coredump`, against the ELF of that exact build (`.pio/elves/`, named by version and ELF digest). +- **The main loop is watched.** Arduino-ESP32 subscribes only core 0's idle task to the task watchdog, and the main loop runs on core 1: a stuck loop used to hang the device for good, with the screen frozen and the Debug Console unable to run commands. `enableLoopWDT()` makes a loop stuck for 5 s a panic, with a core dump, counted towards Safe Mode. And an installed update no longer depends on the main loop: the Update Service restarts into it by itself after 90 s. + +## Consequences + +- Nothing in the main loop may block for 5 s. Network and card work already run on their own tasks. +- Safe Mode can't help when Wi-Fi or the Update Service itself is what crashes; that still needs USB. +- Three crashes within a minute of each restart are needed to reach Safe Mode, so a crash loop costs about half a minute before the device becomes reachable. diff --git a/lib/ota/src/safe_mode.h b/lib/ota/src/safe_mode.h new file mode 100644 index 0000000..fb6e0e6 --- /dev/null +++ b/lib/ota/src/safe_mode.h @@ -0,0 +1,21 @@ +#pragma once + +#include + +namespace roro { + +// Safe Mode (CONTEXT.md): after kCrashLimit starts in a row that ended in a crash, the firmware +// starts only what it takes to be fixed over the air (Wi-Fi, Firmware Updates, the Debug Console). +// Rollback covers new firmware; this covers firmware that was confirmed and crashes anyway. +struct SafeMode { + static constexpr int kCrashLimit = 3; + static constexpr uint32_t kStableAfterMs = 60000; // then the count starts over + + // Called first thing at boot with the count so far; returns the new count. + static int countAtBoot(bool lastStartWasCrash, int crashesBefore) { + return lastStartWasCrash ? crashesBefore + 1 : 0; + } + static bool active(int crashes) { return crashes >= kCrashLimit; } +}; + +} // namespace roro diff --git a/scripts/decode_backtrace.sh b/scripts/decode_backtrace.sh new file mode 100755 index 0000000..bd87030 --- /dev/null +++ b/scripts/decode_backtrace.sh @@ -0,0 +1,12 @@ +#!/usr/bin/env bash +# Turns crash addresses into functions and source lines, using the archived ELF of the build that +# crashed (.pio/elves/, kept by scripts/version.py). +# Usage: scripts/decode_backtrace.sh
... +set -euo pipefail +source "$(dirname "$0")/_docker.sh" +[ $# -ge 2 ] || { echo "Usage: scripts/decode_backtrace.sh
..." >&2; exit 1; } +ELF="$(ls -t "$ROOT"/.pio/elves/*"$1"*.elf 2>/dev/null | head -1 || true)" +[ -n "$ELF" ] || { echo "No archived ELF matches '$1' in .pio/elves/" >&2; exit 1; } +echo "using ${ELF#$ROOT/}" >&2 +DOCKER_EXTRA=() +run_in_container /pio/tools/toolchain-xtensa-esp-elf/bin/xtensa-esp32s3-elf-addr2line -pfiaC -e "/work/${ELF#$ROOT/}" "${@:2}" diff --git a/scripts/decode_coredump.sh b/scripts/decode_coredump.sh new file mode 100755 index 0000000..c9612e0 --- /dev/null +++ b/scripts/decode_coredump.sh @@ -0,0 +1,15 @@ +#!/usr/bin/env bash +# Full post-mortem of a core dump fetched with `scripts/rdbg.py coredump`: every task's backtrace, +# registers and the crashed task's stack, via esp-coredump and GDB in the container. +# Usage: scripts/decode_coredump.sh +set -euo pipefail +source "$(dirname "$0")/_docker.sh" +[ $# -eq 2 ] || { echo "Usage: scripts/decode_coredump.sh " >&2; exit 1; } +CORE="$(realpath "$1")" +ELF="$(ls -t "$ROOT"/.pio/elves/*"$2"*.elf 2>/dev/null | head -1 || true)" +[ -n "$ELF" ] || { echo "No archived ELF matches '$2' in .pio/elves/" >&2; exit 1; } +echo "using ${ELF#$ROOT/}" >&2 +DOCKER_EXTRA=(-v "$(dirname "$CORE"):/core:ro") +run_in_container /pio/penv/bin/esp-coredump --chip esp32s3 info_corefile -t raw \ + -g /pio/tools/tool-xtensa-esp-elf-gdb/bin/xtensa-esp32s3-elf-gdb \ + -c "/core/$(basename "$CORE")" "/work/${ELF#$ROOT/}" diff --git a/scripts/rdbg.py b/scripts/rdbg.py index 1dccaf5..3ac918f 100755 --- a/scripts/rdbg.py +++ b/scripts/rdbg.py @@ -6,10 +6,16 @@ Usage: scripts/rdbg.py [-H host] [-b] [command ...] command runs it and prints what follows, until the console has been quiet for a moment -H host the device's IP (Settings > Firmware), default $RORO_OTA_HOST -b also print the backlog the device sends on connecting (boot messages and so on) + +Commands handled here as well as on the device: + crash the last crash, with its backtrace decoded (scripts/decode_backtrace.sh) + coredump [file] fetch the core dump (default core-.bin) and decode it with esp-coredump The token is read from ~/.config/roro9stack/debug-token (made by the first build). """ import os +import re import select +import subprocess import socket import sys import time @@ -48,6 +54,86 @@ def read_until_quiet(sock, quiet, out): out.flush() +SCRIPTS = os.path.dirname(os.path.abspath(__file__)) + + +def run(sock, command, out=sys.stdout): + """Sends one command and returns its reply (also copied to `out`).""" + sock.sendall((command + "\n").encode()) + # The main loop echoes "> command" when it runs it; the reply follows. + echoed = read_until(sock, f"> {command}\n".encode(), 15) + if echoed is None: + sys.exit("device: the command never ran") + reply = echoed.decode(errors="replace").split(f"> {command}\n", 1)[1] + + class Tee: + def write(self, text): + nonlocal reply + reply += text + if out: + out.write(text) + + def flush(self): + if out: + out.flush() + + if out: + out.write(reply) + try: + read_until_quiet(sock, 1.5, Tee()) + except BrokenPipeError: # e.g. piped into head + pass + return reply + + +def crash_firmware(reply): + """The archived-ELF key for the crashed firmware: its ELF digest, or else its version.""" + sha = re.search(r"elf sha256 ([0-9a-f]{8,})", reply) + if sha: + return sha.group(1) + version = re.search(r"last one in (\S+)", reply) + return version.group(1) if version else None + + +def crash(sock): + reply = run(sock, "crash") + trace = re.search(r"backtrace((?: 0x[0-9a-f]+)+)", reply) + key = crash_firmware(reply) + if trace and key: + print() + subprocess.call([os.path.join(SCRIPTS, "decode_backtrace.sh"), key] + trace.group(1).split()) + + +def coredump(sock, path): + info = run(sock, "crash", out=None) + sock.sendall(b"coredump get\n") + # One buffer throughout: the header, the size and the first bytes often share a packet. + buf = b"" + sock.settimeout(15) + while b"coredump: none" not in buf and not re.search(rb"coredump: data (\d+)\n", buf): + chunk = sock.recv(65536) + if not chunk: + sys.exit("device: closed the connection") + buf += chunk + header = re.search(rb"coredump: data (\d+)\n", buf) + if not header: + sys.exit("device: no core dump in flash") + size = int(header.group(1)) + data = buf[header.end():] + while len(data) < size: + chunk = sock.recv(65536) + if not chunk: + sys.exit(f"device: the connection closed after {len(data)} of {size} bytes") + data += chunk + data = data[:size] + path = path or time.strftime("core-%Y%m%d-%H%M%S.bin") + open(path, "wb").write(data) + print(f"saved {path} ({size} bytes)") + key = crash_firmware(info) + if key: + subprocess.call([os.path.join(SCRIPTS, "decode_coredump.sh"), path, key]) + + def interactive(sock): sock.setblocking(False) while True: @@ -93,18 +179,19 @@ def main(): read_until_quiet(sock, 0.5, show) # the backlog if not args: return interactive(sock) - command = " ".join(args) - sock.sendall((command + "\n").encode()) - # The main loop echoes "> command" when it runs it; the reply follows. - echoed = read_until(sock, f"> {command}\n".encode(), 15) - if echoed is None: - sys.exit("device: the command never ran") - sys.stdout.write(echoed.decode(errors="replace").split(f"> {command}\n", 1)[1]) - try: - read_until_quiet(sock, 1.5, sys.stdout) - except BrokenPipeError: # e.g. piped into head - pass + if args == ["crash"]: + return crash(sock) + if args == ["reset"]: # answered by the console's own task, not the main loop + sock.sendall(b"reset\n") + print((read_until(sock, b"restarting now\n", 10) or b"device: no answer").decode().strip().splitlines()[-1]) + return + if args[0] == "coredump" and args[1:2] != ["erase"]: + return coredump(sock, args[1] if len(args) > 1 else None) + run(sock, " ".join(args)) if __name__ == "__main__": - main() + try: + main() + except (ConnectionResetError, BrokenPipeError): + sys.exit("device: the connection dropped (restarting?)") diff --git a/scripts/version.py b/scripts/version.py index 4fec600..1ac29f3 100644 --- a/scripts/version.py +++ b/scripts/version.py @@ -14,3 +14,20 @@ if env["PIOENV"].endswith("-debug"): # noqa: F821 version += "+debug" # a Debug Build says so wherever the version shows env.Append(CPPDEFINES=[("RORO_VERSION", '\\"%s\\"' % version)]) # noqa: F821 + + +# Keep every build's ELF, named by version and the first 16 hex digits of its SHA-256 (the core dump +# names the crashed firmware by the same digest), so a crash can be decoded after later builds. +def archive_elf(source, target, env): + import hashlib + import os + import shutil + + elf = str(target[0]) + digest = hashlib.sha256(open(elf, "rb").read()).hexdigest()[:16] + folder = os.path.join(env.subst("$PROJECT_DIR"), ".pio", "elves") + os.makedirs(folder, exist_ok=True) + shutil.copy(elf, os.path.join(folder, "%s.%s.elf" % (version, digest))) + + +env.AddPostAction("$BUILD_DIR/${PROGNAME}.elf", archive_elf) # noqa: F821 diff --git a/src/main.cpp b/src/main.cpp index 8529d5e..d8b61ef 100644 --- a/src/main.cpp +++ b/src/main.cpp @@ -16,6 +16,7 @@ #include "file_receiver.h" #include "key_mapper.h" #include "platform/console.h" +#include "platform/crash_report.h" #include "platform/nvs_store.h" #include "platform/system_info.h" #include "service_manager.h" @@ -28,6 +29,7 @@ #include "services/storage_service.h" #include "services/update_service.h" #include "services/wifi_service.h" +#include "safe_mode.h" #include "settings.h" #include "storage_paths.h" #include "ui/notifier.h" @@ -58,6 +60,7 @@ static DebugConsole* debugConsole; static Notifier* notifier; static LauncherApp launcher; static AppManager* apps; +static bool safeMode = false; // see SafeMode: only what it takes to be fixed over the air static RawKeys readKeys() { auto state = M5Cardputer.Keyboard.keysState(); @@ -104,9 +107,13 @@ static StatusInfo currentStatus() { // (UpdateService::tick) decides instead, and an unconfirmed image stays PENDING_VERIFY. extern "C" bool verifyRollbackLater() { return true; } // C linkage, or the weak default wins +static void setupSafeMode(int crashes); + void setup() { nvs.begin(); UpdateService::bootGuard(nvs); // first: before anything that could crash on new firmware + int crashes = crash_report::noteBoot(nvs); + safeMode = SafeMode::active(crashes); Serial.setRxBufferSize(2 * FileReceiver::kChunk); // before the port opens; sd put sends 1 chunk at a time Serial.setTxBufferSize(2048); // the console skips Serial when it's full: room for a burst like `tasks` @@ -116,6 +123,7 @@ void setup() { Serial.begin(115200); settings.load(); + if (safeMode) return setupSafeMode(crashes); battery = new BatteryService(bus); storageService = new StorageService(bus); @@ -157,6 +165,39 @@ void setup() { if (!settings.getBool(Setting::SetupDone)) apps->openModal("setup"); console.printf("%s %s ready, free heap %u, last start: %s\n", kProductName, versionString(), ESP.getFreeHeap(), system_info::resetReason()); + if (system_info::resetWasCrash()) { + crash_report::print(console, nvs); + bus.publish(Event::withText(EventType::Notification, crash_report::headline().c_str(), + static_cast(NotificationLevel::Warning))); + } + // A main loop stuck for 5 s panics (and leaves a core dump) instead of hanging forever: Arduino + // only watches the idle task on core 0, and the loop runs on core 1. + enableLoopWDT(); +} + +// Safe Mode: Wi-Fi, the clock, Firmware Updates and (in a Debug Build) the Debug Console. No Apps, +// no IRC, no SD card: whatever crashed three times in a row is most likely among them. +static void setupSafeMode(int crashes) { + clockService = new ClockService(settings, bus); + savedNetworks = new SavedNetworks(nvs); + savedNetworks->load(); + wifi = new WifiService(settings, *savedNetworks, *clockService); + storageService = new StorageService(bus); // never started: no card access + update = new UpdateService(nvs, *wifi, *savedNetworks, *storageService, bus, settings); + services.add(*clockService); + services.add(*wifi); + services.add(*update); +#ifdef RORO_DEBUG + debugConsole = new DebugConsole(*wifi); + services.add(*debugConsole); +#endif + bus.subscribe(EventType::Notification, [](const Event& e) { console.printf("notification: %s\n", e.text); }); + screen.begin(); + services.startAll(millis()); + console.printf("%s %s in SAFE MODE: %d crash restarts in a row. Only Wi-Fi and Firmware Updates run.\n", + kProductName, versionString(), crashes); + crash_report::print(console, nvs); + enableLoopWDT(); } // Dev aid: commands to drive the UI without the keyboard, from the serial port or the Debug Console. @@ -276,19 +317,31 @@ static const char* const kHelp = "reboot restart\n" "boot other restart into the other app slot (manual Rollback)\n" "log level <0-5> ESP-IDF log level (0 none ... 5 verbose)\n" + "crash the last crash: firmware, reason, task, backtrace\n" + "coredump erase forget the core dump in flash\n" "key press a key: up down left right select back home, or one character\n" "wifi status | wifi add \n" "irc start | irc dump | irc say \n" "sd list | cat | log | burst | sound on|off | short | normal\n" #ifdef RORO_DEBUG "crash abort|wdt crash on purpose (to test crash reports and Safe Mode)\n" + "coredump get (Debug Console only) send the raw core dump: use scripts/rdbg.py coredump\n" + "reset (Debug Console only) restart at once, even if the main loop is stuck\n" "quit close the Debug Console connection\n" #endif ; +// Commands that only touch what Safe Mode starts. +static bool safeModeCommand(const String& line) { + return line == "help" || line == "info" || line == "tasks" || line == "reboot" || line == "boot other" || + line.startsWith("log level ") || line.startsWith("crash") || line.startsWith("coredump") || + line == "wifi status" || line.startsWith("wifi add "); +} + static void runCommand(String line) { line.trim(); if (line.isEmpty()) return; + if (safeMode && !safeModeCommand(line)) return (void)console.println("not available in Safe Mode"); if (line == "help") console.print(kHelp); if (line == "info") { system_info::printSystem(console); @@ -309,6 +362,8 @@ static void runCommand(String line) { esp_log_level_set("*", static_cast(constrain(level, 0, 5))); console.printf("log level: %d\n", constrain(level, 0, 5)); } + if (line == "crash") crash_report::print(console, nvs); + if (line == "coredump erase") console.println(crash_report::erase() ? "coredump: erased" : "coredump: nothing to erase"); #ifdef RORO_DEBUG if (line == "crash abort") abort(); if (line == "crash wdt") @@ -410,7 +465,48 @@ static void serialCommands() { } } +static void remoteCommands() { +#ifdef RORO_DEBUG + for (std::string remote; debugConsole->takeCommand(remote);) { + console.printf("> %s\n", remote.c_str()); // so the transcript reads the same on both ends + runCommand(remote.c_str()); + } +#endif +} + +// After a minute up, the crash streak is over (SafeMode counts starts that crash in a row). +static void noteStableOnce(uint32_t now) { + static bool noted = false; + if (noted || now < SafeMode::kStableAfterMs) return; + noted = true; + crash_report::noteStable(nvs); +} + +static void loopSafeMode() { + uint32_t now = millis(); + serialCommands(); + remoteCommands(); + services.tick(now); + bus.dispatch(); + noteStableOnce(now); + if (update->phase() == UpdateService::Phase::Installed) { + screen.renderUpdate("Restarting", "into " + update->incomingVersion(), -1); + delay(800); + ESP.restart(); + } + static uint32_t lastDraw = 0; + if (update->phase() == UpdateService::Phase::Receiving) { + screen.renderUpdate("Firmware update", "Receiving " + update->incomingVersion(), update->percent()); + } else if (now - lastDraw > 2000 || !lastDraw) { + lastDraw = now; + bool up = wifi->state() == WifiController::State::Connected; + screen.renderUpdate("Safe Mode", up ? "Updates: " + wifi->ip() + ":3232" : "Waiting for Wi-Fi", -1); + } + delay(10); +} + void loop() { + if (safeMode) return loopSafeMode(); #ifdef RORO_TEST_CRASH // Test builds only (never in a release): crash during Probation to exercise Rollback. if (millis() > 5000) abort(); @@ -420,12 +516,8 @@ void loop() { uint32_t now = millis(); serialCommands(); -#ifdef RORO_DEBUG - for (std::string remote; debugConsole->takeCommand(remote);) { - console.printf("> %s\n", remote.c_str()); // so the transcript reads the same on both ends - runCommand(remote.c_str()); - } -#endif + remoteCommands(); + noteStableOnce(now); uploadStep(); printListingWhenReady(); M5Cardputer.update(); diff --git a/src/platform/crash_report.cpp b/src/platform/crash_report.cpp new file mode 100644 index 0000000..ec64287 --- /dev/null +++ b/src/platform/crash_report.cpp @@ -0,0 +1,66 @@ +#include "platform/crash_report.h" + +#include + +#include "platform/system_info.h" +#include "safe_mode.h" +#include "version.h" + +namespace roro::crash_report { + +int noteBoot(KeyValueStore& store) { + bool crashed = system_info::resetWasCrash(); + std::string last; + store.getString("run_ver", last); + if (crashed) { + store.putString("crash_ver", last.empty() ? versionString() : last); + store.putString("crash_why", system_info::resetReason()); + } + if (last != versionString()) store.putString("run_ver", versionString()); + + int32_t before = 0; + store.getInt("crash_boots", before); + int now = SafeMode::countAtBoot(crashed, before); + if (now != before) store.putInt("crash_boots", now); + return now; +} + +void noteStable(KeyValueStore& store) { + int32_t n = 0; + if (store.getInt("crash_boots", n) && n != 0) store.putInt("crash_boots", 0); +} + +void print(Print& out, KeyValueStore& store) { + std::string version, why; + store.getString("crash_ver", version); + store.getString("crash_why", why); + if (version.empty()) out.println("crash: none recorded"); + else out.printf("crash: last one in %s (%s)\n", version.c_str(), why.c_str()); + + esp_core_dump_summary_t sum; + if (esp_core_dump_image_check() != ESP_OK || esp_core_dump_get_summary(&sum) != ESP_OK) { + out.println("crash: no core dump in flash"); + return; + } + char reason[160] = ""; + esp_core_dump_get_panic_reason(reason, sizeof reason); + out.printf("crash: task %s, pc 0x%08lx, cause %lu, address 0x%08lx\n", sum.exc_task, (unsigned long)sum.exc_pc, + (unsigned long)sum.ex_info.exc_cause, (unsigned long)sum.ex_info.exc_vaddr); + if (reason[0]) out.printf("crash: reason: %s\n", reason); + out.print("crash: backtrace"); + for (uint32_t i = 0; i < sum.exc_bt_info.depth && i < 16; i++) out.printf(" 0x%08lx", (unsigned long)sum.exc_bt_info.bt[i]); + out.println(sum.exc_bt_info.corrupted ? " (corrupted)" : ""); + out.printf("crash: elf sha256 %s\n", reinterpret_cast(sum.app_elf_sha256)); +} + +std::string headline() { + esp_core_dump_summary_t sum; + std::string where = ""; + if (esp_core_dump_image_check() == ESP_OK && esp_core_dump_get_summary(&sum) == ESP_OK) + where = std::string(" in ") + sum.exc_task; + return std::string("Restarted after a ") + system_info::resetReason() + where; +} + +bool erase() { return esp_core_dump_image_erase() == ESP_OK; } + +} // namespace roro::crash_report diff --git a/src/platform/crash_report.h b/src/platform/crash_report.h new file mode 100644 index 0000000..ec5ad55 --- /dev/null +++ b/src/platform/crash_report.h @@ -0,0 +1,26 @@ +#pragma once + +#include + +#include + +#include "key_value_store.h" + +namespace roro::crash_report { + +// First thing at boot: remembers which version runs, and after a crash restart, which version +// crashed (the one that ran last time, even if a Rollback has switched slots since). Returns how +// many starts in a row ended in a crash, for Safe Mode. +int noteBoot(KeyValueStore& store); +// The device has been up long enough: the crash streak is over. +void noteStable(KeyValueStore& store); + +// The last crash: which firmware, why, and the task, PC and backtrace from the core dump in flash. +// Decode the backtrace on the PC with scripts/decode_backtrace.sh . +void print(Print& out, KeyValueStore& store); +// One line for a Notification after a crash restart, e.g. "Restarted after a crash in loopTask". +std::string headline(); +// Forgets the core dump, so the next crash's is the one kept. +bool erase(); + +} // namespace roro::crash_report diff --git a/src/services/debug_console.cpp b/src/services/debug_console.cpp index fecc797..47e47ae 100644 --- a/src/services/debug_console.cpp +++ b/src/services/debug_console.cpp @@ -4,6 +4,10 @@ #include +#include +#include +#include + #include "platform/console.h" #include "version.h" @@ -43,6 +47,24 @@ bool readLine(NetworkClient& c, std::string& line, uint32_t timeoutMs) { return false; } +// The raw core dump partition contents, as esp-coredump reads them ("-t raw"). +void sendCoreDump(NetworkClient& client) { + size_t addr = 0, size = 0; + if (esp_core_dump_image_check() != ESP_OK || esp_core_dump_image_get(&addr, &size) != ESP_OK) { + client.print("coredump: none\n"); + return; + } + client.printf("coredump: data %u\n", (unsigned)size); + uint8_t buf[1024]; + for (size_t off = 0; off < size;) { + size_t n = std::min(sizeof buf, size - off); + if (esp_flash_read(nullptr, buf, addr + off, n) != ESP_OK) break; // the host sees a short file + if (client.write(buf, n) != n) return; + off += n; + } + client.print("coredump: end\n"); +} + } // namespace DebugConsole::DebugConsole(WifiService& wifi) : wifi_(wifi), lock_(xSemaphoreCreateMutex()) {} @@ -125,6 +147,17 @@ void DebugConsole::serve(NetworkClient& client) { client.stop(); break; } + if (line == "reset") { // answered here: works even when the main loop is stuck + client.print("debug: restarting now\n"); + client.flush(); + delay(200); + esp_restart(); + } + if (line == "coredump get") { // binary: answered here, not by the main loop + sendCoreDump(client); + line.clear(); + continue; + } xSemaphoreTake(lock_, portMAX_DELAY); bool full = commands_.size() >= kMaxQueued; if (!full && !line.empty()) commands_.push_back(line); diff --git a/src/services/storage_service.cpp b/src/services/storage_service.cpp index 0fe1744..16be963 100644 --- a/src/services/storage_service.cpp +++ b/src/services/storage_service.cpp @@ -14,7 +14,6 @@ namespace roro { void StorageService::start() { if (task_) return; - lock_ = xSemaphoreCreateMutex(); xTaskCreate(taskEntry, "storage", 10240, this, 1, &task_); // room for a signature check } diff --git a/src/services/storage_service.h b/src/services/storage_service.h index a9e85a3..73c2bad 100644 --- a/src/services/storage_service.h +++ b/src/services/storage_service.h @@ -20,7 +20,8 @@ namespace roro { // queued Log lines in batches, lists files for Storage Clean-up, deletes, and formats. class StorageService : public Service { public: - explicit StorageService(EventBus& bus) : monitor_(bus), bus_(bus) {} + // The lock exists from the start, so a Service that's never started (Safe Mode) can still be asked. + explicit StorageService(EventBus& bus) : monitor_(bus), bus_(bus), lock_(xSemaphoreCreateMutex()) {} const char* name() const override { return "storage"; } void start() override; void stop() override; diff --git a/src/services/update_service.cpp b/src/services/update_service.cpp index 619ca25..9967fa0 100644 --- a/src/services/update_service.cpp +++ b/src/services/update_service.cpp @@ -28,6 +28,7 @@ class UpdateSource { namespace { constexpr uint32_t kStallMs = 10000; +constexpr uint32_t kForceRestartMs = 90000; // the main loop waits up to 60 s for someone typing constexpr size_t kChunk = 4096; class NetSource : public UpdateSource { @@ -190,6 +191,7 @@ void UpdateService::taskEntry(void* self) { static_cast(self)->l void UpdateService::listen() { NetworkServer server(kPort); bool listening = false; + uint32_t installedAt = 0; for (;;) { bool connected = wifi_.state() == WifiController::State::Connected; if (connected && !listening) { @@ -201,6 +203,15 @@ void UpdateService::listen() { MDNS.end(); listening = false; } + // The main loop restarts into an installed update when it's safe. If it never does (stuck, + // or waiting on someone typing for too long), restart from here: the update must not wait. + if (phase_ == Phase::Installed) { + if (!installedAt) installedAt = millis(); + if (millis() - installedAt > kForceRestartMs) { + ESP_LOGW("update", "the main loop never restarted into the update: restarting"); + esp_restart(); + } + } if (listening && phase_ == Phase::Idle) { NetworkClient client = server.accept(); if (client) { diff --git a/test/test_ota/test_ota.cpp b/test/test_ota/test_ota.cpp index 18d4397..6aef1a5 100644 --- a/test/test_ota/test_ota.cpp +++ b/test/test_ota/test_ota.cpp @@ -5,6 +5,7 @@ #include #include "probation.h" +#include "safe_mode.h" #include "sha256.h" #include "update_parser.h" #include "version_compare.h" @@ -284,6 +285,23 @@ void test_rollback_at_boot_after_an_unconfirmed_start() { TEST_ASSERT_FALSE(Probation::rollBackAtBoot(false, 3)); // confirmed firmware: never } +void test_safe_mode_after_three_crashes_in_a_row() { + int crashes = 0; + crashes = SafeMode::countAtBoot(true, crashes); + crashes = SafeMode::countAtBoot(true, crashes); + TEST_ASSERT_FALSE(SafeMode::active(crashes)); + crashes = SafeMode::countAtBoot(true, crashes); + TEST_ASSERT_TRUE(SafeMode::active(crashes)); +} + +void test_safe_mode_count_restarts_after_a_normal_start() { + int crashes = SafeMode::countAtBoot(true, 2); + TEST_ASSERT_TRUE(SafeMode::active(crashes)); + crashes = SafeMode::countAtBoot(false, crashes); // e.g. `reboot` from the Debug Console + TEST_ASSERT_EQUAL(0, crashes); + TEST_ASSERT_FALSE(SafeMode::active(crashes)); +} + int main() { UNITY_BEGIN(); RUN_TEST(test_sha256_known_vectors); @@ -305,5 +323,7 @@ int main() { RUN_TEST(test_probation_needs_wifi_when_it_is_configured); RUN_TEST(test_probation_rolls_back_when_wifi_never_comes); RUN_TEST(test_rollback_at_boot_after_an_unconfirmed_start); + RUN_TEST(test_safe_mode_after_three_crashes_in_a_row); + RUN_TEST(test_safe_mode_count_restarts_after_a_normal_start); return UNITY_END(); }