From ea8eb67b2e1d268dedbbd7d6453e05ee69d24c73 Mon Sep 17 00:00:00 2001 From: lawther Date: Thu, 25 Jun 2026 09:53:23 +1000 Subject: [PATCH] feat: sliding-window frame parser with per-type resync tracking Replace the all-or-nothing frame parser with a sliding-window resync: on a bad header checksum, control bytes, length, end byte, or data checksum the parser discards a single byte and retries, recovering valid frames from stutters, cross-device collisions, and line noise (issue #46). Framing logic moves into a dedicated, host-testable framing.c module; error accounting is reworked from message-error counters into per-type resync counters surfaced on the status page and tagged through the unknown-message buffer. Tests: golden-file harness seeded with the real captures from the issue, plus chunked-input cases (| splits one case into multiple add_bytes calls) and a chunk-invariance property sweep proving frame recovery is independent of how the byte stream is fragmented across reads. --- .vscode/tasks.json | 26 ++ CHANGELOG.md | 4 + README.md | 15 + main/CMakeLists.txt | 1 + main/framing.c | 196 ++++++++ main/framing.h | 47 ++ main/main.c | 32 +- main/message_decoder.c | 67 +-- main/pool_state.h | 27 +- main/tcp_bridge.c | 240 ++++------ main/tcp_bridge.h | 27 +- main/unknown_buffer.c | 26 +- main/unknown_buffer.h | 27 +- main/web_handlers.c | 47 +- test/frames/chunked_reassembly.txt | 27 ++ test/frames/chunked_reassembly_output.txt | 22 + test/frames/observed_error_frames.txt | 37 ++ test/frames/observed_error_frames_output.txt | 232 +++++++++ test/frames/synthetic_errors.txt | 28 ++ test/frames/synthetic_errors_output.txt | 28 ++ test/run_tests.sh | 22 +- test/test_framing.c | 467 +++++++++++++++++++ test/unknown_buffer_stub.c | 6 +- 23 files changed, 1381 insertions(+), 270 deletions(-) create mode 100644 main/framing.c create mode 100644 main/framing.h create mode 100644 test/frames/chunked_reassembly.txt create mode 100644 test/frames/chunked_reassembly_output.txt create mode 100644 test/frames/observed_error_frames.txt create mode 100644 test/frames/observed_error_frames_output.txt create mode 100644 test/frames/synthetic_errors.txt create mode 100644 test/frames/synthetic_errors_output.txt create mode 100644 test/test_framing.c diff --git a/.vscode/tasks.json b/.vscode/tasks.json index 07d432b..ef1af61 100644 --- a/.vscode/tasks.json +++ b/.vscode/tasks.json @@ -65,6 +65,32 @@ "close": false }, "problemMatcher": [] + }, + { + "label": "Framing: run", + "type": "shell", + "command": "gcc -I. -I.. -o run_framing test_framing.c log_capture.c && ./run_framing; ec=$?; rm -f ./run_framing; exit $ec", + "options": { "cwd": "${workspaceFolder}/test" }, + "group": "test", + "presentation": { + "reveal": "always", + "panel": "shared", + "close": false + }, + "problemMatcher": [] + }, + { + "label": "Framing: bless goldens", + "type": "shell", + "command": "gcc -I. -I.. -o run_framing test_framing.c log_capture.c && ./run_framing --bless; ec=$?; rm -f ./run_framing; exit $ec", + "options": { "cwd": "${workspaceFolder}/test" }, + "group": "test", + "presentation": { + "reveal": "always", + "panel": "shared", + "close": false + }, + "problemMatcher": [] } ], "inputs": [ diff --git a/CHANGELOG.md b/CHANGELOG.md index 1430e3e..b9d9714 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -24,6 +24,10 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 - Note about CMD 0x12 observed with payload 0x01 0x00. Added to PROTOCOL.md and new sample trace. - Parsing for CMD 0x12 updated so `0x01 0x00` no longer reported as unexpected. - Full decoding of CMD 0x12 status byte for Gas Heaters (HiNRG `0x0072` and ICI (`0x0074`)) +- Rewrote frame level parser to use a sliding window for better resync on errors +- Track frame resync events per failure type (no-start, header/data checksum, control, length, end-byte, overflow) and show the breakdown on the status page, separate from message-level decode errors +- Unknown Messages page now tags each captured frame with its specific reason (no start, overflow, header/data checksum, length, bad framing) instead of a generic "error" chip +- **Breaking (HTTP):** `/status` JSON's `message_counts.errors` (per-type protocol error counters) and `message_counts.error_detail` (introduced in 1.6.0-rc1) are removed, replaced by the new per-type `resyncs` object (`total`, `no_start`, `header_checksum`, `bad_control`, `bad_length`, `bad_end`, `data_checksum`, `buffer_overflow`) emitted by the sliding-window frame parser. Any external consumer reading the old fields needs to switch to `resyncs`. ### Removed ### Fixed ### Deprecated diff --git a/README.md b/README.md index 645e5c1..94c2aea 100644 --- a/README.md +++ b/README.md @@ -244,6 +244,8 @@ From VS Code inside the devcontainer: **Cmd+Shift+P → "Tasks: Run Task"** list - **Replay: all samples** — just the replay step. - **Replay: bless all samples** — rewrite expected output in every sample using the current decoder's output. Use after intentional decoder/logging changes, then review `git diff test/samples/` before committing. - **Replay: single file** / **Replay: bless single file** — same but prompted for a single path. +- **Framing: run** — exercise the sliding-window frame parser against the goldens in `test/frames/`. +- **Framing: bless goldens** — regenerate `test/frames/*_output.txt` from the current parser. Use after intentional framing changes, then review `git diff test/frames/` before committing. ### Adding a regression sample @@ -252,6 +254,19 @@ From VS Code inside the devcontainer: **Cmd+Shift+P → "Tasks: Run Task"** list 3. Run **Replay: bless single file** against it — this normalises the expected output to the current decoder. 4. Review with `git diff`, then commit. The file is now a regression test. +### Frame parser (sliding window) tests + +The frame parser is tested separately from the decoder: each line of `test/frames/observed_error_frames.txt` (real bus captures) and `test/frames/synthetic_errors.txt` (synthetic, one per failure mode) is fed to the parser, and the ordered stream of resync events (`Resync: `) and decoded frames is diffed against the matching `--- Case N ---` block in the `*_output.txt` golden. On a mismatch the failure prints the source location as `path:line`. + +The goldens are blessable from the CLI, mirroring replay: + +```bash +cd test +gcc -I. -I.. -o run_framing test_framing.c log_capture.c && ./run_framing --bless; rm -f run_framing +``` + +After blessing, review `git diff test/frames/` — the diff is the exact record of how parser behaviour changed. + ### Improving "Unhandled" message logging When the decoder gains support for a previously-unknown command, replaying old samples surfaces it as a mismatch (e.g. `Unhandled CMD=0xXX` → real decode). Bless the affected samples and the diff in git is the exact documentation of what improved. diff --git a/main/CMakeLists.txt b/main/CMakeLists.txt index e2fffb3..a3b01f4 100644 --- a/main/CMakeLists.txt +++ b/main/CMakeLists.txt @@ -11,6 +11,7 @@ idf_component_register( "mqtt_commands.c" "web_handlers.c" "tcp_bridge.c" + "framing.c" "message_decoder.c" "register_requester.c" "unknown_buffer.c" diff --git a/main/framing.c b/main/framing.c new file mode 100644 index 0000000..5781012 --- /dev/null +++ b/main/framing.c @@ -0,0 +1,196 @@ +#include "framing.h" +#include "esp_log.h" +#include +#include + +static const char *TAG = "BUS_FRAMING"; + +// Header validation only ever inspects bytes 0-9 (see layout in framing.h); +// cap early-failure captures to that window rather than the whole remaining +// buffer. Otherwise the captured bytes (and length) vary with how much +// trailing valid data happens to be queued, which both pollutes the +// unknown-message diagnostics with unrelated trailing frames and defeats +// dedup in unknown_buffer_record (which keys on reason + len + raw bytes). +#define FRAMING_HEADER_CAPTURE_LEN 10 + +// Format up to `cap` bytes of `data` as a space-separated hex string into +// `hex_str` (size `hex_str_size`). Does not append a truncation marker — +// callers that care whether `len > cap` add their own suffix to the log line. +static void framing_format_hex_dump(const uint8_t *data, int len, int cap, char *hex_str, size_t hex_str_size) +{ + int hex_pos = 0; + int dump_len = MIN(len, cap); + for (int i = 0; i < dump_len && hex_pos < (int)hex_str_size - 3; i++) { + hex_pos += snprintf(&hex_str[hex_pos], hex_str_size - hex_pos, "%02X ", data[i]); + } + hex_str[hex_pos] = '\0'; +} + +// Capture `capture_len` bytes from the front of `fb` into out_frame/out_len +// for diagnostics, then resync by discarding a single byte and shifting the +// rest of the buffer down. The per-byte memmove is O(n), so draining a full +// garbage buffer one byte at a time is O(n^2) - acceptable only because +// BUS_MESSAGE_MAX_SIZE is small (256B). +static void framing_resync_one_byte(framing_buffer_t *fb, uint8_t *out_frame, int *out_len, int capture_len) +{ + if (out_frame) { + memcpy(out_frame, fb->buffer, capture_len); + } + if (out_len) { + *out_len = capture_len; + } + memmove(fb->buffer, &fb->buffer[1], fb->len - 1); + fb->len--; +} + +void framing_init(framing_buffer_t *fb) +{ + if (fb) { + fb->len = 0; + } +} + +bool framing_add_bytes(framing_buffer_t *fb, const uint8_t *data, int len) +{ + if (!fb || !data || len <= 0) { + return false; + } + if (fb->len + len > BUS_MESSAGE_MAX_SIZE) { + return false; + } + memcpy(&fb->buffer[fb->len], data, len); + fb->len += len; + return true; +} + +framing_result_t framing_process_next(framing_buffer_t *fb, uint8_t *out_frame, int *out_len) +{ + if (!fb) { + return FRAMING_NEED_MORE_DATA; + } + + // Need at least minimum message: START + SRC + DST + CTRL + CMD(3) + CHK + END = 12 bytes + if (fb->len < 12) { + return FRAMING_NEED_MORE_DATA; + } + + // Find start byte (0x02) + int start_idx = -1; + for (int i = 0; i < fb->len; i++) { + if (fb->buffer[i] == 0x02) { + start_idx = i; + break; + } + } + + // No start byte found - discard everything + if (start_idx == -1) { + char hex_str[100]; + framing_format_hex_dump(fb->buffer, fb->len, 32, hex_str, sizeof(hex_str)); + ESP_LOGW(TAG, "No start byte in buffer, discarding %d bytes: %s%s", + fb->len, hex_str, fb->len > 32 ? "..." : ""); + // Hand the discarded bytes back so the caller can capture them. + if (out_frame) { + memcpy(out_frame, fb->buffer, fb->len); + } + if (out_len) { + *out_len = fb->len; + } + fb->len = 0; + return FRAMING_NO_START_BYTE; + } + + // Discard bytes before start. This happens silently with respect to the + // resync counters/unknown buffer (those only track the byte-stepped BAD_* + // resyncs and the no-start-at-all case) - log it so a multi-byte jump like + // this is still visible somewhere. + if (start_idx > 0) { + char hex_str[100]; + framing_format_hex_dump(fb->buffer, start_idx, 32, hex_str, sizeof(hex_str)); + ESP_LOGW(TAG, "Discarding %d byte(s) before next start byte: %s%s", + start_idx, hex_str, start_idx > 32 ? "..." : ""); + memmove(fb->buffer, &fb->buffer[start_idx], fb->len - start_idx); + fb->len -= start_idx; + } + + // Check we have enough for header validation (10 bytes: 0..9) + if (fb->len < 10) { + return FRAMING_NEED_MORE_DATA; + } + + // Validate header checksum: byte 9 must be sum(bytes 0-8) & 0xFF + // We test checksum first, and only then the other header bytes - this way, + // a bad length will only survive if the checksum is coincidentally correct. + uint8_t expected_hchk = 0; + for (int i = 0; i < 9; i++) { + expected_hchk += fb->buffer[i]; + } + if (fb->buffer[9] != expected_hchk) { + char hex_str[100]; + framing_format_hex_dump(fb->buffer, fb->len, 32, hex_str, sizeof(hex_str)); + ESP_LOGW(TAG, "Invalid header checksum: calculated %02X, got %02X, data: %s%s, resyncing by 1 byte", + expected_hchk, fb->buffer[9], hex_str, fb->len > 32 ? "..." : ""); + framing_resync_one_byte(fb, out_frame, out_len, MIN(fb->len, FRAMING_HEADER_CAPTURE_LEN)); + return FRAMING_BAD_HEADER_CHECKSUM; + } + + // Validate control bytes (positions 5-6 should be 0x80 0x00) + if (fb->buffer[5] != 0x80 || fb->buffer[6] != 0x00) { + ESP_LOGW(TAG, "Invalid control bytes: %02X %02X (expected 80 00), resyncing by 1 byte", + fb->buffer[5], fb->buffer[6]); + framing_resync_one_byte(fb, out_frame, out_len, MIN(fb->len, FRAMING_HEADER_CAPTURE_LEN)); + return FRAMING_BAD_CONTROL_BYTES; + } + + // Read length from byte 8 + int msg_len = fb->buffer[8]; + if (msg_len < 12 || msg_len > BUS_MESSAGE_MAX_SIZE) { + ESP_LOGW(TAG, "Invalid length field in header: 0x%02X (%d), resyncing by 1 byte", + msg_len, msg_len); + framing_resync_one_byte(fb, out_frame, out_len, MIN(fb->len, FRAMING_HEADER_CAPTURE_LEN)); + return FRAMING_BAD_LENGTH; + } + + // Check if we have received the full message yet + if (fb->len < msg_len) { + return FRAMING_NEED_MORE_DATA; + } + + // Verify end byte (0x03) + if (fb->buffer[msg_len - 1] != 0x03) { + ESP_LOGW(TAG, "Invalid end byte (expected 03, got %02X) at length %d, resyncing by 1 byte", + fb->buffer[msg_len - 1], msg_len); + framing_resync_one_byte(fb, out_frame, out_len, msg_len); + return FRAMING_BAD_END_BYTE; + } + + // Verify data checksum: sum(bytes 10..msg_len-3) & 0xFF + uint32_t data_sum = 0; + for (int i = 10; i < msg_len - 2; i++) { + data_sum += fb->buffer[i]; + } + uint8_t calculated_dchk = data_sum & 0xFF; + if (fb->buffer[msg_len - 2] != calculated_dchk) { + ESP_LOGW(TAG, "Invalid data checksum: calculated %02X, got %02X, resyncing by 1 byte", + calculated_dchk, fb->buffer[msg_len - 2]); + framing_resync_one_byte(fb, out_frame, out_len, msg_len); + return FRAMING_BAD_DATA_CHECKSUM; + } + + // Valid frame — copy out before consuming from buffer + if (out_frame) { + memcpy(out_frame, fb->buffer, msg_len); + } + if (out_len) { + *out_len = msg_len; + } + + // Remove processed message from buffer + int remaining = fb->len - msg_len; + if (remaining > 0) { + memmove(fb->buffer, &fb->buffer[msg_len], remaining); + } + fb->len = remaining; + + return FRAMING_FRAME_READY; +} diff --git a/main/framing.h b/main/framing.h new file mode 100644 index 0000000..e5d7413 --- /dev/null +++ b/main/framing.h @@ -0,0 +1,47 @@ +#ifndef FRAMING_H +#define FRAMING_H + +#include +#include +#include +#include "config.h" + +typedef enum { + FRAMING_NEED_MORE_DATA, // incomplete, wait for more bytes + FRAMING_NO_START_BYTE, // no 0x02 found, buffer cleared + FRAMING_BAD_HEADER_CHECKSUM, // header checksum mismatch, resynced by 1 + FRAMING_BAD_CONTROL_BYTES, // bytes 5-6 not 0x80 0x00, resynced by 1 + FRAMING_BAD_LENGTH, // length field out of range, resynced by 1 + FRAMING_BAD_END_BYTE, // end byte not 0x03, resynced by 1 + FRAMING_BAD_DATA_CHECKSUM, // data checksum mismatch, resynced by 1 + FRAMING_FRAME_READY, // valid frame written to out_frame +} framing_result_t; + +// Context structure holding the reassembly buffer +typedef struct { + uint8_t buffer[BUS_MESSAGE_MAX_SIZE]; + int len; +} framing_buffer_t; + +/** + * Initialize a framing buffer context. + */ +void framing_init(framing_buffer_t *fb); + +/** + * Add bytes to the framing buffer. + * Returns true if bytes were successfully added, false if buffer is full. + */ +bool framing_add_bytes(framing_buffer_t *fb, const uint8_t *data, int len); + +/** + * Extract one complete message from the reassembly buffer. + * On FRAMING_FRAME_READY the frame is written to out_frame and out_len; on + * every other resync result (NO_START / BAD_*) the bytes that triggered the + * resync are written there instead, so the caller can capture them. + * FRAMING_NEED_MORE_DATA means stop and wait; all other results mean call + * again immediately. + */ +framing_result_t framing_process_next(framing_buffer_t *fb, uint8_t *out_frame, int *out_len); + +#endif // FRAMING_H diff --git a/main/main.c b/main/main.c index edaa538..c5976d2 100644 --- a/main/main.c +++ b/main/main.c @@ -54,20 +54,36 @@ static bool decode_wrapper(const uint8_t *data, int len) return decode_message(data, len, &s_decoder_context); } -static void frame_error_wrapper(tcp_bridge_frame_error_t error, const uint8_t *data, int len) +static void resync_wrapper(tcp_bridge_resync_type_t type, const uint8_t *data, int len) { if (xSemaphoreTake(s_pool_state_mutex, pdMS_TO_TICKS(MUTEX_TIMEOUT_MS)) != pdTRUE) { return; } - s_pool_state.messages_error_total++; - switch (error) { - case TCP_BRIDGE_FRAME_ERR_NO_START: s_pool_state.errors_no_start++; break; - case TCP_BRIDGE_FRAME_ERR_BAD_CONTROL: s_pool_state.errors_bad_control++; break; - case TCP_BRIDGE_FRAME_ERR_NO_END: s_pool_state.errors_no_end++; break; + s_pool_state.resyncs_total++; + switch (type) { + case TCP_BRIDGE_RESYNC_NO_START: s_pool_state.resyncs_no_start++; break; + case TCP_BRIDGE_RESYNC_BAD_HEADER_CHECKSUM: s_pool_state.resyncs_bad_header_checksum++; break; + case TCP_BRIDGE_RESYNC_BAD_CONTROL: s_pool_state.resyncs_bad_control++; break; + case TCP_BRIDGE_RESYNC_BAD_LENGTH: s_pool_state.resyncs_bad_length++; break; + case TCP_BRIDGE_RESYNC_BAD_END: s_pool_state.resyncs_bad_end++; break; + case TCP_BRIDGE_RESYNC_BAD_DATA_CHECKSUM: s_pool_state.resyncs_bad_data_checksum++; break; + case TCP_BRIDGE_RESYNC_BUFFER_OVERFLOW: s_pool_state.resyncs_buffer_overflow++; break; } xSemaphoreGive(s_pool_state_mutex); + if (data && len > 0) { - unknown_buffer_record(data, len, true); + unknown_reason_t reason; + switch (type) { + case TCP_BRIDGE_RESYNC_NO_START: reason = UNKNOWN_REASON_NO_START; break; + case TCP_BRIDGE_RESYNC_BAD_HEADER_CHECKSUM: reason = UNKNOWN_REASON_HEADER_CHECKSUM; break; + case TCP_BRIDGE_RESYNC_BAD_CONTROL: reason = UNKNOWN_REASON_BAD_CONTROL; break; + case TCP_BRIDGE_RESYNC_BAD_LENGTH: reason = UNKNOWN_REASON_BAD_LENGTH; break; + case TCP_BRIDGE_RESYNC_BAD_END: reason = UNKNOWN_REASON_BAD_END; break; + case TCP_BRIDGE_RESYNC_BAD_DATA_CHECKSUM: reason = UNKNOWN_REASON_DATA_CHECKSUM; break; + case TCP_BRIDGE_RESYNC_BUFFER_OVERFLOW: reason = UNKNOWN_REASON_BUFFER_OVERFLOW; break; + default: reason = UNKNOWN_REASON_UNEXPECTED; break; + } + unknown_buffer_record(data, len, reason); } } @@ -189,7 +205,7 @@ void app_main(void) .decode_message = decode_wrapper, .led_flash_rx = led_flash_rx, .led_flash_tx = led_flash_tx, - .on_frame_error = frame_error_wrapper, + .on_resync = resync_wrapper, }; esp_err_t bridge_err = tcp_bridge_start(&bridge_config); if (bridge_err == ESP_OK) { diff --git a/main/message_decoder.c b/main/message_decoder.c index c72d884..f465a13 100644 --- a/main/message_decoder.c +++ b/main/message_decoder.c @@ -2906,12 +2906,7 @@ bool decode_message(const uint8_t *data, int len, message_decoder_context_t *ctx // Minimum valid message: 10-byte header + data checksum + end byte if (len < 12 || data[0] != 0x02 || data[len - 1] != 0x03) { - if (ctx->state_mutex && xSemaphoreTake(ctx->state_mutex, pdMS_TO_TICKS(MUTEX_TIMEOUT_MS)) == pdTRUE) { - ctx->pool_state->errors_bad_framing++; - ctx->pool_state->messages_error_total++; - xSemaphoreGive(ctx->state_mutex); - } - unknown_buffer_record(data, len, true); + unknown_buffer_record(data, len, UNKNOWN_REASON_BAD_FRAMING); return false; } @@ -2927,31 +2922,6 @@ bool decode_message(const uint8_t *data, int len, message_decoder_context_t *ctx ESP_LOGI(TAG, "RX MSG: %s", full_msg); free(full_msg); - // Validate length field: byte[8] = total message length including START and END - bool length_error = (data[8] != len); - if (length_error) { - ESP_LOGW(TAG, "Length field mismatch: byte[8]=0x%02X (%d), actual=%d", - data[8], data[8], len); - } - - // Validate header checksum: byte[9] = sum(bytes 0-8) & 0xFF - uint8_t expected_hchk = 0; - for (int i = 0; i < 9; i++) expected_hchk += data[i]; - bool header_chk_error = (expected_hchk != data[9]); - if (header_chk_error) { - ESP_LOGW(TAG, "Header checksum FAILED: expected 0x%02X, got 0x%02X", - expected_hchk, data[9]); - } - - // Validate data checksum - bool data_chk_error = !verify_message_checksum(data, len); - if (data_chk_error) { - uint32_t sum = 0; - for (int i = 10; i < len - 2; i++) sum += data[i]; - ESP_LOGW(TAG, "Data checksum FAILED: expected 0x%02X, got 0x%02X", - (uint8_t)(sum & 0xFF), data[len - 2]); - } - // Extract data payload section (bytes 10 to len-3) // Message format: [START=0][SRC=1-2][DST=3-4][CTRL=5-6][CMD=7][LEN=8][HDR_CHK=9][DATA=10...][DATA_CHK=len-2][END=len-1] const uint8_t *payload = &data[10]; @@ -2977,39 +2947,28 @@ bool decode_message(const uint8_t *data, int len, message_decoder_context_t *ctx bool decoded = dispatch_message(data, len, payload, payload_len, addr_info, ctx); - // Increment global and per-device counters. A frame with any validation - // error counts as an error only, so decoded + unknown + errors = total. + // Increment global and per-device counters. bool record_frame = false; - bool record_is_error = false; if (ctx->state_mutex) { if (xSemaphoreTake(ctx->state_mutex, pdMS_TO_TICKS(MUTEX_TIMEOUT_MS)) == pdTRUE) { - if (length_error || header_chk_error || data_chk_error) { - ctx->pool_state->messages_error_total++; - if (length_error) ctx->pool_state->errors_length_mismatch++; - if (header_chk_error) ctx->pool_state->errors_header_checksum++; - if (data_chk_error) ctx->pool_state->errors_data_checksum++; + if (decoded) ctx->pool_state->messages_decoded_total++; + else { + ctx->pool_state->messages_unknown_total++; record_frame = true; - record_is_error = true; - } else { - if (decoded) ctx->pool_state->messages_decoded_total++; - else { - ctx->pool_state->messages_unknown_total++; - record_frame = true; - } + } - // Per-device counters (skip broadcast) - if (!(src_hi == 0xFF && src_lo == 0xFF)) { - int idx = find_or_insert_seen_device_locked(ctx->pool_state, src_hi, src_lo); - if (idx >= 0) { - if (decoded) ctx->pool_state->seen_devices[idx].decoded_count++; - else ctx->pool_state->seen_devices[idx].unknown_count++; - } + // Per-device counters (skip broadcast) + if (!(src_hi == 0xFF && src_lo == 0xFF)) { + int idx = find_or_insert_seen_device_locked(ctx->pool_state, src_hi, src_lo); + if (idx >= 0) { + if (decoded) ctx->pool_state->seen_devices[idx].decoded_count++; + else ctx->pool_state->seen_devices[idx].unknown_count++; } } xSemaphoreGive(ctx->state_mutex); } } - if (record_frame) unknown_buffer_record(data, len, record_is_error); + if (record_frame) unknown_buffer_record(data, len, UNKNOWN_REASON_UNHANDLED); return decoded; } diff --git a/main/pool_state.h b/main/pool_state.h index 9d4b535..2944a6a 100644 --- a/main/pool_state.h +++ b/main/pool_state.h @@ -246,20 +246,19 @@ typedef struct { uint32_t messages_decoded_total; uint32_t messages_unknown_total; - // Protocol-level error counts. Framing errors (no_start/bad_control/no_end) - // are counted in the bridge reassembly layer and the bytes never reach the - // decoder. Validation errors (length/header_checksum/data_checksum) are - // counted in decode_message; the frame is still dispatched but counts as - // an error instead of decoded/unknown. messages_error_total increments - // once per error event (a frame with multiple validation errors counts once). - uint32_t messages_error_total; - uint32_t errors_no_start; // Bytes discarded: no START (0x02) in buffer - uint32_t errors_bad_control; // START found but control bytes != 80 00 - uint32_t errors_no_end; // No checksum+END match before buffer filled (too long / corrupt) - uint32_t errors_bad_framing; // Frame too short or missing START/END markers - uint32_t errors_length_mismatch; // Length field (byte 8) != actual frame length - uint32_t errors_header_checksum; // Header checksum (byte 9) mismatch - uint32_t errors_data_checksum; // Data checksum mismatch + // Frame resync events counted in the bridge reassembly layer. These are + // byte-level recovery events, not messages: the discarded bytes never reach + // the decoder, so they are tracked separately from messages_* above. A clean + // stutter typically costs one resync; sustained noise costs one per byte + // stepped. resyncs_total is the sum of the per-type counters below. + uint32_t resyncs_total; + uint32_t resyncs_no_start; // No START (0x02) in buffer; run discarded + uint32_t resyncs_bad_header_checksum; // Header checksum (byte 9) mismatch + uint32_t resyncs_bad_control; // Control bytes (5-6) != 80 00 + uint32_t resyncs_bad_length; // Length field (byte 8) out of range + uint32_t resyncs_bad_end; // End byte != 0x03 at declared length + uint32_t resyncs_bad_data_checksum; // Data checksum mismatch + uint32_t resyncs_buffer_overflow; // Buffer filled without a complete frame // Timers (up to MAX_TIMERS) timer_state_t timers[MAX_TIMERS]; diff --git a/main/tcp_bridge.c b/main/tcp_bridge.c index 41adad1..285ee36 100644 --- a/main/tcp_bridge.c +++ b/main/tcp_bridge.c @@ -1,4 +1,5 @@ #include "tcp_bridge.h" +#include "framing.h" #include "config.h" #include "esp_log.h" #include "freertos/FreeRTOS.h" @@ -14,6 +15,15 @@ static const char *TAG = "TCP_BRIDGE"; +// The buffer-overflow recovery path below re-adds the just-read chunk into a +// freshly reset framing buffer and ignores the return value, which is only +// safe because a single UART read can never itself exceed the framing +// buffer's capacity. Guard the assumption so a future config change can't +// silently break it. +_Static_assert(TCP_UART_BUFFER_SIZE <= BUS_MESSAGE_MAX_SIZE, + "TCP_UART_BUFFER_SIZE must not exceed BUS_MESSAGE_MAX_SIZE, or the " + "post-overflow re-add of a UART chunk in the bridge task can fail"); + // Loopback tracking for TX echo detection static uint8_t s_last_tx_msg[BUS_MESSAGE_MAX_SIZE]; static int s_last_tx_len = 0; @@ -26,8 +36,7 @@ static tcp_bridge_config_t s_config = {0}; static TaskHandle_t s_bridge_task_handle = NULL; // Message reassembly buffer -static uint8_t s_msg_buffer[BUS_MESSAGE_MAX_SIZE]; -static int s_msg_buffer_len = 0; +static framing_buffer_t s_framing_buffer; // Global client socket for log forwarding static int s_log_client_sock = -1; @@ -100,153 +109,6 @@ static void tcp_bridge_set_log_client(int sock) } } -/** - * Extract and process one complete message from the reassembly buffer. - * Uses message structure validation and checksum to detect message boundaries. - * Returns true if a message was found and processed. - */ -static bool extract_and_process_message(int client_sock) -{ - // Need at least minimum message: START + SRC + DST + CTRL + CMD(3) + CHK + END = 12 bytes - if (s_msg_buffer_len < 12) { - return false; - } - - // Find start byte (0x02) - int start_idx = -1; - for (int i = 0; i < s_msg_buffer_len; i++) { - if (s_msg_buffer[i] == 0x02) { - start_idx = i; - break; - } - } - - // No start byte found - discard everything - if (start_idx == -1) { - if (s_msg_buffer_len > 0) { - char hex_str[100]; - int hex_pos = 0; - int dump_len = MIN(s_msg_buffer_len, 32); - for (int i = 0; i < dump_len && hex_pos < (int)sizeof(hex_str) - 3; i++) { - hex_pos += snprintf(&hex_str[hex_pos], sizeof(hex_str) - hex_pos, "%02X ", s_msg_buffer[i]); - } - hex_str[hex_pos] = '\0'; - ESP_LOGW(TAG, "No start byte in buffer, discarding %d bytes: %s%s", - s_msg_buffer_len, hex_str, s_msg_buffer_len > 32 ? "..." : ""); - if (s_config.on_frame_error) s_config.on_frame_error(TCP_BRIDGE_FRAME_ERR_NO_START, s_msg_buffer, s_msg_buffer_len); - } - s_msg_buffer_len = 0; - return false; - } - - // Discard bytes before start - if (start_idx > 0) { - memmove(s_msg_buffer, &s_msg_buffer[start_idx], s_msg_buffer_len - start_idx); - s_msg_buffer_len -= start_idx; - } - - // Check we have enough for header validation - if (s_msg_buffer_len < 10) { - return false; // Wait for more data - } - - // Validate control bytes (positions 5-6 should be 0x80 0x00) - if (s_msg_buffer[5] != 0x80 || s_msg_buffer[6] != 0x00) { - char hex_str[100]; - int hex_pos = 0; - int dump_len = MIN(s_msg_buffer_len, 32); - for (int i = 0; i < dump_len && hex_pos < (int)sizeof(hex_str) - 3; i++) { - hex_pos += snprintf(&hex_str[hex_pos], sizeof(hex_str) - hex_pos, "%02X ", s_msg_buffer[i]); - } - hex_str[hex_pos] = '\0'; - ESP_LOGW(TAG, "Invalid control bytes: %02X %02X (expected 80 00), data: %s%s, discarding start byte", - s_msg_buffer[5], s_msg_buffer[6], hex_str, s_msg_buffer_len > 32 ? "..." : ""); - if (s_config.on_frame_error) s_config.on_frame_error(TCP_BRIDGE_FRAME_ERR_BAD_CONTROL, s_msg_buffer, s_msg_buffer_len); - // Discard this start byte and look for next - memmove(s_msg_buffer, &s_msg_buffer[1], s_msg_buffer_len - 1); - s_msg_buffer_len--; - return false; - } - - // Now scan for message end using checksum validation - // Data starts at index 10, checksum algorithm: sum(bytes 10..N-3) & 0xFF - for (int pos = 10; pos < s_msg_buffer_len - 2; pos++) { // Need at least 2 more bytes (checksum + END) - // Calculate checksum from byte 10 to current position (inclusive) - uint32_t sum = 0; - for (int i = 10; i <= pos; i++) { - sum += s_msg_buffer[i]; - } - uint8_t calculated_checksum = sum & 0xFF; - - // Check if next byte matches checksum AND byte after that is END marker (0x03) - // This prevents false positives from accidental checksum matches in payload - if (s_msg_buffer[pos + 1] == calculated_checksum && s_msg_buffer[pos + 2] == 0x03) { - // Found complete message! - int msg_len = pos + 3; // Include checksum and end byte - - // Format as hex string — reserve 3 bytes at end for \r\n\0 - char hexLine[3 * BUS_MESSAGE_MAX_SIZE + 3]; - int hex_pos = 0; - for (int i = 0; i < msg_len; i++) { - if (hex_pos < (int)(sizeof(hexLine) - 3)) { - hex_pos += snprintf(&hexLine[hex_pos], sizeof(hexLine) - hex_pos, - "%02X ", s_msg_buffer[i]); - } - } - hexLine[hex_pos] = '\0'; - - // Check for loopback - bool is_loopback = false; - if (s_last_tx_len > 0 && msg_len == s_last_tx_len) { - TickType_t time_since_tx = xTaskGetTickCount() - s_last_tx_time; - if (time_since_tx < pdMS_TO_TICKS(LOOPBACK_DETECTION_MS)) { - if (memcmp(s_msg_buffer, s_last_tx_msg, msg_len) == 0) { - is_loopback = true; - ESP_LOGI(TAG, "RX LOOPBACK (our TX echoed): %s", hexLine); - s_last_tx_len = 0; - } - } - } - - if (!is_loopback) { - s_config.decode_message(s_msg_buffer, msg_len); - } - - // Send to TCP client if connected - if (client_sock >= 0) { - hexLine[hex_pos] = '\r'; - hexLine[hex_pos + 1] = '\n'; - send_to_client(client_sock, hexLine, hex_pos + 2); - } - - // Remove processed message from buffer - int remaining = s_msg_buffer_len - msg_len; - if (remaining > 0) { - memmove(s_msg_buffer, &s_msg_buffer[msg_len], remaining); - } - s_msg_buffer_len = remaining; - - return true; // Message processed - } - } - - // No complete message yet - check for buffer overflow - if (s_msg_buffer_len >= BUS_MESSAGE_MAX_SIZE - 10) { - char hex_str[100]; - int hex_pos = 0; - int dump_len = 32; // Show first 32 bytes - for (int i = 0; i < dump_len && hex_pos < (int)sizeof(hex_str) - 3; i++) { - hex_pos += snprintf(&hex_str[hex_pos], sizeof(hex_str) - hex_pos, "%02X ", s_msg_buffer[i]); - } - hex_str[hex_pos] = '\0'; - ESP_LOGW(TAG, "Buffer nearly full (%d bytes) without complete message, first 32 bytes: %s..., clearing", - s_msg_buffer_len, hex_str); - if (s_config.on_frame_error) s_config.on_frame_error(TCP_BRIDGE_FRAME_ERR_NO_END, s_msg_buffer, s_msg_buffer_len); - s_msg_buffer_len = 0; - } - - return false; // Wait for more data -} /** * TCP server task implementation @@ -341,19 +203,78 @@ static void tcp_bridge_task(void *pvParameters) } // Append to reassembly buffer - if (s_msg_buffer_len + len <= BUS_MESSAGE_MAX_SIZE) { - memcpy(&s_msg_buffer[s_msg_buffer_len], uart_buf, len); - s_msg_buffer_len += len; - } else { + if (!framing_add_bytes(&s_framing_buffer, uart_buf, len)) { ESP_LOGW(TAG, "Reassembly buffer overflow (%d + %d > %d), clearing", - s_msg_buffer_len, len, BUS_MESSAGE_MAX_SIZE); - if (s_config.on_frame_error) s_config.on_frame_error(TCP_BRIDGE_FRAME_ERR_NO_END, s_msg_buffer, s_msg_buffer_len); - s_msg_buffer_len = 0; + s_framing_buffer.len, len, BUS_MESSAGE_MAX_SIZE); + // Hand the unparseable buffer contents to the resync callback + // (for unknown_buffer capture) before discarding them. + if (s_config.on_resync) { + s_config.on_resync(TCP_BRIDGE_RESYNC_BUFFER_OVERFLOW, + s_framing_buffer.buffer, s_framing_buffer.len); + } + framing_init(&s_framing_buffer); + framing_add_bytes(&s_framing_buffer, uart_buf, len); } // Extract and process all complete messages - while (extract_and_process_message(client_sock)) { - // Keep extracting until no more complete messages + uint8_t frame[BUS_MESSAGE_MAX_SIZE]; + int frame_len; + framing_result_t result; + while ((result = framing_process_next(&s_framing_buffer, frame, &frame_len)) != FRAMING_NEED_MORE_DATA) { + if (result == FRAMING_FRAME_READY) { + char hexLine[3 * BUS_MESSAGE_MAX_SIZE + 3]; + int hex_pos = 0; + for (int i = 0; i < frame_len; i++) { + if (hex_pos < (int)(sizeof(hexLine) - 3)) { + hex_pos += snprintf(&hexLine[hex_pos], sizeof(hexLine) - hex_pos, "%02X ", frame[i]); + } + } + hexLine[hex_pos] = '\0'; + + bool is_loopback = false; + if (s_last_tx_len > 0 && frame_len == s_last_tx_len) { + TickType_t time_since_tx = xTaskGetTickCount() - s_last_tx_time; + if (time_since_tx < pdMS_TO_TICKS(LOOPBACK_DETECTION_MS)) { + if (memcmp(frame, s_last_tx_msg, frame_len) == 0) { + is_loopback = true; + ESP_LOGI(TAG, "RX LOOPBACK (our TX echoed): %s", hexLine); + s_last_tx_len = 0; + } + } + } + + if (!is_loopback) { + s_config.decode_message(frame, frame_len); + } + + if (client_sock >= 0) { + hexLine[hex_pos] = '\r'; + hexLine[hex_pos + 1] = '\n'; + send_to_client(client_sock, hexLine, hex_pos + 2); + } + } else if (s_config.on_resync) { + // Map each framing failure to its own resync category so the + // status page can show a per-type breakdown. The framing layer + // hands back the bytes that triggered every resync (frame/ + // frame_len), so all types are capturable in the unknown buffer. + switch (result) { + case FRAMING_NO_START_BYTE: + s_config.on_resync(TCP_BRIDGE_RESYNC_NO_START, frame, frame_len); break; + case FRAMING_BAD_HEADER_CHECKSUM: + s_config.on_resync(TCP_BRIDGE_RESYNC_BAD_HEADER_CHECKSUM, frame, frame_len); break; + case FRAMING_BAD_CONTROL_BYTES: + s_config.on_resync(TCP_BRIDGE_RESYNC_BAD_CONTROL, frame, frame_len); break; + case FRAMING_BAD_LENGTH: + s_config.on_resync(TCP_BRIDGE_RESYNC_BAD_LENGTH, frame, frame_len); break; + case FRAMING_BAD_END_BYTE: + s_config.on_resync(TCP_BRIDGE_RESYNC_BAD_END, frame, frame_len); break; + case FRAMING_BAD_DATA_CHECKSUM: + s_config.on_resync(TCP_BRIDGE_RESYNC_BAD_DATA_CHECKSUM, frame, frame_len); break; + default: + // FRAMING_NEED_MORE_DATA / FRAMING_FRAME_READY handled above + break; + } + } } } @@ -496,6 +417,9 @@ esp_err_t tcp_bridge_start(const tcp_bridge_config_t *config) // Copy configuration memcpy(&s_config, config, sizeof(tcp_bridge_config_t)); + // Initialize framing buffer + framing_init(&s_framing_buffer); + // Create stop semaphore and reset flag s_stop_requested = false; s_stopped_sem = xSemaphoreCreateBinary(); diff --git a/main/tcp_bridge.h b/main/tcp_bridge.h index 3e2537e..f790e1b 100644 --- a/main/tcp_bridge.h +++ b/main/tcp_bridge.h @@ -24,16 +24,25 @@ typedef bool (*tcp_bridge_decode_fn)(const uint8_t *data, int len); // Called when RX or TX LED should flash typedef void (*tcp_bridge_led_flash_fn)(void); -// Framing errors detected by the reassembly layer (data is discarded) +// Resync events emitted by the reassembly layer. Each value maps 1:1 to a +// framing_result_t failure so the breakdown survives to the status page. +// NO_START and BUFFER_OVERFLOW discard a run of bytes; the BAD_* variants step +// the window forward by a single byte and retry. typedef enum { - TCP_BRIDGE_FRAME_ERR_NO_START, // No START byte (0x02) in buffer, all bytes discarded - TCP_BRIDGE_FRAME_ERR_BAD_CONTROL, // START found but control bytes != 80 00, resync by one byte - TCP_BRIDGE_FRAME_ERR_NO_END, // Buffer filled without a checksum+END match (too long / corrupt) -} tcp_bridge_frame_error_t; + TCP_BRIDGE_RESYNC_NO_START, // No START byte (0x02) in buffer, all bytes discarded + TCP_BRIDGE_RESYNC_BAD_HEADER_CHECKSUM, // Header checksum (byte 9) mismatch + TCP_BRIDGE_RESYNC_BAD_CONTROL, // Control bytes (5-6) != 80 00 + TCP_BRIDGE_RESYNC_BAD_LENGTH, // Length field (byte 8) out of range + TCP_BRIDGE_RESYNC_BAD_END, // End byte != 0x03 at declared length + TCP_BRIDGE_RESYNC_BAD_DATA_CHECKSUM, // Data checksum mismatch + TCP_BRIDGE_RESYNC_BUFFER_OVERFLOW, // Buffer filled without a complete frame (too long / corrupt) +} tcp_bridge_resync_type_t; -// Called when the reassembly layer discards data due to a framing error. -// data/len are the raw bytes being discarded (may be NULL/0 for overflow cases). -typedef void (*tcp_bridge_frame_error_fn)(tcp_bridge_frame_error_t error, const uint8_t *data, int len); +// Called when the reassembly layer resyncs (discards data) after a framing failure. +// data/len are the bytes that triggered the resync, passed for every result type +// (NO_START, BUFFER_OVERFLOW, and all BAD_* steps), so the caller can capture the +// lost frame for diagnostics. +typedef void (*tcp_bridge_resync_fn)(tcp_bridge_resync_type_t type, const uint8_t *data, int len); /** * Configuration structure for TCP bridge @@ -45,7 +54,7 @@ typedef struct { tcp_bridge_decode_fn decode_message; // Message decoder callback tcp_bridge_led_flash_fn led_flash_rx; // RX LED callback (can be NULL) tcp_bridge_led_flash_fn led_flash_tx; // TX LED callback (can be NULL) - tcp_bridge_frame_error_fn on_frame_error; // Framing error callback (can be NULL) + tcp_bridge_resync_fn on_resync; // Framing resync callback (can be NULL) } tcp_bridge_config_t; /** diff --git a/main/unknown_buffer.c b/main/unknown_buffer.c index f57a540..f332bc0 100644 --- a/main/unknown_buffer.c +++ b/main/unknown_buffer.c @@ -22,12 +22,12 @@ void unknown_buffer_init(void) // Otherwise, a new record is created, evicting the least frequently used record if the // buffer is full. // -// Note on matching: A match is defined as the same error status, the same length, and +// Note on matching: A match is defined as the same reason, the same length, and // the same first `UNKNOWN_BUFFER_MAX_RAW_BYTES` bytes. As we cap stored bytes to // `UNKNOWN_BUFFER_MAX_RAW_BYTES`, this means we can't distinguish between two different // frames that only differ in the bytes after `UNKNOWN_BUFFER_MAX_RAW_BYTES`. This is a // known limitation of this implementation. -void unknown_buffer_record(const uint8_t *data, int len, bool is_error) +void unknown_buffer_record(const uint8_t *data, int len, unknown_reason_t reason) { if (!s_mutex || !data || len <= 0) return; @@ -38,7 +38,7 @@ void unknown_buffer_record(const uint8_t *data, int len, bool is_error) if (xSemaphoreTake(s_mutex, pdMS_TO_TICKS(MUTEX_TIMEOUT_MS)) != pdTRUE) return; for (int i = 0; i < s_count; i++) { - if (s_entries[i].is_error == is_error && + if (s_entries[i].reason == reason && s_entries[i].raw_len == (uint16_t)len && memcmp(s_entries[i].raw, data, (size_t)store_len) == 0) { s_entries[i].hit_count++; @@ -69,11 +69,29 @@ void unknown_buffer_record(const uint8_t *data, int len, bool is_error) e->hit_count = 1; e->first_seen = now; e->last_seen = now; - e->is_error = is_error; + e->reason = reason; + e->is_error = (reason != UNKNOWN_REASON_UNHANDLED); xSemaphoreGive(s_mutex); } +const char *unknown_reason_str(unknown_reason_t reason) +{ + switch (reason) { + case UNKNOWN_REASON_UNHANDLED: return "unhandled"; + case UNKNOWN_REASON_NO_START: return "no start"; + case UNKNOWN_REASON_BUFFER_OVERFLOW: return "overflow"; + case UNKNOWN_REASON_BAD_FRAMING: return "bad framing"; + case UNKNOWN_REASON_HEADER_CHECKSUM: return "header checksum"; + case UNKNOWN_REASON_DATA_CHECKSUM: return "data checksum"; + case UNKNOWN_REASON_BAD_CONTROL: return "bad control"; + case UNKNOWN_REASON_BAD_LENGTH: return "bad length"; + case UNKNOWN_REASON_BAD_END: return "bad end"; + case UNKNOWN_REASON_UNEXPECTED: return "unexpected"; + default: return "error"; + } +} + void unknown_buffer_clear(void) { if (!s_mutex) return; diff --git a/main/unknown_buffer.h b/main/unknown_buffer.h index 1c87c3e..6185663 100644 --- a/main/unknown_buffer.h +++ b/main/unknown_buffer.h @@ -9,19 +9,40 @@ #define UNKNOWN_BUFFER_CAPACITY 100 #define UNKNOWN_BUFFER_MAX_RAW_BYTES 64 // store at most the first 64 bytes of each frame +// Why a frame was captured. UNHANDLED means a valid frame with no handler; +// the rest are framing/validation errors. The framing layer now records +// every resync type (including the per-byte BAD_* steps) so the offending +// bytes are visible on the Unknown Messages page. +typedef enum { + UNKNOWN_REASON_UNHANDLED = 0, // valid frame, no handler matched + UNKNOWN_REASON_NO_START, // framing: no START byte in buffer + UNKNOWN_REASON_BUFFER_OVERFLOW, // framing: buffer filled without a complete frame + UNKNOWN_REASON_BAD_FRAMING, // decoder: too short / missing START/END (guards test-decode) + UNKNOWN_REASON_HEADER_CHECKSUM, // framing: header checksum (byte 9) mismatch + UNKNOWN_REASON_DATA_CHECKSUM, // framing: data checksum mismatch + UNKNOWN_REASON_BAD_CONTROL, // framing: control bytes (5-6) != 80 00 + UNKNOWN_REASON_BAD_LENGTH, // framing: length field (byte 8) out of range + UNKNOWN_REASON_BAD_END, // framing: end byte != 0x03 at declared length + UNKNOWN_REASON_UNEXPECTED, // resync/result type not recognized by the mapper +} unknown_reason_t; + typedef struct { uint16_t raw_len; // actual frame length (may exceed UNKNOWN_BUFFER_MAX_RAW_BYTES) uint8_t raw[UNKNOWN_BUFFER_MAX_RAW_BYTES]; // first bytes of the frame uint32_t hit_count; time_t first_seen; // UTC epoch seconds (0 if NTP not synced) time_t last_seen; // UTC epoch seconds (0 if NTP not synced) - bool is_error; // true = framing/checksum error; false = no handler matched + unknown_reason_t reason; // why this frame was captured + bool is_error; // derived: reason != UNKNOWN_REASON_UNHANDLED } unknown_entry_t; void unknown_buffer_init(void); -// Record a frame. is_error=true for framing/checksum errors, false for unhandled frames. -void unknown_buffer_record(const uint8_t *data, int len, bool is_error); +// Record a frame, tagged with why it was captured (see unknown_reason_t). +void unknown_buffer_record(const uint8_t *data, int len, unknown_reason_t reason); + +// Short human-readable label for a reason (e.g. "no start", "header checksum"). +const char *unknown_reason_str(unknown_reason_t reason); void unknown_buffer_clear(void); diff --git a/main/web_handlers.c b/main/web_handlers.c index a4f10ea..ed387d6 100644 --- a/main/web_handlers.c +++ b/main/web_handlers.c @@ -266,12 +266,24 @@ static esp_err_t home_get_handler(httpd_req_t *req) "data.timers.forEach(t=>rows.push(['Timer '+t.num,t.start+' \u2013 '+t.stop+' ['+t.days+']']));}" "const mc=data.message_counts;" "if(mc){" - "const errs=mc.errors||0;" - "const tot=mc.decoded+mc.unknown+errs;" + "const tot=mc.decoded+mc.unknown;" "const pct=tot>0?(mc.decoded/tot*100).toFixed(1)+'%':'n/a';" "const mtr=document.createElement('tr');" - "mtr.innerHTML='Messages'+mc.decoded+' decoded, '+mc.unknown+' unknown, '+errs+' errors ('+pct+')';" + "mtr.innerHTML='Messages'+mc.decoded+' decoded, '+mc.unknown+' unknown ('+pct+')';" "document.getElementById('sys-body').appendChild(mtr);}" + "const rs=data.resyncs;" + "if(rs){" + "const parts=[];" + "if(rs.no_start)parts.push(rs.no_start+' no-start');" + "if(rs.header_checksum)parts.push(rs.header_checksum+' header-checksum');" + "if(rs.bad_control)parts.push(rs.bad_control+' bad-control');" + "if(rs.bad_length)parts.push(rs.bad_length+' bad-length');" + "if(rs.bad_end)parts.push(rs.bad_end+' bad-end');" + "if(rs.data_checksum)parts.push(rs.data_checksum+' data-checksum');" + "if(rs.buffer_overflow)parts.push(rs.buffer_overflow+' overflow');" + "const rtr=document.createElement('tr');" + "rtr.innerHTML='Resyncs'+(rs.total||0)+(parts.length?' ('+parts.join(', ')+')':'')+'';" + "document.getElementById('sys-body').appendChild(rtr);}" "const tb=document.getElementById('pool-body');" "rows.forEach(([k,v])=>{" "const tr=document.createElement('tr');" @@ -615,18 +627,20 @@ static esp_err_t status_get_handler(httpd_req_t *req) cJSON *msg_counts = cJSON_CreateObject(); cJSON_AddNumberToObject(msg_counts, "decoded", state.messages_decoded_total); cJSON_AddNumberToObject(msg_counts, "unknown", state.messages_unknown_total); - cJSON_AddNumberToObject(msg_counts, "errors", state.messages_error_total); - cJSON *err_detail = cJSON_CreateObject(); - cJSON_AddNumberToObject(err_detail, "no_start_byte", state.errors_no_start); - cJSON_AddNumberToObject(err_detail, "bad_control", state.errors_bad_control); - cJSON_AddNumberToObject(err_detail, "no_end", state.errors_no_end); - cJSON_AddNumberToObject(err_detail, "bad_framing", state.errors_bad_framing); - cJSON_AddNumberToObject(err_detail, "length_mismatch", state.errors_length_mismatch); - cJSON_AddNumberToObject(err_detail, "header_checksum", state.errors_header_checksum); - cJSON_AddNumberToObject(err_detail, "data_checksum", state.errors_data_checksum); - cJSON_AddItemToObject(msg_counts, "error_detail", err_detail); cJSON_AddItemToObject(root, "message_counts", msg_counts); + // Frame resync counters (bridge reassembly layer; see pool_state.h) + cJSON *resyncs = cJSON_CreateObject(); + cJSON_AddNumberToObject(resyncs, "total", state.resyncs_total); + cJSON_AddNumberToObject(resyncs, "no_start", state.resyncs_no_start); + cJSON_AddNumberToObject(resyncs, "header_checksum", state.resyncs_bad_header_checksum); + cJSON_AddNumberToObject(resyncs, "bad_control", state.resyncs_bad_control); + cJSON_AddNumberToObject(resyncs, "bad_length", state.resyncs_bad_length); + cJSON_AddNumberToObject(resyncs, "bad_end", state.resyncs_bad_end); + cJSON_AddNumberToObject(resyncs, "data_checksum", state.resyncs_bad_data_checksum); + cJSON_AddNumberToObject(resyncs, "buffer_overflow", state.resyncs_buffer_overflow); + cJSON_AddItemToObject(root, "resyncs", resyncs); + // Devices observed on the bus cJSON *devices = cJSON_CreateArray(); for (int i = 0; i < state.num_seen_devices; i++) { @@ -1648,6 +1662,7 @@ static esp_err_t unknown_msgs_json_handler(httpd_req_t *req) } cJSON_AddBoolToObject(obj, "is_error", e->is_error); + cJSON_AddStringToObject(obj, "reason", unknown_reason_str(e->reason)); cJSON_AddNumberToObject(obj, "raw_len", (double)e->raw_len); cJSON_AddNumberToObject(obj, "hits", (double)e->hit_count); cJSON_AddNumberToObject(obj, "first_seen", (double)e->first_seen); @@ -1725,9 +1740,9 @@ static esp_err_t unknown_msgs_view_handler(httpd_req_t *req) "return el;}" "function addCode(td,txt){" "const c=document.createElement('code');c.textContent=txt;td.appendChild(c);}" - "function addrTd(addr,name,isErr){" + "function addrTd(addr,name,errLabel){" "const td=mkEl('td');" - "if(isErr){const b=mkEl('small','error');b.style.cssText='background:#e55;color:#fff;border-radius:3px;padding:0 3px;margin-right:4px;font-size:.75em';td.appendChild(b);}" + "if(errLabel){const b=mkEl('small',errLabel);b.style.cssText='background:#e55;color:#fff;border-radius:3px;padding:0 4px;margin-right:4px;font-size:.75em';td.appendChild(b);}" "addCode(td,addr);" "if(name){td.appendChild(document.createElement('br'));td.appendChild(mkEl('small',name));}" "return td;}" @@ -1749,7 +1764,7 @@ static esp_err_t unknown_msgs_view_handler(httpd_req_t *req) "entries.forEach(e=>{" "const tr=document.createElement('tr');" "if(e.is_error)tr.style.background='var(--danger-faint,#fff0f0)';" - "tr.appendChild(addrTd(e.src,e.src_name,e.is_error));" + "tr.appendChild(addrTd(e.src,e.src_name,e.is_error?e.reason:null));" "tr.appendChild(addrTd(e.dst,e.dst_name));" "const cmdTd=mkEl('td');addCode(cmdTd,e.cmd);tr.appendChild(cmdTd);" "const payTd=mkEl('td');" diff --git a/test/frames/chunked_reassembly.txt b/test/frames/chunked_reassembly.txt new file mode 100644 index 0000000..2734a5f --- /dev/null +++ b/test/frames/chunked_reassembly.txt @@ -0,0 +1,27 @@ +# Chunked-input cases for the sliding-window parser. A '|' splits the line into +# separate framing_add_bytes() calls, drained after each - mirroring bytes +# arriving across multiple UART reads. These exercise reassembly and resync +# across read boundaries (issue #46 gaps 1 & 2), which the whole-line captures +# in observed_error_frames.txt / synthetic_errors.txt never hit. +# +# Known good frame: 02 00 A0 FF FF 80 00 3B 0E 69 04 65 69 03 +# (Viron XT Pump, CMD 0x3B, payload 04 65) + +# split mid-header, body completes in a later read +02 00 A0 FF FF 80 00 3B 0E | 69 04 65 69 03 + +# split exactly after the header checksum (byte 9), before length/body +02 00 A0 FF FF 80 00 3B 0E 69 | 04 65 69 03 + +# split one byte short of the declared length (waiting on the end byte) +02 00 A0 FF FF 80 00 3B 0E 69 04 65 69 | 03 + +# maximal fragmentation - one byte per read for a clean frame +02 | 00 | A0 | FF | FF | 80 | 00 | 3B | 0E | 69 | 04 | 65 | 69 | 03 + +# self-stutter prefix, resync straddles read boundaries, then good frame +02 00 A0 02 00 | A0 FF FF | 80 00 3B 0E 69 | 04 65 69 03 + +# bad data checksum (6A should be 69); checksum byte arrives split from +# the end byte, parser resyncs and recovers the trailing good frame +02 00 A0 FF FF 80 00 3B 0E 69 04 65 6A | 03 02 00 A0 FF FF 80 00 3B 0E 69 04 65 69 03 diff --git a/test/frames/chunked_reassembly_output.txt b/test/frames/chunked_reassembly_output.txt new file mode 100644 index 0000000..79ca31e --- /dev/null +++ b/test/frames/chunked_reassembly_output.txt @@ -0,0 +1,22 @@ +--- Case 1 --- +Decoded: Src=00A0 (Viron XT Pump), Dst=FFFF (Broadcast), Cmd=0x3B, Payload=0465 + +--- Case 2 --- +Decoded: Src=00A0 (Viron XT Pump), Dst=FFFF (Broadcast), Cmd=0x3B, Payload=0465 + +--- Case 3 --- +Decoded: Src=00A0 (Viron XT Pump), Dst=FFFF (Broadcast), Cmd=0x3B, Payload=0465 + +--- Case 4 --- +Decoded: Src=00A0 (Viron XT Pump), Dst=FFFF (Broadcast), Cmd=0x3B, Payload=0465 + +--- Case 5 --- +Resync: header_checksum +Discard: Discarding 2 byte(s) before next start byte: 00 A0 +Decoded: Src=00A0 (Viron XT Pump), Dst=FFFF (Broadcast), Cmd=0x3B, Payload=0465 + +--- Case 6 --- +Resync: data_checksum +Discard: Discarding 13 byte(s) before next start byte: 00 A0 FF FF 80 00 3B 0E 69 04 65 6A 03 +Decoded: Src=00A0 (Viron XT Pump), Dst=FFFF (Broadcast), Cmd=0x3B, Payload=0465 + diff --git a/test/frames/observed_error_frames.txt b/test/frames/observed_error_frames.txt new file mode 100644 index 0000000..93368d0 --- /dev/null +++ b/test/frames/observed_error_frames.txt @@ -0,0 +1,37 @@ +# These are real observed error frames +02 00 A0 FF FF 80 00 3B 02 00 A0 FF FF 80 00 3B 0E 69 04 65 69 03 02 00 50 FF FF 80 00 0A 0E E8 03 07 0A 03 02 00 50 FF FF 80 00 12 0E F0 01 00 01 03 02 00 50 FF FF 80 00 05 0D E2 00 00 03 02 +02 00 A0 FF FF 80 00 3B 0E 69 04 02 00 A0 FF FF 80 00 3B 0E 69 04 65 69 03 02 00 74 FF FF 80 00 12 10 16 00 02 00 00 02 03 02 00 50 FF FF 80 00 0A 0E E8 03 07 0A 03 02 00 50 FF FF 80 00 12 0E +02 00 A0 02 00 A0 FF FF 80 00 3B 0E 69 04 65 69 03 +02 00 A0 FF FF 80 00 3B 0E 69 02 00 A0 FF FF 80 00 3B 0E 69 02 00 A0 FF FF 80 02 00 74 FF FF 80 00 12 10 16 00 02 00 00 02 03 02 00 A0 FF FF 80 00 3B 0E 69 02 00 74 FF FF 80 00 16 0D 17 0D 0D +02 00 A0 FF FF 80 00 3B 0E 69 05 F5 FA 02 00 A0 FF FF 80 00 3B 0E 69 05 F5 FA 03 02 00 50 FF FF 80 00 0A 0E E8 03 07 0A 03 02 00 50 FF FF 80 00 12 0E F0 01 00 01 03 02 00 50 FF FF 80 00 05 0D +02 00 A0 FF FF 80 00 3B 0E 02 00 A0 FF FF 80 00 3B 0E 69 05 F5 FA 03 02 00 50 FF FF 80 00 0A 0E E8 03 07 0A 03 02 00 50 FF FF 80 00 12 0E F0 01 00 01 03 02 00 50 FF FF 80 00 05 0D E2 00 00 03 +02 00 A0 02 00 A0 FF FF 80 00 3B 0E 69 05 F5 FA 03 +02 00 A0 FF FF 80 00 3B 0E 69 02 00 A0 FF FF 80 00 3B 0E 69 05 F5 FA 03 02 00 50 FF FF 80 00 0A 0E E8 03 07 0A 03 02 00 50 FF FF 80 00 12 0E F0 01 00 01 03 02 00 50 FF FF 80 00 05 0D E2 00 00 +02 00 A0 FF FF 80 00 3B 0E 69 05 F5 02 00 A0 FF FF 80 00 3B 0E 69 05 F5 FA 03 02 00 50 FF FF 80 00 0A 0E E8 03 07 0A 03 02 00 50 FF FF 80 00 12 0E F0 01 00 01 03 02 00 50 FF FF 80 00 05 0D E2 +02 00 A0 FF FF 80 02 00 A0 FF FF 80 00 3B 0E 69 05 F5 FA 03 +02 00 A0 FF 02 00 A0 FF FF 80 00 3B 0E 69 05 F5 FA 03 +02 00 A0 FF FF 80 00 3B 02 00 A0 FF FF 80 00 3B 0E 69 05 F5 FA 03 02 00 50 FF FF 80 00 0A 0E E8 03 07 0A 03 02 00 50 FF FF 80 00 12 0E F0 01 00 01 03 02 00 50 FF FF 80 00 05 0D E2 00 00 03 02 +02 00 A0 FF FF 80 00 3B 0E 69 04 65 69 02 00 50 FF FF 80 00 0A 0E E8 03 07 0A 03 02 00 50 FF FF 80 00 12 0E F0 01 00 01 03 02 00 A0 FF FF 80 00 3B 0E 69 04 65 69 03 02 00 50 FF FF 80 00 05 0D +02 00 A0 02 00 50 FF FF 80 00 12 0E F0 01 00 01 03 +02 00 A0 FF FF 80 00 3B 0E 69 04 65 02 00 50 FF FF 80 00 14 0D F1 01 01 03 02 00 A0 FF 02 00 50 00 6F 80 00 0D 0D 5B 01 01 03 02 00 A0 FF FF 80 00 3B 0E 69 04 65 69 03 02 00 50 FF FF 80 00 0B +02 00 A0 FF FF 80 00 3B 0E 69 04 65 02 00 50 00 6F 80 00 0D 0D 5B 01 01 03 02 00 50 FF FF 80 00 0B 25 00 08 01 01 01 02 00 00 12 00 00 12 00 00 12 00 00 09 00 00 00 00 00 00 00 00 4C 03 02 00 +02 00 A0 FF FF 80 00 3B 0E 69 04 65 02 00 A0 FF FF 80 00 3B 0E 69 04 65 69 03 02 00 50 FF FF 80 00 38 0F 17 C0 01 00 C1 03 02 00 50 FF FF 80 00 38 0F 17 C1 01 00 C2 03 02 00 50 FF FF 80 00 38 +02 00 A0 02 00 50 FF FF 80 00 38 0F 17 C2 01 00 C3 03 +02 00 A0 FF FF 80 02 00 A0 FF FF 80 00 3B 0E 69 04 +02 00 A0 FF FF 80 00 3B 0E 69 04 02 00 50 FF FF 80 00 38 0F 17 C3 01 00 C4 03 02 00 50 FF FF 80 00 38 0F 17 D0 01 05 D6 03 02 00 A0 FF FF 80 00 3B 0E 69 04 65 69 03 02 00 50 FF FF 80 00 38 0F +02 00 A0 FF FF 80 00 3B 0E 69 02 00 A0 FF FF 80 00 3B 0E 69 04 65 69 03 02 00 50 FF FF 80 00 38 0F 17 D0 01 05 D6 03 02 00 50 FF FF 80 00 38 0F 17 D1 01 05 D7 03 02 00 50 FF FF 80 00 38 0F 17 +02 00 A0 FF FF 80 00 3B 0E 69 04 65 69 02 00 A0 FF FF 80 00 3B 0E 69 04 65 69 03 02 00 50 FF FF 80 00 38 0F 17 D2 01 05 D8 03 02 00 50 FF FF 80 00 38 0F 17 D3 01 05 D9 03 02 00 50 FF FF 80 00 +02 00 A0 FF FF 80 00 3B 0E 69 04 65 69 02 00 50 FF FF 80 00 38 0F 17 E2 01 00 E3 03 +02 00 A0 FF FF 80 00 3B 02 00 A0 FF FF 80 00 3B 0E 69 04 65 69 03 02 00 74 FF FF 80 00 12 10 16 00 02 00 00 02 03 02 00 74 FF FF 80 00 16 0D 17 0D 0D 03 02 00 74 FF FF 80 00 17 0E 19 0F 1B 2A +02 00 A0 FF FF 80 00 3B 0E 69 02 00 A0 FF FF 80 00 3B 0E 69 04 65 69 03 02 00 62 FF FF 80 00 0A 0E FA 02 05 07 03 02 00 62 FF FF 80 00 16 0E 06 00 00 00 03 02 00 62 FF FF 80 00 31 0E 21 B8 B8 +02 00 A0 FF FF 80 00 3B 0E 69 04 65 02 00 A0 FF FF 80 00 3B 0E 69 04 65 02 00 A0 FF FF 80 00 3B 0E 69 02 00 A0 FF FF 80 00 3B 0E 69 04 65 69 03 02 00 62 FF FF 80 00 0A 0E FA 02 05 07 03 02 00 +02 00 A0 FF FF 02 00 A0 FF FF 80 00 3B 0E 69 04 65 69 03 +02 00 00 FF 02 00 A0 FF FF 80 00 3B 0E 69 04 65 69 03 +02 02 00 62 FF FF 80 00 16 0E 06 00 00 00 03 +02 20 02 00 A0 FF FF 80 00 3B 0E 69 04 65 69 03 +02 20 02 00 62 00 50 80 00 2B 0E 6D 02 00 02 03 +02 00 00 FF 02 00 A0 FF FF 80 00 3B 0E 69 +02 00 A0 FF FF 80 00 3B 0E 69 02 00 62 00 50 80 00 2B 0E 6D 02 00 02 03 02 00 A0 FF FF 80 00 3B 0E 69 04 65 69 03 02 00 74 FF FF 80 00 12 10 16 00 02 00 00 02 03 02 00 74 FF FF 80 00 16 0D 17 +02 00 A0 FF FF 80 00 3B 0E 69 02 00 A0 FF FF 80 00 3B 0E 69 04 65 69 02 00 A0 FF FF 80 00 3B 0E 69 04 65 69 03 02 00 50 FF FF 80 00 38 0F 17 F0 01 FF F0 03 02 00 74 FF FF 80 00 12 10 16 00 02 +02 00 A0 02 00 A0 FF FF 02 00 A0 FF FF 80 00 3B 0E 69 04 65 69 03 +02 00 A0 FF FF 02 00 A0 FF FF 80 00 3B 0E 69 04 65 69 03 02 00 50 FF FF 80 00 38 1A 22 7C 02 46 69 6C 74 65 72 20 50 75 6D 70 00 A6 03 diff --git a/test/frames/observed_error_frames_output.txt b/test/frames/observed_error_frames_output.txt new file mode 100644 index 0000000..394f88c --- /dev/null +++ b/test/frames/observed_error_frames_output.txt @@ -0,0 +1,232 @@ +--- Case 1 --- +Resync: header_checksum +Discard: Discarding 7 byte(s) before next start byte: 00 A0 FF FF 80 00 3B +Decoded: Src=00A0 (Viron XT Pump), Dst=FFFF (Broadcast), Cmd=0x3B, Payload=0465 +Decoded: Src=0050 (Touch Screen), Dst=FFFF (Broadcast), Cmd=0x0A, Payload=0307 +Decoded: Src=0050 (Touch Screen), Dst=FFFF (Broadcast), Cmd=0x12, Payload=0100 +Decoded: Src=0050 (Touch Screen), Dst=FFFF (Broadcast), Cmd=0x05, Payload=00 + +--- Case 2 --- +Resync: bad_end +Discard: Discarding 10 byte(s) before next start byte: 00 A0 FF FF 80 00 3B 0E 69 04 +Decoded: Src=00A0 (Viron XT Pump), Dst=FFFF (Broadcast), Cmd=0x3B, Payload=0465 +Decoded: Src=0074 (ICI Gas Heater), Dst=FFFF (Broadcast), Cmd=0x12, Payload=00020000 +Decoded: Src=0050 (Touch Screen), Dst=FFFF (Broadcast), Cmd=0x0A, Payload=0307 + +--- Case 3 --- +Resync: header_checksum +Discard: Discarding 2 byte(s) before next start byte: 00 A0 +Decoded: Src=00A0 (Viron XT Pump), Dst=FFFF (Broadcast), Cmd=0x3B, Payload=0465 + +--- Case 4 --- +Resync: bad_end +Discard: Discarding 9 byte(s) before next start byte: 00 A0 FF FF 80 00 3B 0E 69 +Resync: bad_end +Discard: Discarding 9 byte(s) before next start byte: 00 A0 FF FF 80 00 3B 0E 69 +Resync: header_checksum +Discard: Discarding 5 byte(s) before next start byte: 00 A0 FF FF 80 +Decoded: Src=0074 (ICI Gas Heater), Dst=FFFF (Broadcast), Cmd=0x12, Payload=00020000 +Resync: bad_end +Discard: Discarding 9 byte(s) before next start byte: 00 A0 FF FF 80 00 3B 0E 69 + +--- Case 5 --- +Resync: bad_end +Discard: Discarding 12 byte(s) before next start byte: 00 A0 FF FF 80 00 3B 0E 69 05 F5 FA +Decoded: Src=00A0 (Viron XT Pump), Dst=FFFF (Broadcast), Cmd=0x3B, Payload=05F5 +Decoded: Src=0050 (Touch Screen), Dst=FFFF (Broadcast), Cmd=0x0A, Payload=0307 +Decoded: Src=0050 (Touch Screen), Dst=FFFF (Broadcast), Cmd=0x12, Payload=0100 + +--- Case 6 --- +Resync: header_checksum +Discard: Discarding 8 byte(s) before next start byte: 00 A0 FF FF 80 00 3B 0E +Decoded: Src=00A0 (Viron XT Pump), Dst=FFFF (Broadcast), Cmd=0x3B, Payload=05F5 +Decoded: Src=0050 (Touch Screen), Dst=FFFF (Broadcast), Cmd=0x0A, Payload=0307 +Decoded: Src=0050 (Touch Screen), Dst=FFFF (Broadcast), Cmd=0x12, Payload=0100 +Decoded: Src=0050 (Touch Screen), Dst=FFFF (Broadcast), Cmd=0x05, Payload=00 + +--- Case 7 --- +Resync: header_checksum +Discard: Discarding 2 byte(s) before next start byte: 00 A0 +Decoded: Src=00A0 (Viron XT Pump), Dst=FFFF (Broadcast), Cmd=0x3B, Payload=05F5 + +--- Case 8 --- +Resync: bad_end +Discard: Discarding 9 byte(s) before next start byte: 00 A0 FF FF 80 00 3B 0E 69 +Decoded: Src=00A0 (Viron XT Pump), Dst=FFFF (Broadcast), Cmd=0x3B, Payload=05F5 +Decoded: Src=0050 (Touch Screen), Dst=FFFF (Broadcast), Cmd=0x0A, Payload=0307 +Decoded: Src=0050 (Touch Screen), Dst=FFFF (Broadcast), Cmd=0x12, Payload=0100 + +--- Case 9 --- +Resync: bad_end +Discard: Discarding 11 byte(s) before next start byte: 00 A0 FF FF 80 00 3B 0E 69 05 F5 +Decoded: Src=00A0 (Viron XT Pump), Dst=FFFF (Broadcast), Cmd=0x3B, Payload=05F5 +Decoded: Src=0050 (Touch Screen), Dst=FFFF (Broadcast), Cmd=0x0A, Payload=0307 +Decoded: Src=0050 (Touch Screen), Dst=FFFF (Broadcast), Cmd=0x12, Payload=0100 + +--- Case 10 --- +Resync: header_checksum +Discard: Discarding 5 byte(s) before next start byte: 00 A0 FF FF 80 +Decoded: Src=00A0 (Viron XT Pump), Dst=FFFF (Broadcast), Cmd=0x3B, Payload=05F5 + +--- Case 11 --- +Resync: header_checksum +Discard: Discarding 3 byte(s) before next start byte: 00 A0 FF +Decoded: Src=00A0 (Viron XT Pump), Dst=FFFF (Broadcast), Cmd=0x3B, Payload=05F5 + +--- Case 12 --- +Resync: header_checksum +Discard: Discarding 7 byte(s) before next start byte: 00 A0 FF FF 80 00 3B +Decoded: Src=00A0 (Viron XT Pump), Dst=FFFF (Broadcast), Cmd=0x3B, Payload=05F5 +Decoded: Src=0050 (Touch Screen), Dst=FFFF (Broadcast), Cmd=0x0A, Payload=0307 +Decoded: Src=0050 (Touch Screen), Dst=FFFF (Broadcast), Cmd=0x12, Payload=0100 +Decoded: Src=0050 (Touch Screen), Dst=FFFF (Broadcast), Cmd=0x05, Payload=00 + +--- Case 13 --- +Resync: bad_end +Discard: Discarding 12 byte(s) before next start byte: 00 A0 FF FF 80 00 3B 0E 69 04 65 69 +Decoded: Src=0050 (Touch Screen), Dst=FFFF (Broadcast), Cmd=0x0A, Payload=0307 +Decoded: Src=0050 (Touch Screen), Dst=FFFF (Broadcast), Cmd=0x12, Payload=0100 +Decoded: Src=00A0 (Viron XT Pump), Dst=FFFF (Broadcast), Cmd=0x3B, Payload=0465 + +--- Case 14 --- +Resync: header_checksum +Discard: Discarding 2 byte(s) before next start byte: 00 A0 +Decoded: Src=0050 (Touch Screen), Dst=FFFF (Broadcast), Cmd=0x12, Payload=0100 + +--- Case 15 --- +Resync: bad_end +Discard: Discarding 11 byte(s) before next start byte: 00 A0 FF FF 80 00 3B 0E 69 04 65 +Decoded: Src=0050 (Touch Screen), Dst=FFFF (Broadcast), Cmd=0x14, Payload=01 +Resync: header_checksum +Discard: Discarding 3 byte(s) before next start byte: 00 A0 FF +Decoded: Src=0050 (Touch Screen), Dst=006F (Internal Channels), Cmd=0x0D, Payload=01 +Decoded: Src=00A0 (Viron XT Pump), Dst=FFFF (Broadcast), Cmd=0x3B, Payload=0465 + +--- Case 16 --- +Resync: bad_end +Discard: Discarding 11 byte(s) before next start byte: 00 A0 FF FF 80 00 3B 0E 69 04 65 +Decoded: Src=0050 (Touch Screen), Dst=006F (Internal Channels), Cmd=0x0D, Payload=01 +Decoded: Src=0050 (Touch Screen), Dst=FFFF (Broadcast), Cmd=0x0B, Payload=08010101020000120000120000120000090000000000000000 + +--- Case 17 --- +Resync: bad_end +Discard: Discarding 11 byte(s) before next start byte: 00 A0 FF FF 80 00 3B 0E 69 04 65 +Decoded: Src=00A0 (Viron XT Pump), Dst=FFFF (Broadcast), Cmd=0x3B, Payload=0465 +Decoded: Src=0050 (Touch Screen), Dst=FFFF (Broadcast), Cmd=0x38, Payload=C00100 +Decoded: Src=0050 (Touch Screen), Dst=FFFF (Broadcast), Cmd=0x38, Payload=C10100 + +--- Case 18 --- +Resync: header_checksum +Discard: Discarding 2 byte(s) before next start byte: 00 A0 +Decoded: Src=0050 (Touch Screen), Dst=FFFF (Broadcast), Cmd=0x38, Payload=C20100 + +--- Case 19 --- +Resync: header_checksum +Discard: Discarding 5 byte(s) before next start byte: 00 A0 FF FF 80 + +--- Case 20 --- +Resync: bad_end +Discard: Discarding 10 byte(s) before next start byte: 00 A0 FF FF 80 00 3B 0E 69 04 +Decoded: Src=0050 (Touch Screen), Dst=FFFF (Broadcast), Cmd=0x38, Payload=C30100 +Decoded: Src=0050 (Touch Screen), Dst=FFFF (Broadcast), Cmd=0x38, Payload=D00105 +Decoded: Src=00A0 (Viron XT Pump), Dst=FFFF (Broadcast), Cmd=0x3B, Payload=0465 + +--- Case 21 --- +Resync: bad_end +Discard: Discarding 9 byte(s) before next start byte: 00 A0 FF FF 80 00 3B 0E 69 +Decoded: Src=00A0 (Viron XT Pump), Dst=FFFF (Broadcast), Cmd=0x3B, Payload=0465 +Decoded: Src=0050 (Touch Screen), Dst=FFFF (Broadcast), Cmd=0x38, Payload=D00105 +Decoded: Src=0050 (Touch Screen), Dst=FFFF (Broadcast), Cmd=0x38, Payload=D10105 + +--- Case 22 --- +Resync: bad_end +Discard: Discarding 12 byte(s) before next start byte: 00 A0 FF FF 80 00 3B 0E 69 04 65 69 +Decoded: Src=00A0 (Viron XT Pump), Dst=FFFF (Broadcast), Cmd=0x3B, Payload=0465 +Decoded: Src=0050 (Touch Screen), Dst=FFFF (Broadcast), Cmd=0x38, Payload=D20105 +Decoded: Src=0050 (Touch Screen), Dst=FFFF (Broadcast), Cmd=0x38, Payload=D30105 + +--- Case 23 --- +Resync: bad_end +Discard: Discarding 12 byte(s) before next start byte: 00 A0 FF FF 80 00 3B 0E 69 04 65 69 +Decoded: Src=0050 (Touch Screen), Dst=FFFF (Broadcast), Cmd=0x38, Payload=E20100 + +--- Case 24 --- +Resync: header_checksum +Discard: Discarding 7 byte(s) before next start byte: 00 A0 FF FF 80 00 3B +Decoded: Src=00A0 (Viron XT Pump), Dst=FFFF (Broadcast), Cmd=0x3B, Payload=0465 +Decoded: Src=0074 (ICI Gas Heater), Dst=FFFF (Broadcast), Cmd=0x12, Payload=00020000 +Decoded: Src=0074 (ICI Gas Heater), Dst=FFFF (Broadcast), Cmd=0x16, Payload=0D + +--- Case 25 --- +Resync: bad_end +Discard: Discarding 9 byte(s) before next start byte: 00 A0 FF FF 80 00 3B 0E 69 +Decoded: Src=00A0 (Viron XT Pump), Dst=FFFF (Broadcast), Cmd=0x3B, Payload=0465 +Decoded: Src=0062 (Connect 8/10), Dst=FFFF (Broadcast), Cmd=0x0A, Payload=0205 +Decoded: Src=0062 (Connect 8/10), Dst=FFFF (Broadcast), Cmd=0x16, Payload=0000 + +--- Case 26 --- +Resync: bad_end +Discard: Discarding 11 byte(s) before next start byte: 00 A0 FF FF 80 00 3B 0E 69 04 65 +Resync: bad_end +Discard: Discarding 11 byte(s) before next start byte: 00 A0 FF FF 80 00 3B 0E 69 04 65 +Resync: bad_end +Discard: Discarding 9 byte(s) before next start byte: 00 A0 FF FF 80 00 3B 0E 69 +Decoded: Src=00A0 (Viron XT Pump), Dst=FFFF (Broadcast), Cmd=0x3B, Payload=0465 +Decoded: Src=0062 (Connect 8/10), Dst=FFFF (Broadcast), Cmd=0x0A, Payload=0205 + +--- Case 27 --- +Resync: header_checksum +Discard: Discarding 4 byte(s) before next start byte: 00 A0 FF FF +Decoded: Src=00A0 (Viron XT Pump), Dst=FFFF (Broadcast), Cmd=0x3B, Payload=0465 + +--- Case 28 --- +Resync: header_checksum +Discard: Discarding 3 byte(s) before next start byte: 00 00 FF +Decoded: Src=00A0 (Viron XT Pump), Dst=FFFF (Broadcast), Cmd=0x3B, Payload=0465 + +--- Case 29 --- +Resync: header_checksum +Decoded: Src=0062 (Connect 8/10), Dst=FFFF (Broadcast), Cmd=0x16, Payload=0000 + +--- Case 30 --- +Resync: header_checksum +Discard: Discarding 1 byte(s) before next start byte: 20 +Decoded: Src=00A0 (Viron XT Pump), Dst=FFFF (Broadcast), Cmd=0x3B, Payload=0465 + +--- Case 31 --- +Resync: header_checksum +Discard: Discarding 1 byte(s) before next start byte: 20 +Decoded: Src=0062 (Connect 8/10), Dst=0050 (Touch Screen), Cmd=0x2B, Payload=0200 + +--- Case 32 --- +Resync: header_checksum +Discard: Discarding 3 byte(s) before next start byte: 00 00 FF + +--- Case 33 --- +Resync: bad_end +Discard: Discarding 9 byte(s) before next start byte: 00 A0 FF FF 80 00 3B 0E 69 +Decoded: Src=0062 (Connect 8/10), Dst=0050 (Touch Screen), Cmd=0x2B, Payload=0200 +Decoded: Src=00A0 (Viron XT Pump), Dst=FFFF (Broadcast), Cmd=0x3B, Payload=0465 +Decoded: Src=0074 (ICI Gas Heater), Dst=FFFF (Broadcast), Cmd=0x12, Payload=00020000 + +--- Case 34 --- +Resync: bad_end +Discard: Discarding 9 byte(s) before next start byte: 00 A0 FF FF 80 00 3B 0E 69 +Resync: bad_end +Discard: Discarding 12 byte(s) before next start byte: 00 A0 FF FF 80 00 3B 0E 69 04 65 69 +Decoded: Src=00A0 (Viron XT Pump), Dst=FFFF (Broadcast), Cmd=0x3B, Payload=0465 +Decoded: Src=0050 (Touch Screen), Dst=FFFF (Broadcast), Cmd=0x38, Payload=F001FF + +--- Case 35 --- +Resync: header_checksum +Discard: Discarding 2 byte(s) before next start byte: 00 A0 +Resync: header_checksum +Discard: Discarding 4 byte(s) before next start byte: 00 A0 FF FF +Decoded: Src=00A0 (Viron XT Pump), Dst=FFFF (Broadcast), Cmd=0x3B, Payload=0465 + +--- Case 36 --- +Resync: header_checksum +Discard: Discarding 4 byte(s) before next start byte: 00 A0 FF FF +Decoded: Src=00A0 (Viron XT Pump), Dst=FFFF (Broadcast), Cmd=0x3B, Payload=0465 +Decoded: Src=0050 (Touch Screen), Dst=FFFF (Broadcast), Cmd=0x38, Payload=7C0246696C7465722050756D7000 + diff --git a/test/frames/synthetic_errors.txt b/test/frames/synthetic_errors.txt new file mode 100644 index 0000000..4af9c52 --- /dev/null +++ b/test/frames/synthetic_errors.txt @@ -0,0 +1,28 @@ +# Synthetic single-failure-mode frames for the sliding-window parser. +# +# Unlike observed_error_frames.txt (real bus captures, each case here isolates +# exactly one framing_result_t failure. Frames are hand-built with a valid header +# checksum so the parser reaches the intended check, then — except no_start — +# followed by a known-good frame to prove the parser resyncs and recovers. +# +# Known good frame: 02 00 A0 FF FF 80 00 3B 0E 69 04 65 69 03 +# (Viron XT Pump, CMD 0x3B, payload 04 65) + +# no_start: 12 bytes with no START (0x02) anywhere -> whole buffer discarded +FF FF FF FF FF FF FF FF FF FF FF FF + +# header_checksum: stuttered pump prefix so the next 0x02 lands where byte 9 +# (header checksum) is read; sum(bytes 0-8) != byte 9 +02 00 A0 02 00 A0 FF FF 80 00 3B 0E 69 04 65 69 03 + +# bad_control: valid header checksum (0xBA) but control bytes (5-6) = 12 34 +02 00 50 FF FF 12 34 16 0E BA 02 00 A0 FF FF 80 00 3B 0E 69 04 65 69 03 + +# bad_length: valid header checksum (0xEB) but length field (byte 8) = 0x05 (< 12) +02 00 50 FF FF 80 00 16 05 EB 02 00 A0 FF FF 80 00 3B 0E 69 04 65 69 03 + +# bad_end: valid header, length 0x0E, but byte 13 is the next frame's 0x02, not 0x03 +02 00 A0 FF FF 80 00 3B 0E 69 05 F5 FA 02 00 A0 FF FF 80 00 3B 0E 69 04 65 69 03 + +# data_checksum: valid header and correct end byte, but data checksum = 0x6A (should be 0x69) +02 00 A0 FF FF 80 00 3B 0E 69 04 65 6A 03 02 00 A0 FF FF 80 00 3B 0E 69 04 65 69 03 diff --git a/test/frames/synthetic_errors_output.txt b/test/frames/synthetic_errors_output.txt new file mode 100644 index 0000000..196960d --- /dev/null +++ b/test/frames/synthetic_errors_output.txt @@ -0,0 +1,28 @@ +--- Case 1 --- +Resync: no_start + +--- Case 2 --- +Resync: header_checksum +Discard: Discarding 2 byte(s) before next start byte: 00 A0 +Decoded: Src=00A0 (Viron XT Pump), Dst=FFFF (Broadcast), Cmd=0x3B, Payload=0465 + +--- Case 3 --- +Resync: bad_control +Discard: Discarding 9 byte(s) before next start byte: 00 50 FF FF 12 34 16 0E BA +Decoded: Src=00A0 (Viron XT Pump), Dst=FFFF (Broadcast), Cmd=0x3B, Payload=0465 + +--- Case 4 --- +Resync: bad_length +Discard: Discarding 9 byte(s) before next start byte: 00 50 FF FF 80 00 16 05 EB +Decoded: Src=00A0 (Viron XT Pump), Dst=FFFF (Broadcast), Cmd=0x3B, Payload=0465 + +--- Case 5 --- +Resync: bad_end +Discard: Discarding 12 byte(s) before next start byte: 00 A0 FF FF 80 00 3B 0E 69 05 F5 FA +Decoded: Src=00A0 (Viron XT Pump), Dst=FFFF (Broadcast), Cmd=0x3B, Payload=0465 + +--- Case 6 --- +Resync: data_checksum +Discard: Discarding 13 byte(s) before next start byte: 00 A0 FF FF 80 00 3B 0E 69 04 65 6A 03 +Decoded: Src=00A0 (Viron XT Pump), Dst=FFFF (Broadcast), Cmd=0x3B, Payload=0465 + diff --git a/test/run_tests.sh b/test/run_tests.sh index 051ec16..5155c5b 100755 --- a/test/run_tests.sh +++ b/test/run_tests.sh @@ -30,7 +30,7 @@ is_skipped() { } for test_src in test_*.c; do - if [ "$test_src" = "test_replay.c" ]; then + if [ "$test_src" = "test_replay.c" ] || [ "$test_src" = "test_framing.c" ]; then continue fi if is_skipped "$test_src"; then @@ -61,6 +61,26 @@ for test_src in test_*.c; do fi done +# Run framing tests. +if [ -f test_framing.c ]; then + echo "========================================" + echo " Compiling: test_framing.c" + echo "========================================" + + if gcc -I. -I.. -o ./run_framing test_framing.c "${SHARED[@]}" 2>&1; then + if ./run_framing; then + PASS=$((PASS + 1)) + else + FAIL=$((FAIL + 1)) + ERRORS+=("test_framing.c (framing failures)") + fi + rm -f ./run_framing + else + FAIL=$((FAIL + 1)) + ERRORS+=("test_framing.c (compile error)") + fi +fi + # Replay sample logs through the real decoder. if [ -f test_replay.c ]; then echo "========================================" diff --git a/test/test_framing.c b/test/test_framing.c new file mode 100644 index 0000000..065d1a4 --- /dev/null +++ b/test/test_framing.c @@ -0,0 +1,467 @@ +#include +#include +#include +#include +#include + +#include "esp_err.h" +#include "esp_log.h" +#include "log_capture.h" + +// Include framing module directly for testing +#include "../main/framing.h" +#include "../main/framing.c" + +// Helper to trim trailing whitespace/newlines +static void trim_trailing(char *s) { + size_t l = strlen(s); + while (l > 0 && (s[l-1] == ' ' || s[l-1] == '\t' || s[l-1] == '\r' || s[l-1] == '\n')) { + s[--l] = '\0'; + } +} + +// Helper to convert single hex char to nibble +static int hex_char_to_val(char c) { + if (c >= '0' && c <= '9') return c - '0'; + if (c >= 'A' && c <= 'F') return c - 'A' + 10; + if (c >= 'a' && c <= 'f') return c - 'a' + 10; + return -1; +} + +// Helper to parse hex string into byte array +static int parse_hex_to_bytes(const char *hex, uint8_t *dest) { + int len = 0; + const char *p = hex; + while (*p) { + while (*p == ' ' || *p == '\t' || *p == '\r' || *p == '\n') p++; + if (!*p) break; + int hi = hex_char_to_val(*p++); + if (hi < 0 || !*p) break; + int lo = hex_char_to_val(*p++); + if (lo < 0) break; + dest[len++] = (hi << 4) | lo; + } + return len; +} + +// Device name mapping matching python scripts +static const char* get_test_device_name(uint16_t addr) { + if (addr == 0x0050) return "Touch Screen"; + if (addr == 0x0062) return "Connect 8/10"; + if (addr == 0x0074) return "ICI Gas Heater"; + if (addr == 0x00A0) return "Viron XT Pump"; + if (addr == 0xFFFF) return "Broadcast"; + if (addr == 0x006F) return "Internal Channels"; + return "Unknown"; +} + +// Resync type name — must match the resync category keys surfaced elsewhere +// (pool_state resyncs_* fields and the /status JSON). +static const char* resync_name(framing_result_t r) { + switch (r) { + case FRAMING_NO_START_BYTE: return "no_start"; + case FRAMING_BAD_HEADER_CHECKSUM: return "header_checksum"; + case FRAMING_BAD_CONTROL_BYTES: return "bad_control"; + case FRAMING_BAD_LENGTH: return "bad_length"; + case FRAMING_BAD_END_BYTE: return "bad_end"; + case FRAMING_BAD_DATA_CHECKSUM: return "data_checksum"; + default: return "?"; + } +} + +static char actual_out[8192]; +static int actual_len = 0; + +// Drain every frame/resync currently available in `fb`, appending the ordered +// "Discard:/Resync:/Decoded:" lines to actual_out. *log_pos tracks how far the +// log-capture buffer has been consumed so a multi-byte "Discarding ..." log +// line (which is logged but not reflected in `result`) is surfaced exactly +// once, even when draining is spread across several chunks. Stops when the +// parser returns NEED_MORE_DATA. +static void drain_and_record(framing_buffer_t *fb, size_t *log_pos) { + uint8_t frame[BUS_MESSAGE_MAX_SIZE]; + int frame_len; + framing_result_t result; + for (;;) { + result = framing_process_next(fb, frame, &frame_len); + + // A single call can silently discard bytes before resyncing onto a + // later start byte (logged but not reflected in `result`) - surface + // that log line so the golden file can assert on it. This happens + // even on a call that ultimately returns NEED_MORE_DATA, since the + // discard happens before that check. + char *discard = strstr(log_capture_buf + *log_pos, "Discarding "); + if (discard) { + char *line_end = strchr(discard, '\n'); + int line_len = line_end ? (int)(line_end - discard) : (int)strlen(discard); + // Trim trailing whitespace to match what trim_trailing() does + // to the golden file's copy of this line when read back. + while (line_len > 0 && (discard[line_len - 1] == ' ' || discard[line_len - 1] == '\t')) { + line_len--; + } + int n = snprintf(actual_out + actual_len, sizeof(actual_out) - actual_len, + "Discard: %.*s\n", line_len, discard); + if (n > 0) actual_len += n; + } + *log_pos = log_capture_len; + + if (result == FRAMING_NEED_MORE_DATA) { + break; + } + if (result != FRAMING_FRAME_READY) { + int n = snprintf(actual_out + actual_len, sizeof(actual_out) - actual_len, + "Resync: %s\n", resync_name(result)); + if (n > 0) actual_len += n; + continue; + } + uint16_t src = (frame[1] << 8) | frame[2]; + uint16_t dst = (frame[3] << 8) | frame[4]; + uint8_t cmd = frame[7]; + + char payload_str[1024] = ""; + int payload_len = frame_len - 12; + for (int i = 0; i < payload_len; i++) { + sprintf(payload_str + i * 2, "%02X", frame[10 + i]); + } + + int n = snprintf(actual_out + actual_len, sizeof(actual_out) - actual_len, + "Decoded: Src=%04X (%s), Dst=%04X (%s), Cmd=0x%02X, Payload=%s\n", + src, get_test_device_name(src), + dst, get_test_device_name(dst), + cmd, payload_str); + if (n > 0) actual_len += n; + } +} + +// Run one hex/golden file pair. Each non-blank, non-comment line of the hex +// file is one case: its bytes are fed to the parser and the ordered stream of +// resync events ("Resync: ") and decoded frames ("Decoded: ...") is +// compared against the matching "--- Case N ---" block in the golden file. +static int run_file(const char *hex_file_path, const char *gold_file_path, + bool bless, int *passed, int *failed) { + FILE *f_hex = fopen(hex_file_path, "r"); + if (!f_hex) { + fprintf(stderr, "ERROR: Cannot open %s\n", hex_file_path); + return 1; + } + + // Compare mode reads the golden; bless mode rewrites it from the current + // parser output via a temp file + rename (mirrors run_replay --bless). + char gold_tmp_path[4096]; + FILE *f_gold = NULL; + if (bless) { + snprintf(gold_tmp_path, sizeof(gold_tmp_path), "%s.bless.tmp", gold_file_path); + f_gold = fopen(gold_tmp_path, "w"); + } else { + f_gold = fopen(gold_file_path, "r"); + } + if (!f_gold) { + fprintf(stderr, "ERROR: Cannot open %s\n", bless ? gold_tmp_path : gold_file_path); + fclose(f_hex); + return 1; + } + + char hex_line[4096]; + char gold_line[1024]; + int case_num = 1; + int file_line = 0; // 1-based source line in the hex file, for failure locating + framing_buffer_t fb; + + printf("Checking %s ...\n", hex_file_path); + + while (fgets(hex_line, sizeof(hex_line), f_hex)) { + file_line++; + trim_trailing(hex_line); + if (hex_line[0] == '\0' || hex_line[0] == '#') { + continue; // skip blank lines and comments + } + + // Compare mode: read this case's expected block from the golden. + char expected_out[4096] = ""; + if (!bless) { + char expected_hdr[128]; + sprintf(expected_hdr, "--- Case %d ---", case_num); + + if (!fgets(gold_line, sizeof(gold_line), f_gold)) { + fprintf(stderr, "ERROR: Unexpected EOF in %s when looking for Case %d header\n", gold_file_path, case_num); + (*failed)++; + break; + } + trim_trailing(gold_line); + if (strcmp(gold_line, expected_hdr) != 0) { + fprintf(stderr, "ERROR: Expected golden header '%s', got '%s'\n", expected_hdr, gold_line); + (*failed)++; + break; + } + + // Read all expected outputs until a blank line or EOF + int expected_len = 0; + while (fgets(gold_line, sizeof(gold_line), f_gold)) { + trim_trailing(gold_line); + if (gold_line[0] == '\0') { + break; // Blank line signals end of case + } + int n = snprintf(expected_out + expected_len, sizeof(expected_out) - expected_len, "%s\n", gold_line); + if (n > 0) { + expected_len += n; + } + } + } + + // Prepare parser state and capture buffers + framing_init(&fb); + actual_len = 0; + actual_out[0] = '\0'; + log_capture_reset(); + size_t log_pos = log_capture_len; + + // Feed the case into the parser. A '|' in the line splits it into + // separate framing_add_bytes() calls, draining after each - this + // mirrors the bridge's "append per UART read, then drain" loop and + // exercises reassembly/resync across read boundaries. A line with no + // '|' is a single chunk, identical to the original whole-line behaviour. + bool add_failed = false; + char *saveptr = NULL; + for (char *seg = strtok_r(hex_line, "|", &saveptr); + seg != NULL; + seg = strtok_r(NULL, "|", &saveptr)) { + uint8_t tmp_buf[1024]; + int parsed_bytes = parse_hex_to_bytes(seg, tmp_buf); + if (parsed_bytes <= 0) { + continue; // empty/whitespace-only chunk + } + if (!framing_add_bytes(&fb, tmp_buf, parsed_bytes)) { + fprintf(stderr, "ERROR: Failed to add bytes to framing buffer (too long)\n"); + add_failed = true; + break; + } + // Drain everything available so far, recording resync events and + // decoded frames in the order they occur. + drain_and_record(&fb, &log_pos); + } + if (add_failed) { + (*failed)++; + case_num++; + continue; + } + + if (bless) { + // Rewrite this case from the current parser output. + fprintf(f_gold, "--- Case %d ---\n%s\n", case_num, actual_out); + (*passed)++; + } else if (strcmp(actual_out, expected_out) == 0) { + (*passed)++; + } else { + (*failed)++; + printf("FAIL: %s:%d (Case %d)\n", hex_file_path, file_line, case_num); + printf(" Input hex: %s\n", hex_line); + printf(" Expected:\n%s", expected_out); + printf(" Actual:\n%s", actual_out); + printf(" Warnings/Resync Logs:\n"); + if (log_capture_len == 0) { + printf(" (None)\n"); + } else { + printf("%s", log_capture_buf); + } + printf("==================================================\n\n"); + } + + case_num++; + } + + fclose(f_hex); + fclose(f_gold); + + if (bless) { + if (rename(gold_tmp_path, gold_file_path) != 0) { + perror("rename"); + (*failed)++; + } else { + printf(" blessed: %s (%d case%s)\n", + gold_file_path, case_num - 1, (case_num - 1) == 1 ? "" : "s"); + } + } + return case_num - 1; +} + +// Direct assertion for the overflow guard, which framing_process_next never +// reports (the bridge layer raises it when framing_add_bytes rejects a push). +static bool run_overflow_test(int *passed, int *failed) { + framing_buffer_t fb; + uint8_t big[BUS_MESSAGE_MAX_SIZE + 1]; + memset(big, 0xFF, sizeof(big)); + + framing_init(&fb); + bool reject_oversized = !framing_add_bytes(&fb, big, BUS_MESSAGE_MAX_SIZE + 1); + + framing_init(&fb); + bool accept_exact = framing_add_bytes(&fb, big, BUS_MESSAGE_MAX_SIZE); + bool reject_one_more = !framing_add_bytes(&fb, big, 1); + + bool ok = reject_oversized && accept_exact && reject_one_more; + printf("Checking framing_add_bytes overflow guard ...\n"); + printf(" oversized push rejected=%d, exact-fill accepted=%d, +1 rejected=%d -> %s\n", + reject_oversized, accept_exact, reject_one_more, ok ? "PASS" : "FAIL"); + if (ok) (*passed)++; else (*failed)++; + return ok; +} + +// Feed `n` bytes through a fresh parser, split into chunks at the given sorted +// byte offsets (draining after each chunk), and write only the ordered +// "Decoded:" lines to `out`. num_splits==0 means feed everything in one shot. +// Used by the chunk-invariance property test below. +static void decoded_lines_chunked(const uint8_t *bytes, int n, + const int *splits, int num_splits, + char *out, size_t out_size) { + framing_buffer_t fb; + framing_init(&fb); + out[0] = '\0'; + int out_len = 0; + log_capture_reset(); // discard logs accumulate but are irrelevant here + + int pos = 0; + for (int s = 0; s <= num_splits; s++) { + int end = (s < num_splits) ? splits[s] : n; + if (end > pos) { + framing_add_bytes(&fb, &bytes[pos], end - pos); + pos = end; + } + uint8_t frame[BUS_MESSAGE_MAX_SIZE]; + int frame_len; + framing_result_t result; + while ((result = framing_process_next(&fb, frame, &frame_len)) != FRAMING_NEED_MORE_DATA) { + if (result != FRAMING_FRAME_READY) { + continue; // resync/discard accounting is deliberately ignored + } + uint16_t src = (frame[1] << 8) | frame[2]; + uint16_t dst = (frame[3] << 8) | frame[4]; + uint8_t cmd = frame[7]; + char payload_str[1024] = ""; + int payload_len = frame_len - 12; + for (int i = 0; i < payload_len; i++) { + sprintf(payload_str + i * 2, "%02X", frame[10 + i]); + } + int w = snprintf(out + out_len, out_size - out_len, + "Decoded: Src=%04X, Dst=%04X, Cmd=0x%02X, Payload=%s\n", + src, dst, cmd, payload_str); + if (w > 0) out_len += w; + } + } +} + +// Property: the set and order of recovered frames is invariant to how the byte +// stream is chunked across framing_add_bytes() calls. The parser is +// deterministic on buffer contents, and the only chunk-sensitive path (the +// no-start mass-discard) only ever drops non-0x02 bytes, so it can never lose a +// recoverable frame. We therefore decode each case one-shot, then re-decode it +// split at every interior offset AND fully fragmented (one byte per chunk), and +// assert the "Decoded:" lines match. Resync/discard counts legitimately vary +// with chunking and are NOT compared. Reuses the existing capture/synthetic +// inputs, so it needs no goldens of its own. (Lines here must not use '|'.) +static void run_chunk_invariance(const char *hex_file_path, int *passed, int *failed) { + FILE *f = fopen(hex_file_path, "r"); + if (!f) { + fprintf(stderr, "ERROR: Cannot open %s\n", hex_file_path); + (*failed)++; + return; + } + printf("Checking chunk invariance: %s ...\n", hex_file_path); + + char line[4096]; + int file_line = 0, case_num = 0, local_fail = 0; + while (fgets(line, sizeof(line), f)) { + file_line++; + trim_trailing(line); + if (line[0] == '\0' || line[0] == '#') { + continue; + } + uint8_t bytes[1024]; + int n = parse_hex_to_bytes(line, bytes); + if (n <= 0) { + continue; + } + case_num++; + + char oneshot[8192]; + decoded_lines_chunked(bytes, n, NULL, 0, oneshot, sizeof(oneshot)); + + bool case_failed = false; + + // Every single interior split point (two chunks). + for (int split = 1; split < n && !case_failed; split++) { + char chunked[8192]; + decoded_lines_chunked(bytes, n, &split, 1, chunked, sizeof(chunked)); + if (strcmp(oneshot, chunked) != 0) { + local_fail++; + case_failed = true; + printf("FAIL: %s:%d (Case %d) split@%d\n", hex_file_path, file_line, case_num, split); + printf(" One-shot:\n%s Chunked:\n%s", oneshot, chunked); + printf("==================================================\n"); + } + } + + // Maximal fragmentation: one byte per chunk. + if (!case_failed && n > 1) { + int splits[1024]; + for (int i = 0; i < n - 1; i++) splits[i] = i + 1; + char fragmented[8192]; + decoded_lines_chunked(bytes, n, splits, n - 1, fragmented, sizeof(fragmented)); + if (strcmp(oneshot, fragmented) != 0) { + local_fail++; + printf("FAIL: %s:%d (Case %d) fully fragmented\n", hex_file_path, file_line, case_num); + printf(" One-shot:\n%s Fragmented:\n%s", oneshot, fragmented); + printf("==================================================\n"); + } + } + } + fclose(f); + + if (local_fail == 0) { + printf(" %d case(s) invariant across all single splits + full fragmentation -> PASS\n", case_num); + (*passed)++; + } else { + (*failed)++; + } +} + +int main(int argc, char **argv) { + bool bless = false; + for (int i = 1; i < argc; i++) { + if (strcmp(argv[i], "--bless") == 0) { + bless = true; + } else { + fprintf(stderr, "Usage: %s [--bless]\n", argv[0]); + return 2; + } + } + + // Enable log capture so ESP_LOG resync/warnings go to buffer instead of stdout + log_capture_enabled = true; + + int passed = 0; + int failed = 0; + + printf(bless ? "Blessing framing goldens...\n\n" : "Running standalone framing tests...\n\n"); + + int real_cases = run_file("frames/observed_error_frames.txt", + "frames/observed_error_frames_output.txt", bless, &passed, &failed); + int synth_cases = run_file("frames/synthetic_errors.txt", + "frames/synthetic_errors_output.txt", bless, &passed, &failed); + int chunk_cases = run_file("frames/chunked_reassembly.txt", + "frames/chunked_reassembly_output.txt", bless, &passed, &failed); + run_overflow_test(&passed, &failed); + + // Property test: feeding the same bytes split at any boundary must recover + // the same frames. Runs over the existing whole-line captures only (no '|'). + if (!bless) { + run_chunk_invariance("frames/observed_error_frames.txt", &passed, &failed); + run_chunk_invariance("frames/synthetic_errors.txt", &passed, &failed); + } + + int total_checks = real_cases + synth_cases + chunk_cases + 1; + printf("\nFraming test summary: %d golden checks (%d real captures, %d synthetic modes, %d chunked, 1 overflow)" + " + 2 chunk-invariance sweeps, %d passed, %d failed\n", + total_checks, real_cases, synth_cases, chunk_cases, passed, failed); + + return (failed == 0) ? 0 : 1; +} diff --git a/test/unknown_buffer_stub.c b/test/unknown_buffer_stub.c index fcd75f2..7054c85 100644 --- a/test/unknown_buffer_stub.c +++ b/test/unknown_buffer_stub.c @@ -1,9 +1,9 @@ #include -#include +#include "../main/unknown_buffer.h" // No-op stub — message_decoder.c calls this but the real implementation // uses FreeRTOS primitives not available in the host test environment. -void unknown_buffer_record(const uint8_t *data, int len, bool is_error) +void unknown_buffer_record(const uint8_t *data, int len, unknown_reason_t reason) { - (void)data; (void)len; (void)is_error; + (void)data; (void)len; (void)reason; }