fix(firmware): event_log thread safety and NVS wear
- Remove monotonic counter writes to NVS (stop burning flash on every event). Derive head and cnt by scanning slots on boot. - Widen seq to uint32 so slot scan works across multi-year lifetimes. - Add FreeRTOS mutex around write/read so WiFi event handlers can safely call event_log_write from another task. - Check Preferences.begin() return; disable logging if NVS unavailable. - Extract NTP_SYNC_THRESHOLD constant; drop misleading native uptime. - Add tests for empty read, max_entries truncation, real-path hash.
This commit is contained in:
@@ -7,10 +7,15 @@
|
|||||||
#include <Arduino.h>
|
#include <Arduino.h>
|
||||||
#include <Preferences.h>
|
#include <Preferences.h>
|
||||||
#include <time.h>
|
#include <time.h>
|
||||||
|
#include <freertos/FreeRTOS.h>
|
||||||
|
#include <freertos/semphr.h>
|
||||||
static Preferences s_prefs;
|
static Preferences s_prefs;
|
||||||
static const char* NVS_NS = "evlog";
|
static const char* NVS_NS = "evlog";
|
||||||
static const char* NVS_HEAD = "head"; // next write slot (0..31)
|
static bool s_ok = false;
|
||||||
static const char* NVS_CNT = "cnt"; // total writes (for seq)
|
static SemaphoreHandle_t s_mutex = nullptr;
|
||||||
|
static uint32_t g_head = 0; // next write slot (0..31), RAM-only
|
||||||
|
static uint32_t g_cnt = 0; // total writes since boot scan, RAM-only
|
||||||
|
static constexpr time_t NTP_SYNC_THRESHOLD = 1700000000; // 2023-11-14
|
||||||
#else
|
#else
|
||||||
// Native build: in-memory stub
|
// Native build: in-memory stub
|
||||||
#include <cstdint>
|
#include <cstdint>
|
||||||
@@ -56,48 +61,78 @@ static bool slot_read(size_t idx, EventLogEntry& e) {
|
|||||||
|
|
||||||
void event_log_init() {
|
void event_log_init() {
|
||||||
#ifdef ARDUINO
|
#ifdef ARDUINO
|
||||||
s_prefs.begin(NVS_NS, /*readOnly=*/false);
|
if (s_mutex == nullptr) {
|
||||||
|
s_mutex = xSemaphoreCreateMutex();
|
||||||
|
}
|
||||||
|
s_ok = s_prefs.begin(NVS_NS, /*readOnly=*/false);
|
||||||
|
if (!s_ok) {
|
||||||
|
Serial.println("[evlog] NVS begin failed");
|
||||||
|
return;
|
||||||
|
}
|
||||||
|
// Scan all 32 slots; locate the one with the largest seq.
|
||||||
|
// Empty log: every slot tag == 0 (not a valid EventLogTag, which starts at 1).
|
||||||
|
uint32_t max_seq = 0;
|
||||||
|
int max_idx = -1;
|
||||||
|
bool any_valid = false;
|
||||||
|
for (size_t i = 0; i < SLOTS; i++) {
|
||||||
|
EventLogEntry e = {};
|
||||||
|
if (!slot_read(i, e)) continue;
|
||||||
|
if (e.tag == 0) continue;
|
||||||
|
any_valid = true;
|
||||||
|
if (max_idx < 0 || e.seq >= max_seq) {
|
||||||
|
max_seq = e.seq;
|
||||||
|
max_idx = (int)i;
|
||||||
|
}
|
||||||
|
}
|
||||||
|
if (any_valid) {
|
||||||
|
g_head = (uint32_t)((max_idx + 1) % SLOTS);
|
||||||
|
g_cnt = max_seq + 1;
|
||||||
|
} else {
|
||||||
|
g_head = 0;
|
||||||
|
g_cnt = 0;
|
||||||
|
}
|
||||||
#else
|
#else
|
||||||
// nothing
|
// nothing
|
||||||
#endif
|
#endif
|
||||||
}
|
}
|
||||||
|
|
||||||
void event_log_write(EventLogTag tag, uint16_t data0, uint16_t data1) {
|
void event_log_write(EventLogTag tag, uint16_t data0, uint16_t data1) {
|
||||||
EventLogEntry e = {};
|
|
||||||
#ifdef ARDUINO
|
#ifdef ARDUINO
|
||||||
|
if (!s_ok) return;
|
||||||
|
if (s_mutex) xSemaphoreTake(s_mutex, portMAX_DELAY);
|
||||||
|
EventLogEntry e = {};
|
||||||
time_t now = time(nullptr);
|
time_t now = time(nullptr);
|
||||||
e.ts_unix = (now > 1700000000) ? (uint32_t)now : 0;
|
e.ts_unix = (now > NTP_SYNC_THRESHOLD) ? (uint32_t)now : 0;
|
||||||
e.uptime_s = (uint32_t)(millis() / 1000);
|
e.uptime_s = (uint32_t)(millis() / 1000);
|
||||||
uint32_t head = s_prefs.getUInt(NVS_HEAD, 0);
|
|
||||||
uint32_t cnt = s_prefs.getUInt(NVS_CNT, 0);
|
|
||||||
#else
|
|
||||||
e.ts_unix = 0;
|
|
||||||
e.uptime_s = g_cnt; // stand-in for uptime in native tests
|
|
||||||
uint32_t head = g_head;
|
|
||||||
uint32_t cnt = g_cnt;
|
|
||||||
#endif
|
|
||||||
e.tag = (uint8_t)tag;
|
e.tag = (uint8_t)tag;
|
||||||
e.data0 = data0;
|
e.data0 = data0;
|
||||||
e.data1 = data1;
|
e.data1 = data1;
|
||||||
e.seq = (uint8_t)(cnt & 0xFF);
|
e.seq = g_cnt;
|
||||||
slot_write(head % SLOTS, e);
|
slot_write(g_head % SLOTS, e);
|
||||||
#ifdef ARDUINO
|
g_head = (g_head + 1) % SLOTS;
|
||||||
s_prefs.putUInt(NVS_HEAD, (head + 1) % SLOTS);
|
g_cnt = g_cnt + 1;
|
||||||
s_prefs.putUInt(NVS_CNT, cnt + 1);
|
if (s_mutex) xSemaphoreGive(s_mutex);
|
||||||
#else
|
#else
|
||||||
g_head = (head + 1) % SLOTS;
|
EventLogEntry e = {};
|
||||||
g_cnt = cnt + 1;
|
e.ts_unix = 0;
|
||||||
|
e.uptime_s = 0;
|
||||||
|
e.tag = (uint8_t)tag;
|
||||||
|
e.data0 = data0;
|
||||||
|
e.data1 = data1;
|
||||||
|
e.seq = g_cnt;
|
||||||
|
slot_write(g_head % SLOTS, e);
|
||||||
|
g_head = (g_head + 1) % SLOTS;
|
||||||
|
g_cnt = g_cnt + 1;
|
||||||
#endif
|
#endif
|
||||||
}
|
}
|
||||||
|
|
||||||
size_t event_log_read_recent(EventLogEntry* out, size_t max_entries) {
|
size_t event_log_read_recent(EventLogEntry* out, size_t max_entries) {
|
||||||
#ifdef ARDUINO
|
#ifdef ARDUINO
|
||||||
uint32_t head = s_prefs.getUInt(NVS_HEAD, 0);
|
if (!s_ok) return 0;
|
||||||
uint32_t cnt = s_prefs.getUInt(NVS_CNT, 0);
|
if (s_mutex) xSemaphoreTake(s_mutex, portMAX_DELAY);
|
||||||
#else
|
#endif
|
||||||
uint32_t head = g_head;
|
uint32_t head = g_head;
|
||||||
uint32_t cnt = g_cnt;
|
uint32_t cnt = g_cnt;
|
||||||
#endif
|
|
||||||
size_t available = (cnt < SLOTS) ? (size_t)cnt : SLOTS;
|
size_t available = (cnt < SLOTS) ? (size_t)cnt : SLOTS;
|
||||||
size_t n = (max_entries < available) ? max_entries : available;
|
size_t n = (max_entries < available) ? max_entries : available;
|
||||||
for (size_t i = 0; i < n; i++) {
|
for (size_t i = 0; i < n; i++) {
|
||||||
@@ -105,5 +140,8 @@ size_t event_log_read_recent(EventLogEntry* out, size_t max_entries) {
|
|||||||
size_t idx = (head + SLOTS - 1 - i) % SLOTS;
|
size_t idx = (head + SLOTS - 1 - i) % SLOTS;
|
||||||
slot_read(idx, out[i]);
|
slot_read(idx, out[i]);
|
||||||
}
|
}
|
||||||
|
#ifdef ARDUINO
|
||||||
|
if (s_mutex) xSemaphoreGive(s_mutex);
|
||||||
|
#endif
|
||||||
return n;
|
return n;
|
||||||
}
|
}
|
||||||
|
|||||||
@@ -27,8 +27,8 @@ struct EventLogEntry {
|
|||||||
uint16_t data0;
|
uint16_t data0;
|
||||||
uint16_t data1;
|
uint16_t data1;
|
||||||
uint8_t tag; // EventLogTag
|
uint8_t tag; // EventLogTag
|
||||||
uint8_t seq; // rolling sequence, wraps
|
uint32_t seq; // widened; survives multi-year event rates
|
||||||
uint8_t _pad[18]; // pad to 32 bytes for fixed slot size
|
uint8_t _pad[15]; // pad to 32 bytes for fixed slot size
|
||||||
} __attribute__((packed));
|
} __attribute__((packed));
|
||||||
static_assert(sizeof(EventLogEntry) == 32, "EventLogEntry must be 32 bytes");
|
static_assert(sizeof(EventLogEntry) == 32, "EventLogEntry must be 32 bytes");
|
||||||
|
|
||||||
|
|||||||
@@ -46,11 +46,42 @@ void test_ring_buffer_wraps_after_32_entries() {
|
|||||||
TEST_ASSERT_EQUAL(8, buf[31].data0);
|
TEST_ASSERT_EQUAL(8, buf[31].data0);
|
||||||
}
|
}
|
||||||
|
|
||||||
|
void test_empty_log_read_returns_zero() {
|
||||||
|
event_log_init();
|
||||||
|
EventLogEntry buf[8];
|
||||||
|
size_t n = event_log_read_recent(buf, 8);
|
||||||
|
TEST_ASSERT_EQUAL(0, n);
|
||||||
|
}
|
||||||
|
|
||||||
|
void test_read_recent_truncates_to_max_entries() {
|
||||||
|
event_log_init();
|
||||||
|
for (int i = 0; i < 10; i++) event_log_write(EVT_HTTP_OK, (uint16_t)i, 0);
|
||||||
|
EventLogEntry buf[3];
|
||||||
|
size_t n = event_log_read_recent(buf, 3);
|
||||||
|
TEST_ASSERT_EQUAL(3, n);
|
||||||
|
// Newest 3: data0 == 9, 8, 7
|
||||||
|
TEST_ASSERT_EQUAL(9, buf[0].data0);
|
||||||
|
TEST_ASSERT_EQUAL(8, buf[1].data0);
|
||||||
|
TEST_ASSERT_EQUAL(7, buf[2].data0);
|
||||||
|
}
|
||||||
|
|
||||||
|
void test_path_hash_distinguishes_real_api_paths() {
|
||||||
|
uint16_t h1 = event_log_path_hash("/api/v1/heartbeat");
|
||||||
|
uint16_t h2 = event_log_path_hash("/api/v1/camera/events/batch");
|
||||||
|
uint16_t h3 = event_log_path_hash("/api/v1/events/batch");
|
||||||
|
TEST_ASSERT_NOT_EQUAL(h1, h2);
|
||||||
|
TEST_ASSERT_NOT_EQUAL(h1, h3);
|
||||||
|
TEST_ASSERT_NOT_EQUAL(h2, h3);
|
||||||
|
}
|
||||||
|
|
||||||
int main() {
|
int main() {
|
||||||
UNITY_BEGIN();
|
UNITY_BEGIN();
|
||||||
RUN_TEST(test_entry_is_32_bytes);
|
RUN_TEST(test_entry_is_32_bytes);
|
||||||
RUN_TEST(test_path_hash_is_stable_and_differs);
|
RUN_TEST(test_path_hash_is_stable_and_differs);
|
||||||
RUN_TEST(test_write_then_read_recent_returns_newest_first);
|
RUN_TEST(test_write_then_read_recent_returns_newest_first);
|
||||||
RUN_TEST(test_ring_buffer_wraps_after_32_entries);
|
RUN_TEST(test_ring_buffer_wraps_after_32_entries);
|
||||||
|
RUN_TEST(test_empty_log_read_returns_zero);
|
||||||
|
RUN_TEST(test_read_recent_truncates_to_max_entries);
|
||||||
|
RUN_TEST(test_path_hash_distinguishes_real_api_paths);
|
||||||
return UNITY_END();
|
return UNITY_END();
|
||||||
}
|
}
|
||||||
|
|||||||
Reference in New Issue
Block a user