Debug Builds: the console over Wi-Fi (Debug Console, TCP 2323)

cardputer-adv-debug (-DRORO_DEBUG, version +debug) adds a Debug Console: after a token line, a client gets the last 6 KB of console output, live lines (ESP-IDF logs included) and the serial commands. The socket task only queues lines; the main loop runs them. Release builds compile none of it. The token lives in ~/.config/roro9stack/debug-token, created by _docker.sh and passed into the container. All output now goes through `console`, which never waits for USB: a host that was attached but not reading stalled the main loop up to 2 s per line. New commands everywhere: info (slots with their versions from NVS, since the framework stamps its own into each image), tasks, reboot, boot other, log level, help. scripts/rdbg.py is the client; flash.sh --debug builds it; CI builds both variants. ADR 0004. Verified on the device: USB-flashed, then updated over Wi-Fi to a Debug Build that confirmed on Probation; both slots hold Debug Builds. Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01EhqxQ49eCju4CzKYNjZzwT
2026-10-04 02:44:14 +02:00
parent 5b199c2436
commit 0fb7f4e9d5
18 changed files with 828 additions and 97 deletions
@@ -0,0 +1,86 @@
+#include "platform/console.h"
+
+#include <Arduino.h>
+
+#ifdef RORO_DEBUG
+#include <esp_log.h>
+#include <freertos/FreeRTOS.h>
+
+#include <algorithm>
+#include <cstdio>
+#endif
+
+namespace roro {
+
+Console console;
+
+#ifdef RORO_DEBUG
+namespace {
+
+// Any task may write (ESP-IDF logs come from everywhere), so the ring is behind a spinlock, held
+// only for the copy.
+portMUX_TYPE ringLock = portMUX_INITIALIZER_UNLOCKED;
+vprintf_like_t espLogNext = nullptr;
+
+int teeEspLog(const char* format, va_list args) {
+    char line[200];
+    va_list copy;
+    va_copy(copy, args);
+    int n = vsnprintf(line, sizeof line, format, copy);
+    va_end(copy);
+    if (n > 0) console.toRing(reinterpret_cast<const uint8_t*>(line), std::min<size_t>(n, sizeof line - 1));
+    return espLogNext ? espLogNext(format, args) : n;  // the serial port, as before
+}
+
+}  // namespace
+
+void Console::captureEspLogs() { espLogNext = esp_log_set_vprintf(teeEspLog); }
+
+void Console::toRing(const uint8_t* data, size_t len) {
+    if (len > kRingBytes) {
+        data += len - kRingBytes;  // only the tail can fit
+        len = kRingBytes;
+    }
+    portENTER_CRITICAL(&ringLock);
+    size_t at = head_ % kRingBytes;
+    size_t first = std::min(len, kRingBytes - at);
+    memcpy(ring_ + at, data, first);
+    memcpy(ring_, data + first, len - first);
+    head_ += len;
+    portEXIT_CRITICAL(&ringLock);
+}
+
+uint32_t Console::oldest() const {
+    portENTER_CRITICAL(&ringLock);
+    uint32_t pos = head_ > kRingBytes ? head_ - kRingBytes : 0;
+    portEXIT_CRITICAL(&ringLock);
+    return pos;
+}
+
+size_t Console::readSince(uint32_t& pos, uint8_t* out, size_t max, uint32_t& skipped) {
+    portENTER_CRITICAL(&ringLock);
+    uint32_t from = head_ > kRingBytes ? head_ - kRingBytes : 0;
+    skipped = pos < from ? from - pos : 0;
+    if (pos < from) pos = from;
+    size_t n = std::min<size_t>(max, head_ - pos);
+    size_t at = pos % kRingBytes;
+    size_t first = std::min(n, kRingBytes - at);
+    memcpy(out, ring_ + at, first);
+    memcpy(out + first, ring_, n - first);
+    pos += n;
+    portEXIT_CRITICAL(&ringLock);
+    return n;
+}
+#endif
+
+size_t Console::write(const uint8_t* data, size_t len) {
+#ifdef RORO_DEBUG
+    toRing(data, len);
+#endif
+    // Never wait for the USB host. One that's attached but not reading (a VM, a closed terminal)
+    // would stall the caller for up to 2 s per write while HWCDC retries; the ring keeps it anyway.
+    if (Serial.availableForWrite() >= static_cast<int>(len)) Serial.write(data, len);
+    return len;
+}
+
+}  // namespace roro
@@ -0,0 +1,40 @@
+#pragma once
+
+#include <Print.h>
+
+#include <cstddef>
+#include <cstdint>
+
+namespace roro {
+
+// Where the firmware's console output goes: the USB serial port, and in a Debug Build also a ring
+// buffer the Debug Console sends over Wi-Fi (with what came before the connection, so boot messages
+// aren't lost). Use `console` instead of Serial for anything a human should be able to read remotely.
+class Console : public Print {
+   public:
+    size_t write(uint8_t c) override { return write(&c, 1); }
+    size_t write(const uint8_t* data, size_t len) override;
+    using Print::write;
+
+#ifdef RORO_DEBUG
+    static constexpr size_t kRingBytes = 6144;
+
+    // Also copies ESP-IDF's own log lines into the ring (they still reach the serial port).
+    void captureEspLogs();
+    // Copies bytes written since `pos` into `out`, and advances `pos`. A reader that fell more than
+    // the ring behind gets the oldest bytes still there, and `skipped` says how many it missed.
+    size_t readSince(uint32_t& pos, uint8_t* out, size_t max, uint32_t& skipped);
+    // The position of the oldest byte still in the ring: a new reader starts there.
+    uint32_t oldest() const;
+    // The ring only, for output that already reaches the serial port another way.
+    void toRing(const uint8_t* data, size_t len);
+
+   private:
+    uint8_t ring_[kRingBytes];
+    uint32_t head_ = 0;  // total bytes ever written; the ring holds the last kRingBytes of them
+#endif
+};
+
+extern Console console;
+
+}  // namespace roro
@@ -0,0 +1,118 @@
+#include "platform/system_info.h"
+
+#include <Arduino.h>
+#include <esp_heap_caps.h>
+#include <esp_ota_ops.h>
+#include <esp_system.h>
+#include <freertos/FreeRTOS.h>
+#include <freertos/task.h>
+
+#include <string>
+#include <vector>
+
+#include "version.h"
+
+namespace roro::system_info {
+
+const char* resetReason() {
+    switch (esp_reset_reason()) {
+        case ESP_RST_POWERON: return "power-on";
+        case ESP_RST_EXT: return "reset pin";
+        case ESP_RST_SW: return "restart";
+        case ESP_RST_PANIC: return "panic";
+        case ESP_RST_INT_WDT: return "interrupt watchdog";
+        case ESP_RST_TASK_WDT: return "task watchdog";
+        case ESP_RST_WDT: return "watchdog";
+        case ESP_RST_DEEPSLEEP: return "deep sleep";
+        case ESP_RST_BROWNOUT: return "brownout";
+        case ESP_RST_SDIO: return "sdio";
+        case ESP_RST_USB: return "usb";
+        case ESP_RST_JTAG: return "jtag";
+        default: return "unknown";
+    }
+}
+
+bool resetWasCrash() {
+    switch (esp_reset_reason()) {
+        case ESP_RST_PANIC:
+        case ESP_RST_INT_WDT:
+        case ESP_RST_TASK_WDT:
+        case ESP_RST_WDT: return true;
+        default: return false;
+    }
+}
+
+static const char* stateName(esp_ota_img_states_t s) {
+    switch (s) {
+        case ESP_OTA_IMG_NEW: return "new";
+        case ESP_OTA_IMG_PENDING_VERIFY: return "pending verify";
+        case ESP_OTA_IMG_VALID: return "valid";
+        case ESP_OTA_IMG_INVALID: return "invalid";
+        case ESP_OTA_IMG_ABORTED: return "aborted";
+        default: return "undefined";
+    }
+}
+
+void printSystem(Print& out) {
+    uint32_t s = millis() / 1000;
+    out.printf("firmware: %s %s\n", kProductName, versionString());
+    out.printf("uptime: %luh%02lum%02lus, last start: %s\n", (unsigned long)(s / 3600), (unsigned long)(s / 60 % 60),
+               (unsigned long)(s % 60), resetReason());
+    out.printf("heap: %u free, %u lowest, %u largest block\n", ESP.getFreeHeap(), ESP.getMinFreeHeap(),
+               (unsigned)heap_caps_get_largest_free_block(MALLOC_CAP_8BIT));
+    out.printf("chip: %s rev %d, %lu MHz, %.1f C\n", ESP.getChipModel(), ESP.getChipRevision(),
+               (unsigned long)ESP.getCpuFreqMHz(), temperatureRead());
+}
+
+static std::string slotKey(const esp_partition_t* slot) { return std::string("ver_") + slot->label; }
+
+void recordSlotVersion(KeyValueStore& store, const esp_partition_t* slot, const char* version) {
+    std::string known;
+    if (slot && !(store.getString(slotKey(slot).c_str(), known) && known == version))
+        store.putString(slotKey(slot).c_str(), version);
+}
+
+void printSlots(Print& out, KeyValueStore& store) {
+    const esp_partition_t* running = esp_ota_get_running_partition();
+    const esp_partition_t* next = esp_ota_get_boot_partition();
+    esp_partition_iterator_t it = esp_partition_find(ESP_PARTITION_TYPE_APP, ESP_PARTITION_SUBTYPE_ANY, nullptr);
+    for (; it; it = esp_partition_next(it)) {  // the last next() releases the iterator
+        const esp_partition_t* p = esp_partition_get(it);
+        esp_app_desc_t desc;
+        bool hasApp = esp_ota_get_partition_description(p, &desc) == ESP_OK;
+        std::string version = "(unknown version)";
+        store.getString(slotKey(p).c_str(), version);
+        esp_ota_img_states_t state;
+        bool hasState = esp_ota_get_state_partition(p, &state) == ESP_OK;
+        out.printf("slot %s: %s%s%s, %s\n", p->label, hasApp ? version.c_str() : "(empty)", p == running ? ", running" : "",
+                   p == next ? ", boots next" : "", hasState ? stateName(state) : "no OTA state");
+    }
+}
+
+void printTasks(Print& out) {
+    UBaseType_t n = uxTaskGetNumberOfTasks();
+    std::vector<TaskStatus_t> tasks(n + 4);
+    uint32_t total = 0;
+    n = uxTaskGetSystemState(tasks.data(), tasks.size(), &total);
+    out.printf("%-16s %-4s %3s %6s %5s %s\n", "task", "st", "pri", "stack", "cpu%", "core");
+    static const char kStates[] = "RrBSD";  // running, ready, blocked, suspended, deleted
+    for (UBaseType_t i = 0; i < n; i++) {
+        const TaskStatus_t& t = tasks[i];
+        unsigned cpu = total ? (unsigned)((uint64_t)t.ulRunTimeCounter * 100 / total) : 0;
+        int core = t.xCoreID == tskNO_AFFINITY ? -1 : (int)t.xCoreID;
+        out.printf("%-16s %-4c %3u %6u %5u %d\n", t.pcTaskName, t.eCurrentState < 5 ? kStates[t.eCurrentState] : '?',
+                   (unsigned)t.uxCurrentPriority, (unsigned)t.usStackHighWaterMark, cpu, core);
+    }
+}
+
+const char* bootOtherSlot() {
+    const esp_partition_t* other = esp_ota_get_next_update_partition(nullptr);
+    esp_app_desc_t desc;
+    if (!other || esp_ota_get_partition_description(other, &desc) != ESP_OK) return "the other slot is empty";
+    if (esp_ota_set_boot_partition(other) != ESP_OK) return "the other slot doesn't hold a valid image";
+    delay(200);
+    esp_restart();
+    return "";
+}
+
+}  // namespace roro::system_info
@@ -0,0 +1,29 @@
+#pragma once
+
+#include <Print.h>
+#include <esp_partition.h>
+
+#include "key_value_store.h"
+
+namespace roro::system_info {
+
+// Why the chip last started: "power-on", "panic", "task watchdog", "brownout"...
+const char* resetReason();
+// True if the last start was a crash or a watchdog, not a power-on or a deliberate restart.
+bool resetWasCrash();
+
+// Firmware, uptime and memory, one fact per line.
+void printSystem(Print& out);
+// Both app slots: which one runs, which boots next, and each one's version and OTA state. Versions
+// come from NVS ("ver_<slot>"): the prebuilt framework stamps every image with its own version.
+void printSlots(Print& out, KeyValueStore& store);
+// Remembers which version the running slot holds (call at boot), or the slot an update just wrote.
+void recordSlotVersion(KeyValueStore& store, const esp_partition_t* slot, const char* version);
+// FreeRTOS tasks: state, priority, lowest free stack, CPU share since boot.
+void printTasks(Print& out);
+
+// Boots the firmware in the other app slot if it holds a valid image (a manual Rollback).
+// Returns an error message; on success it restarts and doesn't return.
+const char* bootOtherSlot();
+
+}  // namespace roro::system_info