mirror of
https://github.com/ruvnet/RuView.git
synced 2026-10-21 22:22:33 -05:00
feat(firmware): persistent on-node log and coredump-to-flash (#1878)
* feat(firmware): add the 16MB flash profile the C6 fleet runs on The 4MB and display layouts have 1.875MB and 2MB OTA slots, sized for 4MB and 8MB parts. A 16MB C6 (DevKitC-1 N16) has no layout in the tree at all, so building for one meant hand-editing sdkconfig -- and a smaller table written over a deployed 16MB node relocates NVS and destroys its provisioning, which is why this belongs in the repo rather than in a workstation's untracked sdkconfig. Two 4MB OTA slots, plus a 64K coredump partition and an 8000K FAT volume for on-node storage. Rollback is enabled so an OTA'd image that cannot confirm itself is reverted by the bootloader. Layered, not inherited: sdkconfig.defaults.esp32c6 keeps its 4MB layout so the common 4MB devkit is never silently repartitioned. Co-Authored-By: claude-flow <ruv@ruv.net> Claude-Session: https://claude.ai/code/session_01PVWMiHQifoYXL7uL3bphrZ * feat(firmware): persistent on-node log and coredump-to-flash A remote fault currently leaves no post-mortem. main.c decodes the reset reason at boot and logs it to the CONSOLE -- which is exactly what a power cycle destroys, and a power cycle is how a wedged node gets recovered. The flash was already provisioned for this and the features were simply off: partitions_16mb.csv has reserved a 64K `coredump` partition and an 8000K `storage` FAT volume since the 16MB layout was written, neither had ever been mounted or written, and the build defaulted to CONFIG_ESP_COREDUMP_ENABLE_TO_NONE. - node_log.c/h: a 128 B-record ring on the storage volume. Boot records (reset reason + the previous session's final uptime + a health snapshot), periodic health samples, and event records. Ordering is boot_id + uptime_s because these boards have no RTC and nothing can be timestamped absolutely. Counters are stored RAW and differenced at read time, so a cadence change never invalidates old records. Retention, not wear, binds: 128 B every 300 s is ~208 days in 8 MB, and the write rate is bounded explicitly. - ap_rssi_dbm, the association link from esp_wifi_sta_get_ap_info. The adaptive controller's rssi_median_dbm is a CSI statistic, not the uplink, so a node with a bad uplink currently shows no signal for it anywhere. - CONFIG_ESP_COREDUMP_ENABLE_TO_FLASH, complementary rather than a substitute: a coredump catches a CRASH, the boot record catches a HANG followed by a watchdog reset. node_log_init failing is non-fatal by design -- the module disables itself and every entry point becomes a no-op. A logging volume that will not mount must never take the fleet down with it. csi_collector gains two gate accessors. This build selects its frame gate at compile time, so both return CSI_GATE_NOT_CONFIGURABLE rather than a plausible number: the log keeps a field of fixed width and meaning either way, and an explicit "not applicable" is stored instead of something a reader would later reason from as a real setting. Built with ESP-IDF v5.4 for esp32c6 using defaults + .esp32c6 + .16mb. Verified from the resulting artifacts: 16MB table with coredump and storage present, COREDUMP_ENABLE_TO_FLASH set, rollback enabled, image 0x10abd0 bytes in a 4M slot. NOT flashed to hardware from this branch -- the equivalent code was exercised on a node-3 pilot, but that is not evidence for this build. Co-Authored-By: claude-flow <ruv@ruv.net> Claude-Session: https://claude.ai/code/session_01PVWMiHQifoYXL7uL3bphrZ * docs(adr-362): reading the on-node log is on-demand, never streamed The log engine lands with no consumer, so the access pattern was open. Records the decision to pull a node's log only when a human asks -- after a hang or a crash, or while troubleshooting that node -- and to keep nothing server-side. The reasoning that decided it: the ring already survives a power cycle on the node (~208 days of retention), so a server copy duplicates a durability property that is already met; and airtime is this fleet's binding constraint, measured at 91% consumed by two slow nodes, so a periodic drain across nine boards would spend exactly the resource whose exhaustion you would open the log to investigate. An instrument must not perturb what it measures. Leaves the decode-where question open on purpose, with the argument for a raw proxy stated: decoding server-side defines the record layout in both C and Rust, and the pilot already paid once for a host/firmware disagreement about a field's meaning. Co-Authored-By: claude-flow <ruv@ruv.net> Claude-Session: https://claude.ai/code/session_01PVWMiHQifoYXL7uL3bphrZ --------- Co-authored-by: Joe <joe@GitDev.hedgehog> Co-authored-by: claude-flow <ruv@ruv.net>
This commit is contained in:
8 files changed
+661
-1
No files matched your search
@@ -0,0 +1,69 @@
|
||||
# ADR-362: Reading the on-node log is on-demand, never streamed
|
||||
|
||||
**Status:** Accepted
|
||||
**Date:** 2026-09-09
|
||||
**Follows:** the on-node log engine (persistent 128 B-record ring + coredump-to-flash)
|
||||
|
||||
## Context
|
||||
|
||||
The firmware now keeps a persistent log on the node's `storage` volume and can
|
||||
write a coredump to flash. Nothing reads either one. The log is a new concept
|
||||
in this tree, so there is no existing consumer to extend and the access
|
||||
pattern is genuinely open.
|
||||
|
||||
Two shapes were considered:
|
||||
|
||||
1. **Ingest** — the server polls every node on a schedule, drains new records,
|
||||
and keeps its own copy that the UI reads.
|
||||
2. **On-demand** — the server fetches a node's log only when a human asks for
|
||||
it, and keeps nothing.
|
||||
|
||||
## Decision
|
||||
|
||||
**On-demand only. No streaming, no periodic polling, no server-side copy, no
|
||||
alerting.**
|
||||
|
||||
The log is pulled after a board hangs or crashes, or while troubleshooting a
|
||||
specific node. That is the whole access pattern.
|
||||
|
||||
## Why
|
||||
|
||||
- **The persistence already lives on the node.** The ring holds ~208 days at
|
||||
128 B per 300 s, and surviving a power cycle is the entire reason the module
|
||||
exists — a power cycle is how a wedged node gets recovered. A second copy on
|
||||
the server duplicates a durability property that is already satisfied.
|
||||
- **Airtime is this fleet's binding constraint, and it is the thing being
|
||||
diagnosed.** Two nodes uplinking at 1 Mbps were measured consuming 91% of
|
||||
fleet airtime. A periodic log drain across nine nodes would spend exactly the
|
||||
resource whose exhaustion is the most common thing you would open the log to
|
||||
investigate. An instrument must not perturb what it measures.
|
||||
- **Coredumps are 64 KB.** They are only ever worth moving when something has
|
||||
actually crashed.
|
||||
- **The use is diagnostic, not observational.** Nobody watches nine logs. You
|
||||
open one node's history when that node misbehaves.
|
||||
|
||||
## What this implies gets built
|
||||
|
||||
- A server route that proxies to the node on request — `GET
|
||||
/api/v1/nodes/{id}/log`, and the same for `/coredump` — authenticating with
|
||||
the OTA PSK the firmware endpoints already sit behind.
|
||||
- A page under the existing Tools menu to view one node's records.
|
||||
- **No** scheduler, **no** new storage, **no** retention policy on the server.
|
||||
|
||||
## Open question, deliberately not settled here
|
||||
|
||||
Whether the server decodes the 128 B records into JSON, or proxies raw bytes
|
||||
and lets the decoder at the edge (browser, or `node_log_read.py`) interpret
|
||||
them.
|
||||
|
||||
Decoding server-side means the record layout is defined in two places — C and
|
||||
Rust — and can drift silently. The pilot already paid for a version of this:
|
||||
a field whose sentinel the host had to learn to render as `n/a`, where a
|
||||
plausible wrong value would have been worse than an obvious gap. That argues
|
||||
for the raw proxy and a single definition of the format.
|
||||
|
||||
## Non-goals
|
||||
|
||||
Real-time monitoring, log streaming, fleet-wide log aggregation, and alerting
|
||||
on log contents are all explicitly out of scope. If a future need genuinely
|
||||
requires one of them, it should revisit this ADR rather than grow into it.
|
||||
@@ -1,5 +1,5 @@
|
||||
set(SRCS
|
||||
"main.c" "csi_collector.c"
|
||||
"main.c" "csi_collector.c" "node_log.c"
|
||||
"thermal.c" "stream_sender.c" "nvs_config.c"
|
||||
"edge_processing.c" "ota_update.c" "power_mgmt.c"
|
||||
"wasm_runtime.c" "wasm_upload.c" "rvf_parser.c"
|
||||
@@ -32,6 +32,9 @@ set(REQUIRES
|
||||
esp_http_client
|
||||
esp_app_format
|
||||
esp_timer
|
||||
fatfs # node_log.c: the storage FAT volume
|
||||
wear_levelling # node_log.c: wl_mount behind that volume
|
||||
espcoredump # coredump-to-flash readback
|
||||
esp_pm
|
||||
esp_driver_uart
|
||||
esp_driver_gpio
|
||||
|
||||
@@ -750,6 +750,20 @@ uint16_t csi_collector_get_send_fail_count(void)
|
||||
return (f > 0xFFFFu) ? 0xFFFFu : (uint16_t)f;
|
||||
}
|
||||
|
||||
/* The gate here is fixed at compile time (mesh-aligned bucketing, falling
|
||||
* back to elapsed time when unsynced), so there is no mode or period to
|
||||
* report. Return the explicit sentinel rather than a number that reads as
|
||||
* a real setting. */
|
||||
uint8_t csi_collector_get_gate_mode(void)
|
||||
{
|
||||
return CSI_GATE_NOT_CONFIGURABLE;
|
||||
}
|
||||
|
||||
uint8_t csi_collector_get_gate_seq_period(void)
|
||||
{
|
||||
return CSI_GATE_NOT_CONFIGURABLE;
|
||||
}
|
||||
|
||||
/* ---- ADR-029: Channel hopping ---- */
|
||||
|
||||
void csi_collector_set_hop_table(const uint8_t *channels, uint8_t hop_count, uint32_t dwell_ms)
|
||||
|
||||
@@ -139,4 +139,22 @@ uint16_t csi_collector_get_pkt_yield_per_sec(void);
|
||||
*/
|
||||
uint16_t csi_collector_get_send_fail_count(void);
|
||||
|
||||
/** Reported by the gate accessors when this build has no selectable gate. */
|
||||
#define CSI_GATE_NOT_CONFIGURABLE 0xFF
|
||||
|
||||
/**
|
||||
* Report which frame-selection gate is in force, for the on-node log.
|
||||
*
|
||||
* This build has exactly one gate -- mesh-aligned bucketing with an
|
||||
* elapsed-time fallback -- fixed at compile time, so there is no mode or
|
||||
* period to report and both accessors return CSI_GATE_NOT_CONFIGURABLE.
|
||||
*
|
||||
* They exist so the log record keeps a field of fixed width and meaning
|
||||
* whether or not a build can select a gate at runtime, and so an explicit
|
||||
* "not applicable" is stored rather than a plausible number that would
|
||||
* later be reasoned from.
|
||||
*/
|
||||
uint8_t csi_collector_get_gate_mode(void);
|
||||
uint8_t csi_collector_get_gate_seq_period(void);
|
||||
|
||||
#endif /* CSI_COLLECTOR_H */
|
||||
@@ -21,6 +21,7 @@
|
||||
#include "led_strip.h"
|
||||
|
||||
#include "csi_collector.h"
|
||||
#include "node_log.h"
|
||||
#include "thermal.h"
|
||||
#include "stream_sender.h"
|
||||
#include "nvs_config.h"
|
||||
@@ -116,6 +117,10 @@ static void event_handler(void *arg, esp_event_base_t event_base,
|
||||
} else if (event_base == WIFI_EVENT && event_id == WIFI_EVENT_STA_DISCONNECTED) {
|
||||
wifi_event_sta_disconnected_t *disc = (wifi_event_sta_disconnected_t *)event_data;
|
||||
ESP_LOGW(TAG, "WiFi disconnected, reason=%d rssi=%d", disc->reason, disc->rssi);
|
||||
/* The 7.5 h outage was root-caused to the MAX_RETRY latch only because
|
||||
* someone was watching the console at the time. Persist it. */
|
||||
node_log_note_disconnect((uint8_t)disc->reason, (int8_t)disc->rssi);
|
||||
node_log_event(NODE_LOG_EV_WIFI_DISCONNECT, disc->reason, disc->rssi);
|
||||
s_retry_num++;
|
||||
/* Release the boot wait once, so a node that comes up while the AP is
|
||||
* down still starts CSI capture and the mesh instead of blocking in
|
||||
@@ -451,6 +456,24 @@ void app_main(void)
|
||||
} else {
|
||||
ESP_LOGI(TAG, "reset reason: %s (%d)", why, (int)rr);
|
||||
}
|
||||
|
||||
/* And persist it. The console line above is exactly what a power cycle
|
||||
* destroys, which is the whole reason this fleet has no post-mortem for
|
||||
* a remote fault. node_log_init failing is non-fatal by design -- the
|
||||
* node comes up either way, it just has no memory. */
|
||||
if (node_log_init() == ESP_OK) {
|
||||
uint32_t prev_uptime_s = 0;
|
||||
nvs_handle_t nh;
|
||||
if (nvs_open("nodelog", NVS_READWRITE, &nh) == ESP_OK) {
|
||||
nvs_get_u32(nh, "last_up_s", &prev_uptime_s);
|
||||
nvs_set_u32(nh, "last_up_s", 0);
|
||||
nvs_commit(nh);
|
||||
nvs_close(nh);
|
||||
}
|
||||
node_log_boot((uint32_t)rr, prev_uptime_s);
|
||||
ESP_LOGI(TAG, "on-node log active: boot_id=%u, %u records retained",
|
||||
(unsigned)node_log_boot_id(), (unsigned)node_log_count());
|
||||
}
|
||||
}
|
||||
|
||||
/* Bring thermal monitoring up before the radio is loaded, so the first
|
||||
@@ -655,5 +678,24 @@ void app_main(void)
|
||||
#ifdef CONFIG_UPLINK_WATCHDOG
|
||||
uplink_watchdog_tick();
|
||||
#endif
|
||||
/* Offered every 10 s; node_log enforces its own floor, so the cadence
|
||||
* lives in one place rather than being implied by this loop's delay.
|
||||
* Also refresh the uptime NVS cell, which is what lets the NEXT boot
|
||||
* record say how long the previous session actually survived -- the
|
||||
* difference between "it rebooted" and "it wedged after 225 s". */
|
||||
node_log_periodic();
|
||||
{
|
||||
static uint32_t s_last_persist_s;
|
||||
uint32_t up_s = (uint32_t)(esp_timer_get_time() / 1000000);
|
||||
if (up_s - s_last_persist_s >= 60) {
|
||||
s_last_persist_s = up_s;
|
||||
nvs_handle_t nh;
|
||||
if (nvs_open("nodelog", NVS_READWRITE, &nh) == ESP_OK) {
|
||||
nvs_set_u32(nh, "last_up_s", up_s);
|
||||
nvs_commit(nh);
|
||||
nvs_close(nh);
|
||||
}
|
||||
}
|
||||
}
|
||||
}
|
||||
}
|
||||
@@ -0,0 +1,382 @@
|
||||
#include "node_log.h"
|
||||
|
||||
#include <limits.h>
|
||||
#include <string.h>
|
||||
#include <unistd.h>
|
||||
|
||||
#include "esp_log.h"
|
||||
#include "esp_system.h"
|
||||
#include "esp_timer.h"
|
||||
#include "esp_vfs_fat.h"
|
||||
#include "esp_wifi.h"
|
||||
#include "freertos/FreeRTOS.h"
|
||||
#include "freertos/semphr.h"
|
||||
#include "nvs.h"
|
||||
#include "nvs_flash.h"
|
||||
|
||||
#include "c6_sync_espnow.h"
|
||||
#include "csi_collector.h"
|
||||
#include "nvs_config.h"
|
||||
#include "thermal.h"
|
||||
|
||||
static const char *TAG = "node_log";
|
||||
|
||||
/* The FAT volume reserved in partitions_16mb.csv (storage, 8000K) and never
|
||||
* mounted until now. */
|
||||
#define NODE_LOG_PARTITION "storage"
|
||||
#define NODE_LOG_MOUNT "/nlog"
|
||||
#define NODE_LOG_PATH NODE_LOG_MOUNT "/health.bin"
|
||||
|
||||
/* Ring capacity. 60000 * 128 B = 7.68 MB, just inside the 8000K volume with
|
||||
* room for FAT's own metadata. At the 300 s cadence that is ~208 days. */
|
||||
#define NODE_LOG_MAX_RECORDS 60000
|
||||
|
||||
/* Hard floor between periodic samples. The design settled on 300 s; this is
|
||||
* the enforcement, not the schedule. A caller asking more often is DROPPED
|
||||
* rather than served, because flash wear is the one way this module can do
|
||||
* harm and a bug in a caller must not be able to cause it. */
|
||||
#define NODE_LOG_MIN_PERIOD_S 60
|
||||
|
||||
/* Events bypass the periodic floor -- they are rare and they are the whole
|
||||
* point -- but not without limit, or a disconnect storm becomes a write storm. */
|
||||
#define NODE_LOG_MIN_EVENT_MS 1000
|
||||
|
||||
static bool s_active;
|
||||
static FILE *s_fp;
|
||||
static wl_handle_t s_wl = WL_INVALID_HANDLE;
|
||||
static SemaphoreHandle_t s_lock;
|
||||
static uint16_t s_boot_id;
|
||||
static uint32_t s_seq;
|
||||
static size_t s_count; /* records currently in the ring */
|
||||
static size_t s_head; /* next slot to write */
|
||||
static int64_t s_last_periodic_us;
|
||||
static int64_t s_last_event_us;
|
||||
|
||||
/* CRC16/CCITT-FALSE. A record that fails this is skipped by the reader rather
|
||||
* than trusted, which matters because a power cut mid-write leaves a partial
|
||||
* record and the ring has no other way to know. */
|
||||
static uint16_t crc16(const uint8_t *p, size_t n)
|
||||
{
|
||||
uint16_t crc = 0xFFFF;
|
||||
for (size_t i = 0; i < n; i++) {
|
||||
crc ^= (uint16_t)p[i] << 8;
|
||||
for (int b = 0; b < 8; b++) {
|
||||
crc = (crc & 0x8000) ? (uint16_t)((crc << 1) ^ 0x1021) : (uint16_t)(crc << 1);
|
||||
}
|
||||
}
|
||||
return crc;
|
||||
}
|
||||
|
||||
/* 16 B header, then a type-specific payload. The header is identical across
|
||||
* types so a reader can order and validate without dispatching first. */
|
||||
typedef struct __attribute__((packed)) {
|
||||
uint8_t type;
|
||||
uint8_t flags;
|
||||
uint16_t boot_id;
|
||||
uint32_t seq;
|
||||
uint32_t uptime_s;
|
||||
uint16_t payload_len;
|
||||
uint16_t crc16; /* over the record with this field zeroed */
|
||||
} node_log_hdr_t;
|
||||
|
||||
_Static_assert(sizeof(node_log_hdr_t) == 16, "header must be 16 B");
|
||||
|
||||
/* ~72 B used of the 112 B payload budget, leaving ~40 B of deliberate slack so
|
||||
* a field can be added later WITHOUT changing the record size and invalidating
|
||||
* every reader already in the field. */
|
||||
typedef struct __attribute__((packed)) {
|
||||
int8_t die_c;
|
||||
uint8_t thermal_state;
|
||||
int8_t tx_dbm;
|
||||
int8_t ap_rssi_dbm; /* the one field we did not have and needed */
|
||||
uint8_t channel;
|
||||
uint8_t wifi_state;
|
||||
uint8_t gate_mode;
|
||||
uint8_t gate_seq_period;
|
||||
uint16_t free_heap_kib;
|
||||
uint16_t min_heap_kib;
|
||||
uint16_t csi_fps_x100;
|
||||
uint32_t frames_processed;
|
||||
uint32_t frames_rejected;
|
||||
uint32_t seq_drop;
|
||||
uint32_t tx_early_drop;
|
||||
uint16_t tx_rate_skip;
|
||||
uint32_t tx_send_fail;
|
||||
uint16_t disconnect_count;
|
||||
uint8_t last_disc_reason;
|
||||
int8_t last_disc_rssi;
|
||||
uint8_t mesh_flags; /* bit0 valid, bit1 leader */
|
||||
uint8_t leader_id;
|
||||
int32_t mesh_offset_us;
|
||||
uint16_t mesh_staleness_ms;
|
||||
uint32_t mesh_seq;
|
||||
} node_log_periodic_t;
|
||||
|
||||
typedef struct __attribute__((packed)) {
|
||||
uint32_t reset_reason;
|
||||
uint32_t prev_uptime_s;
|
||||
node_log_periodic_t health; /* a boot record carries a snapshot too */
|
||||
} node_log_boot_t;
|
||||
|
||||
typedef struct __attribute__((packed)) {
|
||||
uint8_t subtype;
|
||||
uint8_t _pad[3];
|
||||
int32_t a;
|
||||
int32_t b;
|
||||
} node_log_event_t;
|
||||
|
||||
/* Counters main.c owns; set through the setters below rather than reached for,
|
||||
* so this module has no include cycle with main.c. */
|
||||
static volatile uint16_t s_disconnect_count;
|
||||
static volatile uint8_t s_last_disc_reason;
|
||||
static volatile int8_t s_last_disc_rssi;
|
||||
|
||||
void node_log_note_disconnect(uint8_t reason, int8_t rssi)
|
||||
{
|
||||
s_disconnect_count++;
|
||||
s_last_disc_reason = reason;
|
||||
s_last_disc_rssi = rssi;
|
||||
}
|
||||
|
||||
static void fill_health(node_log_periodic_t *h)
|
||||
{
|
||||
memset(h, 0, sizeof(*h));
|
||||
|
||||
/* thermal.c initialises s_last_c to -273.0f and only replaces it on the
|
||||
* first thermal_tick(), which runs from the adaptive controller -- LATER
|
||||
* than the boot record and later than the first periodic samples. Casting
|
||||
* that sentinel to int8 yields -17, a PLAUSIBLE temperature, which is
|
||||
* exactly the kind of invented-but-believable number that must never reach
|
||||
* a log someone will later reason from. Store INT8_MIN as an explicit
|
||||
* "no reading" instead; node_log_read.py renders it as n/a. */
|
||||
float die = thermal_celsius();
|
||||
h->die_c = (die < -100.0f || die > 125.0f) ? INT8_MIN : (int8_t)die;
|
||||
h->thermal_state = (uint8_t)thermal_state();
|
||||
h->tx_dbm = thermal_tx_dbm();
|
||||
h->gate_mode = csi_collector_get_gate_mode();
|
||||
h->gate_seq_period = csi_collector_get_gate_seq_period();
|
||||
|
||||
/* The association link, NOT the CSI-derived rssi_median_dbm in
|
||||
* adaptive_controller.c. Nodes 5 and 6 show every symptom of a bad uplink
|
||||
* and this is the one call that can confirm or refute it. */
|
||||
wifi_ap_record_t ap;
|
||||
if (esp_wifi_sta_get_ap_info(&ap) == ESP_OK) {
|
||||
h->ap_rssi_dbm = (int8_t)ap.rssi;
|
||||
h->channel = ap.primary;
|
||||
h->wifi_state = 1;
|
||||
}
|
||||
|
||||
h->free_heap_kib = (uint16_t)(esp_get_free_heap_size() / 1024);
|
||||
h->min_heap_kib = (uint16_t)(esp_get_minimum_free_heap_size() / 1024);
|
||||
h->csi_fps_x100 = csi_collector_get_pkt_yield_per_sec() * 100;
|
||||
h->tx_send_fail = csi_collector_get_send_fail_count();
|
||||
|
||||
h->disconnect_count = s_disconnect_count;
|
||||
h->last_disc_reason = s_last_disc_reason;
|
||||
h->last_disc_rssi = s_last_disc_rssi;
|
||||
|
||||
h->mesh_flags = (uint8_t)((c6_sync_espnow_is_valid() ? 1 : 0)
|
||||
| (c6_sync_espnow_is_leader() ? 2 : 0));
|
||||
int64_t off = c6_sync_espnow_get_offset_us();
|
||||
/* Saturate rather than wrap: a wrapped offset reads as a plausible small
|
||||
* number and would be believed. */
|
||||
if (off > INT32_MAX) h->mesh_offset_us = INT32_MAX;
|
||||
else if (off < INT32_MIN) h->mesh_offset_us = INT32_MIN;
|
||||
else h->mesh_offset_us = (int32_t)off;
|
||||
}
|
||||
|
||||
/* Append one record. Callers hold no lock; this takes it. */
|
||||
static void append(uint8_t type, const void *payload, size_t len)
|
||||
{
|
||||
if (!s_active || len > (NODE_LOG_RECORD_SIZE - sizeof(node_log_hdr_t))) {
|
||||
return;
|
||||
}
|
||||
if (xSemaphoreTake(s_lock, pdMS_TO_TICKS(200)) != pdTRUE) {
|
||||
return; /* never block a caller on the log */
|
||||
}
|
||||
|
||||
uint8_t rec[NODE_LOG_RECORD_SIZE];
|
||||
memset(rec, 0, sizeof(rec));
|
||||
node_log_hdr_t *h = (node_log_hdr_t *)rec;
|
||||
h->type = type;
|
||||
h->boot_id = s_boot_id;
|
||||
h->seq = ++s_seq;
|
||||
h->uptime_s = (uint32_t)(esp_timer_get_time() / 1000000);
|
||||
h->payload_len = (uint16_t)len;
|
||||
h->crc16 = 0;
|
||||
memcpy(rec + sizeof(*h), payload, len);
|
||||
h->crc16 = crc16(rec, sizeof(rec));
|
||||
|
||||
if (fseek(s_fp, (long)(s_head * NODE_LOG_RECORD_SIZE), SEEK_SET) == 0
|
||||
&& fwrite(rec, 1, sizeof(rec), s_fp) == sizeof(rec)) {
|
||||
/* fflush only pushes the C stdio buffer into the VFS; FATFS still holds
|
||||
* the directory entry and FAT chain in RAM. Without fsync a reboot
|
||||
* loses the file's size, and on the next open "r+b" sees a zero-length
|
||||
* file -- which is precisely what the node-3 pilot showed: boot 1's
|
||||
* records vanished while the NVS-backed prev_uptime survived. A log
|
||||
* that does not survive a power cycle is the exact thing this module
|
||||
* exists to prevent, so the cost of an fsync per record is accepted:
|
||||
* at one record per 60 s it is nothing, and the bounded write rate is
|
||||
* what keeps it that way. */
|
||||
fflush(s_fp);
|
||||
fsync(fileno(s_fp));
|
||||
s_head = (s_head + 1) % NODE_LOG_MAX_RECORDS;
|
||||
if (s_count < NODE_LOG_MAX_RECORDS) s_count++;
|
||||
} else {
|
||||
ESP_LOGW(TAG, "record write failed; disabling to protect the volume");
|
||||
s_active = false;
|
||||
}
|
||||
xSemaphoreGive(s_lock);
|
||||
}
|
||||
|
||||
esp_err_t node_log_init(void)
|
||||
{
|
||||
if (s_active) return ESP_OK;
|
||||
|
||||
s_lock = xSemaphoreCreateMutex();
|
||||
if (!s_lock) return ESP_ERR_NO_MEM;
|
||||
|
||||
const esp_vfs_fat_mount_config_t cfg = {
|
||||
.format_if_mount_failed = true,
|
||||
.max_files = 2,
|
||||
.allocation_unit_size = CONFIG_WL_SECTOR_SIZE,
|
||||
};
|
||||
esp_err_t err = esp_vfs_fat_spiflash_mount_rw_wl(
|
||||
NODE_LOG_MOUNT, NODE_LOG_PARTITION, &cfg, &s_wl);
|
||||
if (err != ESP_OK) {
|
||||
ESP_LOGW(TAG, "FAT mount failed (%s); logging DISABLED, node unaffected",
|
||||
esp_err_to_name(err));
|
||||
return err;
|
||||
}
|
||||
|
||||
/* boot_id orders records across reboots. Without an RTC it is the only
|
||||
* ordering that survives a power cycle. */
|
||||
nvs_handle_t nh;
|
||||
if (nvs_open("nodelog", NVS_READWRITE, &nh) == ESP_OK) {
|
||||
uint16_t b = 0;
|
||||
nvs_get_u16(nh, "boot_id", &b);
|
||||
s_boot_id = (uint16_t)(b + 1);
|
||||
nvs_set_u16(nh, "boot_id", s_boot_id);
|
||||
nvs_commit(nh);
|
||||
nvs_close(nh);
|
||||
}
|
||||
|
||||
s_fp = fopen(NODE_LOG_PATH, "r+b");
|
||||
if (!s_fp) {
|
||||
/* First boot only. Create it, then fsync so the directory entry is on
|
||||
* flash before anything is written into it. */
|
||||
s_fp = fopen(NODE_LOG_PATH, "w+b");
|
||||
if (s_fp) {
|
||||
fflush(s_fp);
|
||||
fsync(fileno(s_fp));
|
||||
}
|
||||
}
|
||||
if (!s_fp) {
|
||||
ESP_LOGW(TAG, "cannot open %s; logging DISABLED", NODE_LOG_PATH);
|
||||
esp_vfs_fat_spiflash_unmount_rw_wl(NODE_LOG_MOUNT, s_wl);
|
||||
s_wl = WL_INVALID_HANDLE;
|
||||
return ESP_FAIL;
|
||||
}
|
||||
|
||||
/* Recover head/seq by scanning. The ring has no superblock deliberately:
|
||||
* a superblock is one more thing a power cut can leave inconsistent, and
|
||||
* the scan is a one-off cost at boot. */
|
||||
uint8_t rec[NODE_LOG_RECORD_SIZE];
|
||||
uint32_t best_seq = 0;
|
||||
for (size_t i = 0; i < NODE_LOG_MAX_RECORDS; i++) {
|
||||
if (fseek(s_fp, (long)(i * NODE_LOG_RECORD_SIZE), SEEK_SET) != 0) break;
|
||||
if (fread(rec, 1, sizeof(rec), s_fp) != sizeof(rec)) break;
|
||||
node_log_hdr_t *h = (node_log_hdr_t *)rec;
|
||||
if (h->type == 0) continue;
|
||||
uint16_t got = h->crc16;
|
||||
h->crc16 = 0;
|
||||
if (crc16(rec, sizeof(rec)) != got) continue;
|
||||
s_count++;
|
||||
if (h->seq > best_seq) {
|
||||
best_seq = h->seq;
|
||||
s_head = (i + 1) % NODE_LOG_MAX_RECORDS;
|
||||
}
|
||||
}
|
||||
s_seq = best_seq;
|
||||
s_active = true;
|
||||
ESP_LOGI(TAG, "logging active: boot_id=%u recovered=%u records, head=%u",
|
||||
(unsigned)s_boot_id, (unsigned)s_count, (unsigned)s_head);
|
||||
return ESP_OK;
|
||||
}
|
||||
|
||||
bool node_log_is_active(void) { return s_active; }
|
||||
uint16_t node_log_boot_id(void) { return s_boot_id; }
|
||||
size_t node_log_count(void) { return s_count; }
|
||||
|
||||
void node_log_boot(uint32_t reset_reason, uint32_t prev_uptime_s)
|
||||
{
|
||||
node_log_boot_t b;
|
||||
memset(&b, 0, sizeof(b));
|
||||
b.reset_reason = reset_reason;
|
||||
b.prev_uptime_s = prev_uptime_s;
|
||||
fill_health(&b.health);
|
||||
append(NODE_LOG_TYPE_BOOT, &b, sizeof(b));
|
||||
}
|
||||
|
||||
void node_log_periodic(void)
|
||||
{
|
||||
int64_t now = esp_timer_get_time();
|
||||
if (s_last_periodic_us != 0
|
||||
&& (now - s_last_periodic_us) < (int64_t)NODE_LOG_MIN_PERIOD_S * 1000000) {
|
||||
return;
|
||||
}
|
||||
s_last_periodic_us = now;
|
||||
node_log_periodic_t h;
|
||||
fill_health(&h);
|
||||
append(NODE_LOG_TYPE_PERIODIC, &h, sizeof(h));
|
||||
}
|
||||
|
||||
void node_log_event(uint8_t subtype, int32_t a, int32_t b)
|
||||
{
|
||||
int64_t now = esp_timer_get_time();
|
||||
if (s_last_event_us != 0
|
||||
&& (now - s_last_event_us) < (int64_t)NODE_LOG_MIN_EVENT_MS * 1000) {
|
||||
return;
|
||||
}
|
||||
s_last_event_us = now;
|
||||
node_log_event_t e;
|
||||
memset(&e, 0, sizeof(e));
|
||||
e.subtype = subtype;
|
||||
e.a = a;
|
||||
e.b = b;
|
||||
append(NODE_LOG_TYPE_EVENT, &e, sizeof(e));
|
||||
}
|
||||
|
||||
size_t node_log_read(uint8_t *out, size_t max_records, size_t skip)
|
||||
{
|
||||
if (!s_active || !out || max_records == 0) return 0;
|
||||
if (xSemaphoreTake(s_lock, pdMS_TO_TICKS(500)) != pdTRUE) return 0;
|
||||
|
||||
size_t written = 0;
|
||||
for (size_t n = 0; n < s_count && written < max_records; n++) {
|
||||
if (n < skip) continue;
|
||||
/* newest-first: step back from head */
|
||||
size_t idx = (s_head + NODE_LOG_MAX_RECORDS - 1 - n) % NODE_LOG_MAX_RECORDS;
|
||||
if (fseek(s_fp, (long)(idx * NODE_LOG_RECORD_SIZE), SEEK_SET) != 0) break;
|
||||
if (fread(out + written * NODE_LOG_RECORD_SIZE, 1, NODE_LOG_RECORD_SIZE, s_fp)
|
||||
!= NODE_LOG_RECORD_SIZE) break;
|
||||
written++;
|
||||
}
|
||||
xSemaphoreGive(s_lock);
|
||||
return written;
|
||||
}
|
||||
|
||||
esp_err_t node_log_clear(void)
|
||||
{
|
||||
if (!s_active) return ESP_ERR_INVALID_STATE;
|
||||
if (xSemaphoreTake(s_lock, pdMS_TO_TICKS(1000)) != pdTRUE) return ESP_ERR_TIMEOUT;
|
||||
esp_err_t err = ESP_OK;
|
||||
if (s_fp) { fclose(s_fp); s_fp = NULL; }
|
||||
s_fp = fopen(NODE_LOG_PATH, "w+b");
|
||||
if (!s_fp) { s_active = false; err = ESP_FAIL; }
|
||||
s_count = 0;
|
||||
s_head = 0;
|
||||
s_seq = 0;
|
||||
xSemaphoreGive(s_lock);
|
||||
return err;
|
||||
}
|
||||
@@ -0,0 +1,114 @@
|
||||
/* Persistent on-node log -- survives a power cycle, readable without a cable.
|
||||
*
|
||||
* The problem this exists for (Joe, 2026-09-07): "a hung node ... doesnt do us
|
||||
* any good for troubleshooting remotly because the unplug and mount results in
|
||||
* a clearing of the condtion." Today the post-mortem for any remote fault is
|
||||
* nothing: main.c decodes the reset reason at boot and logs it to the CONSOLE,
|
||||
* which is exactly what a power cycle destroys.
|
||||
*
|
||||
* The flash was already partitioned for this and the features were off --
|
||||
* partitions_16mb.csv reserves a 64K coredump partition and an 8000K storage
|
||||
* FAT volume, neither of which had ever been mounted or written.
|
||||
*
|
||||
* # Retention, not wear, is the binding constraint
|
||||
*
|
||||
* 128 B records every 300 s fills 8 MB in ~222 days. Endurance at that rate is
|
||||
* ~61,000 years, so the ring wraps 36 million times before the flash is at
|
||||
* risk. The write rate is nonetheless bounded explicitly below, because flash
|
||||
* wear is the one way this module can do harm.
|
||||
*
|
||||
* # Why uptime and boot_id rather than a timestamp
|
||||
*
|
||||
* These boards have no RTC. Nothing can be timestamped absolutely, so ordering
|
||||
* comes from boot_id (incremented once per boot, persisted in NVS) plus
|
||||
* uptime_s within that boot. That ordering survives a power cycle; a wall clock
|
||||
* would not.
|
||||
*
|
||||
* # Counters are stored RAW
|
||||
*
|
||||
* Every counter here is cumulative and is written as-is. Differencing happens
|
||||
* at read time. Storing rates instead would bake in the sampling interval and
|
||||
* make every record useless the moment the cadence changed.
|
||||
*/
|
||||
#pragma once
|
||||
|
||||
#include <stdbool.h>
|
||||
#include <stddef.h>
|
||||
#include <stdint.h>
|
||||
|
||||
#include "esp_err.h"
|
||||
|
||||
#ifdef __cplusplus
|
||||
extern "C" {
|
||||
#endif
|
||||
|
||||
/** Every record is exactly this size, so the ring is index-addressable and a
|
||||
* reader never has to parse forward to find a boundary. */
|
||||
#define NODE_LOG_RECORD_SIZE 128
|
||||
|
||||
/** Record types. A reader dispatches on this byte alone. */
|
||||
#define NODE_LOG_TYPE_PERIODIC 1
|
||||
#define NODE_LOG_TYPE_BOOT 2
|
||||
#define NODE_LOG_TYPE_EVENT 3
|
||||
|
||||
/** Event subtypes. Periodic samples give the trend; these give the moment. */
|
||||
#define NODE_LOG_EV_WIFI_DISCONNECT 1
|
||||
#define NODE_LOG_EV_WIFI_RECONNECT 2
|
||||
#define NODE_LOG_EV_THERMAL_STATE 3
|
||||
#define NODE_LOG_EV_SEND_FAIL_RATE 4
|
||||
#define NODE_LOG_EV_WATCHDOG 5
|
||||
|
||||
/** Mount the FAT volume and open the ring. Call once at boot, after NVS is up
|
||||
* (the boot counter lives there).
|
||||
*
|
||||
* Failure is NOT fatal: on any error this module disables itself and every
|
||||
* other entry point becomes a no-op. A logging volume that will not mount must
|
||||
* never take the fleet down with it. */
|
||||
esp_err_t node_log_init(void);
|
||||
|
||||
/** True when the ring mounted and writes are being accepted. */
|
||||
bool node_log_is_active(void);
|
||||
|
||||
/** Append the boot record: reset reason, the previous session's final uptime,
|
||||
* and a health snapshot.
|
||||
*
|
||||
* The highest-value record here. It catches a HANG FOLLOWED BY A WATCHDOG
|
||||
* RESET, which is the failure that bites this fleet and the one a coredump
|
||||
* does not capture. */
|
||||
void node_log_boot(uint32_t reset_reason, uint32_t prev_uptime_s);
|
||||
|
||||
/** Append a periodic health sample. Rate-limited internally, so a caller cannot
|
||||
* wear the flash by calling it in a tight loop. */
|
||||
void node_log_periodic(void);
|
||||
|
||||
/** Append an event record. a/b carry subtype-specific detail -- for a WiFi
|
||||
* disconnect they are the reason code and the RSSI at that moment, the pair
|
||||
* main.c currently logs only to the console. */
|
||||
void node_log_event(uint8_t subtype, int32_t a, int32_t b);
|
||||
|
||||
/** Record a WiFi disconnect for the health snapshot's cumulative counters.
|
||||
* Kept as a setter so this module has no include cycle with main.c, which is
|
||||
* where the reason and RSSI are actually known. */
|
||||
void node_log_note_disconnect(uint8_t reason, int8_t rssi);
|
||||
|
||||
/** Copy raw records into out, newest-first, for the HTTP reader.
|
||||
*
|
||||
* @param out destination, at least max_records * NODE_LOG_RECORD_SIZE
|
||||
* @param max_records maximum to copy
|
||||
* @param skip how many of the newest to skip, so a caller can page
|
||||
* @return number of records written into out */
|
||||
size_t node_log_read(uint8_t *out, size_t max_records, size_t skip);
|
||||
|
||||
/** Total records currently held in the ring. */
|
||||
size_t node_log_count(void);
|
||||
|
||||
/** Boot id of the current session. Records from the same boot share it. */
|
||||
uint16_t node_log_boot_id(void);
|
||||
|
||||
/** Erase every record. Deliberately explicit and never called automatically --
|
||||
* the whole point of the module is that state survives. */
|
||||
esp_err_t node_log_clear(void);
|
||||
|
||||
#ifdef __cplusplus
|
||||
}
|
||||
#endif
|
||||
@@ -21,3 +21,21 @@ CONFIG_PARTITION_TABLE_CUSTOM_FILENAME="partitions_16mb.csv"
|
||||
# itself, or the bootloader reverts on the next boot. See ota_rollback_* in
|
||||
# ota_update.c for when confirmation happens and why.
|
||||
CONFIG_BOOTLOADER_APP_ROLLBACK_ENABLE=y
|
||||
|
||||
# Coredump to flash. The 64K `coredump` partition has existed in
|
||||
# partitions_16mb.csv since the 16MB layout was written and has never held
|
||||
# anything, because the build defaulted to
|
||||
# CONFIG_ESP_COREDUMP_ENABLE_TO_NONE=y. A panic therefore left no stack trace
|
||||
# on a fleet whose faults are all remote.
|
||||
#
|
||||
# Complementary to the on-node log, not a substitute: a coredump captures a
|
||||
# CRASH, and the log's boot record captures a HANG followed by a watchdog
|
||||
# reset -- which is the failure this fleet actually sees.
|
||||
CONFIG_ESP_COREDUMP_ENABLE_TO_FLASH=y
|
||||
CONFIG_ESP_COREDUMP_DATA_FORMAT_ELF=y
|
||||
CONFIG_ESP_COREDUMP_CHECKSUM_CRC32=y
|
||||
CONFIG_ESP_COREDUMP_LOGS=y
|
||||
|
||||
# The `storage` FAT volume (8000K) that node_log.c mounts. Reserved in the
|
||||
# same partition table and likewise never used until now.
|
||||
CONFIG_WL_SECTOR_SIZE_4096=y
|
||||
Reference in new issue
Block a user