improved the logtool, but not quite there yet?

This commit is contained in:
Thaddeus Hughes
2026-03-30 11:39:04 -05:00
parent 9eb283420a
commit 837ec18fad
24 changed files with 55223 additions and 57 deletions

View File

@@ -12,7 +12,9 @@
"Bash(grep -r \"esp_bt\" C:/data/stockcropper-sw/SC-F001/build/esp-idf/bt/ --include=\"*.cmake\" -l 2>/dev/null | head -5)", "Bash(grep -r \"esp_bt\" C:/data/stockcropper-sw/SC-F001/build/esp-idf/bt/ --include=\"*.cmake\" -l 2>/dev/null | head -5)",
"Bash(grep -r \"esp_bt.h\" C:/data/stockcropper-sw/SC-F001/build/ --include=\"*.cmake\" 2>/dev/null | head -5)", "Bash(grep -r \"esp_bt.h\" C:/data/stockcropper-sw/SC-F001/build/ --include=\"*.cmake\" 2>/dev/null | head -5)",
"WebFetch(domain:docs.espressif.com)", "WebFetch(domain:docs.espressif.com)",
"Bash(curl -s \"https://docs.espressif.com/projects/esp-idf/en/stable/esp32/api-reference/peripherals/clk_tree.html\" | sed 's/<script[^>]*>.*<\\\\/script>//g; s/<style[^>]*>.*<\\\\/style>//g; s/<[^>]*>//g; s/&amp;/\\\\&/g; s/&lt;/</g; s/&gt;/>/g; s/&nbsp;/ /g; s/&quot;/\"/g; s/&#39;/'\"'\"'/g' | tr -s ' \\\\n' | grep -v '^[[:space:]]*$' 2>&1 | head -2000)" "Bash(curl -s \"https://docs.espressif.com/projects/esp-idf/en/stable/esp32/api-reference/peripherals/clk_tree.html\" | sed 's/<script[^>]*>.*<\\\\/script>//g; s/<style[^>]*>.*<\\\\/style>//g; s/<[^>]*>//g; s/&amp;/\\\\&/g; s/&lt;/</g; s/&gt;/>/g; s/&nbsp;/ /g; s/&quot;/\"/g; s/&#39;/'\"'\"'/g' | tr -s ' \\\\n' | grep -v '^[[:space:]]*$' 2>&1 | head -2000)",
"Bash(find /c/data/stockcropper-sw/SC-F001/main -name \"*.c\" -o -name \"*.h\" | xargs grep -l \"soft_idle_enter\\\\|soft_idle_exit\" 2>/dev/null)",
"Bash(xxd:*)"
] ]
} }
} }

1
.gitignore vendored
View File

@@ -1 +1,2 @@
/build/ /build/
/26c3058c23be21cf6f9cc812bd5d0a8907b2ecf2/

View File

@@ -13,21 +13,21 @@
**GPIO Map:** **GPIO Map:**
| GPIO | Function | | GPIO | Function |
|------|----------| |------|----------|
| 13 | Button interrupt (active low, pull-up) — also EXT0 wakeup | | 13 | Button interrupt (active low, pull-up) |
| 14 | Jack position sensor / encoder | | 14 | Jack position sensor / encoder |
| 16 | Drive encoder | | 16 | Drive encoder |
| 19 | Aux sensor 2 (reserved) | | 19 | Aux sensor 2 (reserved) |
| 21/22 | I2C SDA/SCL (400kHz) → TCA9555 I/O expander | | 21/22 | I2C SDA/SCL (400kHz) → TCA9555 I/O expander |
| 25 | 433MHz RF receiver (RMT input) | | 25 | 433MHz RF receiver (RMT input) |
| 26 | Solar charger bulk enable (RTC GPIO, holds across deep sleep) | | 26 | Solar charger bulk enable (RTC GPIO) |
| 27 | Safety sensor (active low) | | 27 | Safety sensor (active low) |
| 32/33 | External 32.768 kHz RTC crystal (standard watch crystal, 2¹⁵ Hz) | | 32/33 | External 32.768 kHz RTC crystal (on PCB, not used — see RTC section) |
| 36 (VP) | ADC: drive current sense | | 36 (VP) | ADC: drive current sense |
| 39 (VN) | ADC: battery voltage | | 39 (VN) | ADC: battery voltage |
| 34 | ADC: jack current sense | | 34 | ADC: jack current sense |
| 35 | ADC: aux current sense | | 35 | ADC: aux current sense |
**TCA9555 (I2C at 0x20):** **TCA9555 (I2C at 0x21):**
- Port 0 (input): 2 physical buttons + 2 additional inputs - Port 0 (input): 2 physical buttons + 2 additional inputs
- Port 1 (output): 3× H-bridge relay pairs (DRIVE, JACK, AUX) + LEDs - Port 1 (output): 3× H-bridge relay pairs (DRIVE, JACK, AUX) + LEDs
@@ -42,23 +42,25 @@
``` ```
app_main() app_main()
├── rtc_xtal_init() RTC crystal + EXT0 wakeup + sleep wakeup check ├── rtc_xtal_init() Button GPIO setup
├── i2c_init() TCA9555 init (relays off, LEDs off) ├── i2c_init() TCA9555 init (relays off, LEDs off)
├── adc_init() ADC1 calibration (12dB attenuation, line-fit) ├── adc_init() ADC1 calibration (12dB attenuation, line-fit)
├── storage_init() Flash params + circular log buffer ├── storage_init() Flash params
├── log_init() Circular log buffer
├── solar_run_fsm() (called in main loop too) ├── solar_run_fsm() (called in main loop too)
├── uart_init() Serial JSON API task ├── uart_init() Serial JSON API task
├── sensors_init() GPIO ISR setup for sensors/encoders
├── fsm_init() Control FSM task (priority 10, 20ms tick)
├── rf_433_init() 433MHz RMT receiver task ├── rf_433_init() 433MHz RMT receiver task
├── bt_hid_init() BLE HID host scanner task ├── bt_hid_init() BLE HID host scanner task
├── fsm_init() Control FSM task (priority 10, 20ms tick)
└── webserver_init() WiFi softAP + HTTP + mDNS + DNS └── webserver_init() WiFi softAP + HTTP + mDNS + DNS
Main loop (50ms): Main loop (50ms):
i2c_poll_buttons() i2c_poll_buttons()
fsm_request() based on button events fsm_request() based on button events
solar_run_fsm() solar_run_fsm()
driveLEDs() status animation drive_leds() status animation
rtc_check_shutdown_timer() → deep sleep on inactivity (180s) rtc_check_shutdown_timer() → soft idle on inactivity (180s)
``` ```
**FreeRTOS Tasks:** **FreeRTOS Tasks:**
@@ -82,13 +84,13 @@ Main loop (50ms):
| `power_mgmt.c/h` | ADC reading, e-fuse thermal algorithm, battery voltage | | `power_mgmt.c/h` | ADC reading, e-fuse thermal algorithm, battery voltage |
| `sensors.c/h` | GPIO ISR-based sensor debouncing, encoder counters | | `sensors.c/h` | GPIO ISR-based sensor debouncing, encoder counters |
| `i2c.c/h` | TCA9555 relay/LED/button control | | `i2c.c/h` | TCA9555 relay/LED/button control |
| `storage.c/h` | 47-param NVM table + circular binary log buffer | | `storage.c/h` | 48-param NVM table + circular binary log buffer |
| `comms.c/h` | Unified GET/POST JSON API (shared by HTTP and UART) | | `comms.c/h` | Unified GET/POST JSON API (shared by HTTP and UART) |
| `webserver.c/h` | WiFi softAP, HTTP server, embedded gzip webpage | | `webserver.c/h` | WiFi softAP, HTTP server, embedded gzip webpage |
| `uart_comms.c/h` | Serial JSON interface (115200 8N1) | | `uart_comms.c/h` | Serial JSON interface (115200 8N1) |
| `rf_433.c/h` | 433MHz OOK receiver, keycode learn/match | | `rf_433.c/h` | 433MHz OOK receiver, keycode learn/match |
| `bt_hid.c/h` | BLE HID host, media remote button mapping | | `bt_hid.c/h` | BLE HID host, media remote button mapping |
| `rtc.c/h` | Unix time, harvest alarms, deep sleep scheduling | | `rtc.c/h` | Unix time, harvest alarms, soft idle, inactivity timer |
| `solar.c/h` | Simple FLOAT/BULK solar charge state machine | | `solar.c/h` | Simple FLOAT/BULK solar charge state machine |
| `sc_err.h` | Error code definitions | | `sc_err.h` | Error code definitions |
| `log_test.c/h` | Flash log unit tests | | `log_test.c/h` | Flash log unit tests |
@@ -109,8 +111,7 @@ STATE_DRIVE_END_DELAY (1s)
STATE_JACK_DOWN (reverse until e-fuse/sensor) STATE_JACK_DOWN (reverse until e-fuse/sensor)
→ back to STATE_IDLE → back to STATE_IDLE
STATE_UNDO_JACK_START (emergency: reverse jack immediately) STATE_UNDO_JACK_START (emergency: reverse jack, run until e-fuse/sensor)
STATE_UNDO_JACK (run until e-fuse/sensor)
→ back to STATE_IDLE → back to STATE_IDLE
CAL_JACK_DELAY / CAL_JACK_MOVE (jack calibration sequence) CAL_JACK_DELAY / CAL_JACK_MOVE (jack calibration sequence)
@@ -128,7 +129,7 @@ CAL_DRIVE_DELAY / CAL_DRIVE_MOVE (drive calibration sequence)
2. `process_battery_voltage()` — ADC → EMA 2. `process_battery_voltage()` — ADC → EMA
3. `sensors_check()` — drain ISR queue, update counters/debounce 3. `sensors_check()` — drain ISR queue, update counters/debounce
4. State machine transitions (timer + sensor + efuse checks) 4. State machine transitions (timer + sensor + efuse checks)
5. `driveRelays()` — write relay output from current state 5. `drive_relays()` — write relay output from current state
6. `send_fsm_log()` — 39-byte timestamped entry to flash 6. `send_fsm_log()` — 39-byte timestamped entry to flash
--- ---
@@ -169,12 +170,14 @@ Safety break → immediate `STATE_UNDO_JACK_START`.
|----------|--------|-------------| |----------|--------|-------------|
| `/` | GET | Embedded gzip HTML webpage | | `/` | GET | Embedded gzip HTML webpage |
| `/get` | GET | JSON system status | | `/get` | GET | JSON system status |
| `/set` | POST | JSON commands + parameter updates | | `/post` | POST | JSON commands + parameter updates |
| `/log` | GET | Binary log download (4B JSON len + JSON + 8B offsets + log data) | | `/log` | GET | Binary log download (4B JSON len + JSON + 8B offsets + log data) |
| `/ota` | POST | Firmware update upload |
### UART (115200 8N1) ### UART (115200 8N1)
- `GET` → same as HTTP GET /get - `GET` → same as HTTP GET /get
- `POST: {json}` → same as HTTP POST /set - `POST: {json}` → same as HTTP POST /post
- `RTCDEBUG` → dump RTC timekeeping state (time, backup, sleep entry, clock source)
- `HELP` → command reference - `HELP` → command reference
- Shares `comms_handle_get()` / `comms_handle_post()` with HTTP - Shares `comms_handle_get()` / `comms_handle_post()` with HTTP
@@ -198,7 +201,7 @@ Safety break → immediate `STATE_UNDO_JACK_START`.
**Flash partition "storage":** **Flash partition "storage":**
``` ```
0x0000 0x0FFF Parameters (4 sectors, CRC32-protected, 47 params) 0x0000 0x0FFF Parameters (4 sectors, CRC32-protected, 48 params)
0x1000 end Circular log buffer (head/tail tracked) 0x1000 end Circular log buffer (head/tail tracked)
``` ```
@@ -226,31 +229,24 @@ Safety break → immediate `STATE_UNDO_JACK_START`.
--- ---
## RTC & 32.768 kHz Crystal ## RTC & Timekeeping
**Crystal:** Standard 32.768 kHz (32768 Hz = 2¹⁵ Hz) tuning-fork watch crystal on GPIO32/GPIO33. This frequency is universal for RTCs because it divides to exactly 1 Hz with a 15-bit binary counter. **Time source:** `esp_timer` (40 MHz APB crystal, ~20 ppm accuracy). The external 32.768 kHz crystal on GPIO32/33 is present on the PCB but **not used** — deep sleep is disabled (soft idle instead), so RTC slow clock accuracy is irrelevant. The RTC slow clock uses the default internal RC oscillator.
**sdkconfig.defaults settings:** **`rtc_xtal_init()` in `rtc.c`:** Configures the button GPIO (GPIO13); no crystal bootstrap or sleep wakeup sources.
- `CONFIG_RTC_CLK_SRC_EXT_CRYS=y` — selects the external crystal as the RTC slow clock source instead of the internal ~150 kHz RC oscillator
- `CONFIG_ESP32_RTC_EXT_CRYST_ADDIT_CURRENT_V2=y` — enables extra drive current during the crystal startup window; required for high-ESR tuning-fork crystals (e.g. CM315D32768DZFT ~70 kΩ ESR)
**Known startup failure mode:** On power-on, the ESP32 bootloader attempts to calibrate the crystal. If it fails to detect oscillation within its calibration window, it logs `W: 32 kHz XTAL not found, switching to internal 150 kHz oscillator` and falls back to the RC oscillator. The RC oscillator has ±5% accuracy, producing up to ~180 s/hr of RTC drift — this completely breaks harvest scheduling. **Time persistence across resets:** `sync_unix_us` and `sync_rtc_us` are `RTC_DATA_ATTR` (survive software resets — panics, WDT). On restart, `rtc_restore_time()` recovers time via the RTC hardware counter (which runs in the RTC domain and survives resets). RC oscillator drift (~±5%) is negligible over a <30s crash restart (~1.5s worst case).
**Firmware mitigation (`rtc_xtal_init()` in `rtc.c`):** If `rtc_clk_slow_src_get()` does not return `SOC_RTC_SLOW_CLK_SRC_XTAL32K` at startup, the code applies a manual bootstrap: `rtc_clk_32k_bootstrap(20000)` (~600 ms of extra drive current at 32 kHz cycles), waits 500 ms for oscillation to stabilise, then calls `rtc_clk_slow_src_set(SOC_RTC_SLOW_CLK_SRC_XTAL32K)` to switch explicitly. Success or failure is logged via `ESP_LOGI/LOGE`. **Diagnosing time issues:** Run `RTCDEBUG` over UART. Reports current time, sync time, elapsed since sync, next alarm, uptime, and soft idle state.
**Diagnosing crystal issues:** Run `RTCDEBUG` over UART and check `slow_clk_src`. It reports either `XTAL32K (OK)` or `NOT XTAL32K — check crystal!`. The `logtool/rtc_test.py` script automates this and runs multi-cycle drift tests.
**Time persistence across deep sleep:** `rtc_backup_s` and `rtc_sleep_entry_s` are `RTC_DATA_ATTR` (survive deep sleep). On wakeup, `rtc_restore_time()` adds exactly `DEEP_SLEEP_US / 1e6` seconds to `rtc_sleep_entry_s` to reconstruct the correct time without an NTP sync.
--- ---
## Power Management ## Power Management
- **Battery voltage:** GPIO39, divider `V = raw × 0.00767 + 0.4` - **Battery voltage:** GPIO39, divider `V = raw × V_SENS_K + V_SENS_OFFSET` (defaults: K=0.00766̄, offset=0.4)
- **Solar charger:** GPIO26 (RTC hold) FLOAT/BULK FSM, bulk for 20s when V < 5V for 5s - **Solar charger:** GPIO26 (RTC hold) FLOAT/BULK FSM, bulk for 20s when V < 5V for 5s
- **Inactivity shutdown:** 180s deep sleep - **Inactivity shutdown:** 180s **soft idle** (WiFi/BT off, LEDs off not deep sleep). Button press exits soft idle.
- **Deep sleep wakeup:** RTC timer (120s), RTC alarm (next harvest), EXT0 GPIO13 (button) - **RTC_DATA_ATTR:** Sync timestamps, alarm times, charge state survive software resets (panics, WDT)
- **RTC_DATA_ATTR:** FSM state, errors, alarm times, charge state survive deep sleep
--- ---
@@ -270,8 +266,8 @@ SC_ERR_LOW_BATTERY = 0x230 // Voltage below threshold
## Build System ## Build System
- **Framework:** ESP-IDF (>=4.1.0) - **Framework:** ESP-IDF (>=5.0)
- **Component deps** (`idf_component.yml`): `espressif/mdns`, `joltwallet/littlefs`, `esp-idf-lib/tca95x5` - **Component deps** (`main/idf_component.yml`): `espressif/mdns ~1.9.1`
- **IDF requires:** `driver`, `esp_http_server`, `esp_netif`, `lwip`, `json`, `esp_timer`, `esp_adc`, `app_update`, `esp_wifi`, `nvs_flash`, `mdns`, `bt`, `esp_hid` - **IDF requires:** `driver`, `esp_http_server`, `esp_netif`, `lwip`, `json`, `esp_timer`, `esp_adc`, `app_update`, `esp_wifi`, `nvs_flash`, `mdns`, `bt`, `esp_hid`
- **Webpage:** `webpage.html``webpage_compile.py``webpage_gzip.h` (embedded gzip binary). **Must re-run `webpage_compile.py` after any HTML edit before building.** - **Webpage:** `webpage.html``webpage_compile.py``webpage_gzip.h` (embedded gzip binary). **Must re-run `webpage_compile.py` after any HTML edit before building.**
- **Version:** `version.h.in` filled by CMake from git tags → `FIRMWARE_VERSION`, `BUILD_DATE` - **Version:** `version.h.in` filled by CMake from git tags → `FIRMWARE_VERSION`, `BUILD_DATE`

68
TODO.md
View File

@@ -59,7 +59,73 @@
22. - [clauded] NVS vs custom params: NVS serves WiFi/BT internals + BDA storage; custom flash partition serves app params with CRC32 protection. Different purposes, no consolidation needed. 22. - [clauded] NVS vs custom params: NVS serves WiFi/BT internals + BDA storage; custom flash partition serves app params with CRC32 protection. Different purposes, no consolidation needed.
23. - [clauded] BUG FIX: `FSM_CMD_START` fallthrough was overwriting `this_move_dist = MIN(...)` with unconditional `DRIVE_DIST` — replaced fallthrough with goto to shared start logic so leash limit is preserved 23. - [clauded] BUG FIX: `FSM_CMD_START` fallthrough was overwriting `this_move_dist = MIN(...)` with unconditional `DRIVE_DIST` — replaced fallthrough with goto to shared start logic so leash limit is preserved
24. - [ ] Do general bug-scan with claude. Especially think through the FSM logic. 24. - [clauded] General bug scan (FSM, power, sensors, storage, comms, RTC, peripherals)
- Ran 4 parallel deep-dive reviews across entire codebase. Findings below.
- False positives eliminated: override fallthrough (breaks present), soft idle during motor ops (FSM resets timer), JACK_DOWN_TIME uninitialized first move (jack_finish_us always set before use)
## Suspected Bugs (from item 24 scan)
28. - [ ] **BUG [CRITICAL]:** `get_is_safe()` hardcoded `return true` — safety sensor completely bypassed
- sensors.c:182 — `return true;` with `//return is_safe;` commented out below
- All FSM safety checks (STATE_JACK_UP_START, JACK_UP, DRIVE_START_DELAY, DRIVE, DRIVE_END_DELAY, calibration states) are no-ops
- Safety break will NOT trigger STATE_UNDO_JACK_START — machine runs through hazard conditions
- Debounce logic in sensors_check() still runs but output is discarded
29. - [ ] **BUG [CRITICAL]:** E-fuse INOM params allow min=0.0 → division by zero
- power_mgmt.c:380 — `float I_norm = fabsf(channel->current / I_nominal);`
- storage.h EFUSE_INOM_1/2/3 bounds: min=0.0, max=200.0
- If param=0 → I_norm=Inf → instant trip on any current (motor won't run)
- If param=NaN (flash corruption) → I_norm=NaN → all comparisons false → e-fuse NEVER trips (motor can burn)
- Fix: raise min bound to 0.1 or add explicit NaN/zero guard before division
30. - [ ] **BUG [HIGH]:** No timeout on STATE_UNDO_JACK_START
- control_fsm.c:486-493 — waits for `!efuse_get(BRIDGE_JACK)` with no max wait
- If jack efuse never cools (hardware fault, thermal runaway), FSM stuck indefinitely
- User CAN send FSM_CMD_STOP to escape, but no automatic recovery
- Fix: add timeout (e.g. 30-60s) before forcing transition to IDLE with error
31. - [ ] **BUG [HIGH]:** No e-fuse checks in calibration movement states
- control_fsm.c:495-512 — STATE_CALIBRATE_JACK_MOVE and STATE_CALIBRATE_DRIVE_MOVE
- Only check get_is_safe() and timer_done(), NOT efuse_get()
- Relay outputs (lines 625-640) drive motors regardless of efuse status
- Jack cal runs up to 3s, drive cal up to 6s without overcurrent protection
- Fix: add efuse_get() check and abort calibration on trip
32. - [ ] **BUG [HIGH]:** BLE HID scan task missing watchdog registration
- bt_hid.c — `bt_hid_scan_task()` never calls `esp_task_wdt_add(NULL)`
- Task blocks on `xSemaphoreTake(s_scan_sem, portMAX_DELAY)` — if GAP callback never signals, hangs forever
- Unlike rf_433 task (which registers WDT), BT task has no WDT coverage
- Fix: add `esp_task_wdt_add(NULL)` and periodic `esp_task_wdt_reset()` (or use timeout on semaphore)
33. - [ ] **BUG [HIGH]:** ISR sensor queue full → events silently dropped
- sensors.c:57 — queue size 16, `xQueueSendFromISR()` return value not checked
- If sensors_check() consumer falls behind (4 sensors firing edges), events lost
- Encoder counts become inaccurate → drive distance wrong
- Fix: check return value, optionally increment a dropped-event counter for diagnostics
34. - [ ] **BUG [HIGH]:** Params not validated on set, only on commit — FSM reads unvalidated values
- storage.c:268-273 — `set_param_value_t()` writes directly to `parameter_table[]` with no bounds check
- `validate_param()` only called in `commit_params()` (before flash write)
- Between POST and commit, FSM can read out-of-range values (e.g. DRIVE_DIST=999999)
- Fix: call `validate_param()` inside `set_param_value_t()`, or at least in comms.c after setting
35. - [ ] **BUG [MEDIUM]:** Solar FSM timer uninitialized
- solar.c:17 — `RTC_DATA_ATTR int64_t timer;` has no initializer
- RTC memory may contain garbage on first cold boot before `solar_reset_fsm()` sets it to -1
- `solar_run_fsm()` is called (main.c:253) before `solar_reset_fsm()` has run on first boot path
- Fix: initialize to -1 in declaration: `RTC_DATA_ATTR int64_t timer = -1;`
36. - [ ] **BUG [MEDIUM]:** E-fuse param bounds too loose
- EFUSE_HEAT_THRESH min=0.0 — allows instant trip on any current draw (storage.h)
- EFUSE_INRUSH_US max=10000000 (10s) — allows 10s of unlimited current with no e-fuse protection
- Fix: tighten bounds (e.g. HEAT_THRESH min=1.0, INRUSH_US max=2000000)
37. - [ ] **BUG [MEDIUM]:** No mutex on parameter_table[] — concurrent access from HTTP/UART/FSM tasks
- storage.c — `parameter_table[]` read/written by HTTP POST handlers, UART handlers, and FSM task
- 32-bit aligned reads/writes are atomic on ESP32, so u16/u32/i16/i32/f32 are safe
- f64 (8 bytes) and str16 (16 bytes) could be torn reads — but no f64 or str params are read by FSM in hot path
- Severity is low in practice but architecturally unsound
25. - [ ] Extract pure logic (e-fuse thermal model, param serialization, sensor debounce) into host-testable modules with Unity/CMock? 25. - [ ] Extract pure logic (e-fuse thermal model, param serialization, sensor debounce) into host-testable modules with Unity/CMock?
26. - [ ] UART integration test framework: Python runner + ESP-side test commands 26. - [ ] UART integration test framework: Python runner + ESP-side test commands
27. - [ ] Bug: WiFi won't want to connect to STA except at first boot 27. - [ ] Bug: WiFi won't want to connect to STA except at first boot

BIN
logtool/16MAR2026_2223.bin Normal file

Binary file not shown.

View File

@@ -0,0 +1,2 @@
Reading storage-16MAR2026-1728.bin ...
Parsed 52 entries

BIN
logtool/16MAR2026_2225.bin Normal file

Binary file not shown.

View File

@@ -0,0 +1,58 @@
Reading storage-16MAR2026-1728.bin ...
Parsed 52 entries
Time State Bat(V) Drive(A) Jack(A) Aux(A) Counter Stable Raw DrHeat JkHeat AxHeat
----------------------- -------------------- ------------------- --------------------------------------- ----------------------------------- ------------------------- ------- ----------------- ---------------- ------------------------------------ -------------------------------------- ------
UNK(0xd4) — — — — — — — — — —
1970-01-01 00:00:15.894 IDLE -34926674051072.000 0.00 18141941858304.00 -0.00 15947 DRIVE+AUX2 - 0.0 0.0 0.0
UNK(0xc0) — — — — — — — — — —
UNK(0x3d) — — — — — — — — — —
UNK(0x3c) — — — — — — — — — —
UNK(0x40) — — — — — — — — — —
2458965396544290816 IDLE -0.000 0.00 -0.00 0.00 -13883 SAFETY+DRIVE+AUX2 SAFETY+JACK+AUX2 3.8 0.0 0.0
UNK(0x40) — — — — — — — — — —
UNK(0x9c) — — — — — — — — — —
PARSE_ERR 0.000 0.00 0.00 0.00 0 - - 0.0 0.0 0.0
UNK(0x30) — — — — — — — — — —
72339069014654230 IDLE -0.000 0.00 -0.00 0.00 0 - - 0.0 0.0 0.0
UNK(0x20) — — — — — — — — — —
15564440319108055738 IDLE 0.000 0.00 0.00 0.00 0 - - 0.0 0.0 0.0
UNK(0x91) — — — — — — — — — —
UNK(0x20) — — — — — — — — — —
UNK(0xcd) — — — — — — — — — —
UNK(0x40) — — — — — — — — — —
72339069014687196 IDLE 3.486 0.00 0.00 0.00 16147 SAFETY+AUX2 DRIVE+AUX2 0.0 0.0 0.0
PARSE_ERR 0.000 0.00 0.00 0.00 0 - - 0.0 0.0 0.0
UNK(0xea) — — — — — — — — — —
UNK(0x11) — — — — — — — — — —
UNK(0x41) — — — — — — — — — —
UNK(0xae) — — — — — — — — — —
UNK(0x40) — — — — — — — — — —
PARSE_ERR 0.000 0.00 0.00 0.00 0 - - 0.0 0.0 0.0
UNK(0x20) — — — — — — — — — —
11096869488759107671 CALIBRATE_JACK_DELAY 0.000 55944611772684566528.00 -0.00 0.00 0 - - 0.0 67650244627660800.0 0.0
UNK(0x80) — — — — — — — — — —
281474977709058 JACK_UP_START 0.000 0.00 -0.00 -295735836036957208576.00 15488 SAFETY+DRIVE SAFETY -0.0 0.0 0.0
UNK(0xd3) — — — — — — — — — —
6151020166072509758 MOVE_START_DELAY 0.000 0.00 11751184508542699927613527293952.00 0.00 -27648 AUX2 AUX2 184761406165897707520.0 912500379009562710927105661457137664.0 96.1
UNK(0xb8) — — — — — — — — — —
1972-01-28 13:05:11.952 IDLE 0.000 68671368807317504.00 0.00 12.83 -26752 JACK+AUX2 SAFETY+DRIVE -0.0 124029976523403327445139456.0 0.0
4430992851352526 IDLE 0.000 -76302429880697741276410658934489088.00 0.00 0.00 16718 - DRIVE+AUX2 1923670617821681863848652481495040.0 7180627444374621246193664.0 0.0
UNK(0x40) — — — — — — — — — —
PARSE_ERR 0.000 0.00 0.00 0.00 0 - - 0.0 0.0 0.0
UNK(0x11) — — — — — — — — — —
UNK(0x18) — — — — — — — — — —
UNK(0x40) — — — — — — — — — —
PARSE_ERR 0.000 0.00 0.00 0.00 0 - - 0.0 0.0 0.0
UNK(0xd4) — — — — — — — — — —
UNK(0x40) — — — — — — — — — —
UNK(0x35) — — — — — — — — — —
UNK(0x60) — — — — — — — — — —
UNK(0x5b) — — — — — — — — — —
UNK(0x7f) — — — — — — — — — —
UNK(0x0f) — — — — — — — — — —
UNK(0x40) — — — — — — — — — —
UNK(0x3e) — — — — — — — — — —
UNK(0x40) — — — — — — — — — —
UNK(0xff) — — — — — — — — — —
Entries : 52 total (15 FSM, 0 BAT, 0 CRASH, 0 BOOT, 0 TIME_SET)

BIN
logtool/17MAR2026_0815.bin Normal file

Binary file not shown.

View File

@@ -0,0 +1,3 @@
Reading storage-16MAR2026-1728.bin ...
Log offsets: tail=16384 head=4329920
Parsed 54831 entries

BIN
logtool/17MAR2026_0816.bin Normal file

Binary file not shown.

54841
logtool/17MAR2026_0816.txt Normal file

File diff suppressed because it is too large Load Diff

BIN
logtool/17MAR2026_0819.bin Normal file

Binary file not shown.

View File

@@ -0,0 +1,3 @@
Reading storage-16MAR2026-1728.bin ...
Log offsets: tail=16384 head=4329920
Parsed 54831 entries

BIN
logtool/17MAR2026_0821.bin Normal file

Binary file not shown.

View File

@@ -0,0 +1,3 @@
Reading storage-16MAR2026-1728.bin ...
Log offsets: tail=16384 head=4329920
Parsed 54831 entries

BIN
logtool/17MAR2026_0859.bin Normal file

Binary file not shown.

View File

@@ -0,0 +1,3 @@
Reading storage-16MAR2026-1728.bin ...
Log offsets: tail=16384 head=4329920
Parsed 70748 entries

29
logtool/debug-notes.md Normal file
View File

@@ -0,0 +1,29 @@
# Logtool Debug Notes — 16 MAR 2026
## Problem
`storage-16MAR2026-1728.bin` not parsing correctly.
## Root Cause (SOLVED)
Two issues in `parser.py`:
### 1. Unrecognized file format
The file format is `[4B tail BE][4B head BE][raw log data]` — no JSON header.
- `head - tail == file_size - 8` (the raw log data is exactly the flash region from tail to head)
- The old HTTP format was: `[4B json_len BE][json][4B tail BE][4B head BE][raw log data]`
- The parser's autodetect only recognized the old HTTP format (and required json_len < 8192)
- **Fix:** Added detection for bare tail+head format in `autodetect_and_parse()`
### 2. Type-first vs type-last detection failure
The log entries use **type-first** format: `[len][type][payload]`
But `_try_detect_type_first()` returned False because:
- First entry had type=0x00 at both positions (ambiguous)
- Timestamp was near-zero (RTC not yet set), so timestamp sanity check failed
- Function gave up after only 1 entry (`break` at end of loop)
- **Fix:** Loop over multiple entries (up to 200), added voltage sanity check (0.5-60V)
## Verification
- 54,831 entries parsed successfully
- FSM states: IDLE (51169), JACK_UP (1078), DRIVE (994), etc.
- Voltages: 3.3V13.3V (reasonable for 3S LiPo system)
- Timestamps: Jan 13 Feb 6, 2026 (after RTC set)
- Old HTTP-format .bin files still parse correctly

View File

@@ -114,7 +114,7 @@ def show_plots(entries: list, title: str = "SC-F001 Log"):
add_crash_lines(ax3) add_crash_lines(ax3)
ax3.grid(True, alpha=0.3) ax3.grid(True, alpha=0.3)
ax3.xaxis.set_major_formatter(mdates.DateFormatter('%H:%M:%S')) ax3.xaxis.set_major_formatter(mdates.AutoDateFormatter(ax3.xaxis.get_major_locator()))
fig.autofmt_xdate() fig.autofmt_xdate()
plt.tight_layout() plt.tight_layout()
plt.show() plt.show()
@@ -151,7 +151,7 @@ def live_plot(url: str, interval_s: float = 2.0):
} }
axes[1].legend(fontsize=8, loc='upper right') axes[1].legend(fontsize=8, loc='upper right')
axes[3].legend(fontsize=8, loc='upper right') axes[3].legend(fontsize=8, loc='upper right')
axes[3].xaxis.set_major_formatter(mdates.DateFormatter('%H:%M:%S')) axes[3].xaxis.set_major_formatter(mdates.AutoDateFormatter(axes[3].xaxis.get_major_locator()))
state = {'current_tail': 0, 'first': True} state = {'current_tail': 0, 'first': True}

View File

@@ -108,10 +108,15 @@ def _ts_to_str(ts_ms: int) -> str:
def _unpack_fsm(payload: bytes, fsm_states: dict) -> dict: def _unpack_fsm(payload: bytes, fsm_states: dict) -> dict:
if len(payload) < 39: if len(payload) < 27:
raise ValueError(f"FSM payload too short: {len(payload)} < 39") raise ValueError(f"FSM payload too short: {len(payload)} < 27")
ts_ms, bat_V, drive_A, jack_A, aux_A, counter, sensors, \ ts_ms, bat_V, drive_A, jack_A, aux_A, counter, sensors = \
drive_heat, jack_heat, aux_heat = struct.unpack_from('<QffffhBfff', payload, 0) struct.unpack_from('<QffffhB', payload, 0)
drive_heat = jack_heat = aux_heat = 0.0
if len(payload) >= 31:
drive_heat, = struct.unpack_from('<f', payload, 27)
if len(payload) >= 39:
jack_heat, aux_heat = struct.unpack_from('<ff', payload, 31)
return { return {
'ts_ms': ts_ms, 'ts_ms': ts_ms,
'time_str': _ts_to_str(ts_ms), 'time_str': _ts_to_str(ts_ms),
@@ -187,10 +192,19 @@ def _unpack_time_set(payload: bytes) -> dict:
} }
def parse_entries(data: bytes, fsm_states: dict = None) -> list: def _is_valid_entry_type(t: int) -> bool:
return (0 <= t <= 12) or t in (LOG_TYPE_BAT, LOG_TYPE_CRASH, LOG_TYPE_BOOT, LOG_TYPE_TIME_SET)
def parse_entries(data: bytes, fsm_states: dict = None, type_first: bool = False) -> list:
""" """
Parse a stream of raw binary log entries. Parse a stream of raw binary log entries.
Returns list of dicts, each with 'entry_type' and type-specific fields. Returns list of dicts, each with 'entry_type' and type-specific fields.
Entry format depends on type_first:
False (current FW): [len u8][payload (len-1 bytes)][type u8]
True (old FW): [len u8][type u8][payload (len-1 bytes)]
In both cases total bytes consumed per entry = len + 1.
""" """
if fsm_states is None: if fsm_states is None:
fsm_states = _FALLBACK_FSM_STATES fsm_states = _FALLBACK_FSM_STATES
@@ -202,25 +216,70 @@ def parse_entries(data: bytes, fsm_states: dict = None) -> list:
while i < n: while i < n:
b = data[i] b = data[i]
# Erased flash or sector padding → done or skip sector # Erased flash or sector padding → skip to next sector
if b == 0xFF: if b == 0xFF or b == 0x00:
break
if b == 0x00:
# Sector padding: skip to next 4096-byte boundary
sector_size = 4096 sector_size = 4096
next_sector = ((i // sector_size) + 1) * sector_size next_sector = ((i // sector_size) + 1) * sector_size
i = next_sector i = next_sector
continue continue
# In type_first (old FW) format, sectors have a small zero-pad header
# that isn't full-sector padding. Only skip individual zero bytes.
if type_first and b == 0x00:
i += 1
continue
entry_len = b # stored len = payload_size + 1 entry_len = b # stored len = payload_size + 1
payload_size = entry_len - 1 payload_size = entry_len - 1
type_offset = i + 1 + payload_size # = i + entry_len end_offset = i + entry_len # last byte of this entry's content
if type_offset >= n: if end_offset >= n:
break # truncated break # truncated
# Detect entry format: with type byte (total = len+1) or without (total = len).
# Check if data[end_offset] is the start of the next entry (no type byte)
# vs a type byte followed by the next entry at end_offset+1.
has_type_byte = True
if end_offset + 1 < n:
next_at_len = data[end_offset] # byte right after payload
next_at_len1 = data[end_offset + 1] # byte one further
# If the byte at end_offset looks like a valid next-entry len byte
# (matches current entry len or is another plausible len), and the
# byte at end_offset+1 does NOT, then there's no type byte.
next_ok = next_at_len not in (0x00, 0xFF) and next_at_len < 250
next1_ok = next_at_len1 not in (0x00, 0xFF) and next_at_len1 < 250
if next_ok and not _is_valid_entry_type(next_at_len):
# end_offset byte isn't a valid type, treat as next entry (no type)
has_type_byte = False
elif next_ok and next_at_len == entry_len and not next1_ok:
# Same len repeating at stride=len (not len+1) → no type byte
has_type_byte = False
if not has_type_byte:
# No type byte: [len][payload], total = len bytes, FSM type implied
payload = data[i + 1 : i + entry_len]
entry_type = 0 # default to IDLE / FSM
i = end_offset # advance by len (not len+1)
elif type_first:
entry_type = data[i + 1]
payload = data[i + 2 : i + 1 + entry_len]
# Fallback: if type-first gives invalid type, try type-last
if not _is_valid_entry_type(entry_type):
alt_type = data[end_offset]
if _is_valid_entry_type(alt_type):
entry_type = alt_type
payload = data[i + 1 : i + 1 + payload_size] payload = data[i + 1 : i + 1 + payload_size]
entry_type = data[type_offset] i = end_offset + 1
else:
payload = data[i + 1 : i + 1 + payload_size]
entry_type = data[end_offset]
# Fallback: if type-last gives invalid type, try type-first
if not _is_valid_entry_type(entry_type):
alt_type = data[i + 1]
if _is_valid_entry_type(alt_type):
entry_type = alt_type
payload = data[i + 2 : i + 1 + entry_len]
i = end_offset + 1
try: try:
if 0 <= entry_type <= 12: if 0 <= entry_type <= 12:
@@ -258,7 +317,7 @@ def parse_entries(data: bytes, fsm_states: dict = None) -> list:
} }
entries.append(e) entries.append(e)
i = type_offset + 1 # advance past type byte # i was already advanced in the format-detection block above
return entries return entries
@@ -285,18 +344,118 @@ def parse_response(blob: bytes, fsm_states: dict = None) -> tuple:
return meta, tail, head, entries return meta, tail, head, entries
def _detect_old_partition_dump(blob: bytes) -> int:
"""
Detect old firmware partition dump format.
Old format: 8-byte file header + 0x4000 bytes params + log entries
with type byte at the start of each entry's content region.
Returns the log data start offset, or 0 if not detected.
"""
if len(blob) < 0x4100:
return 0
# Check if offset 0x4000 looks like a log sector: leading zero-pad
# followed by a valid entry with a valid type byte at +1 (type-first format)
base = 0x4000
# Find first non-zero byte in the sector
first_nz = 0
while first_nz < 4096 and blob[base + first_nz] == 0x00:
first_nz += 1
if first_nz >= 4096:
return 0
entry_len = blob[base + first_nz]
if entry_len < 2 or base + first_nz + 1 + entry_len > len(blob):
return 0
# In old format, the type byte is the first byte after the len byte
entry_type = blob[base + first_nz + 1]
if _is_valid_entry_type(entry_type):
return base
return 0
def _try_detect_type_first(data: bytes) -> bool:
"""
Given raw log entry data, try to determine if entries use
type-first format (old FW) vs type-last format (current FW).
Samples multiple entries and checks which placement yields
valid entry types, plausible timestamps, or reasonable voltages.
"""
i = 0
n = len(data)
attempts = 0
max_attempts = 200
while i < n and attempts < max_attempts:
b = data[i]
if b == 0xFF:
break
if b == 0x00:
i = ((i // 4096) + 1) * 4096
continue
entry_len = b
end_offset = i + entry_len
if end_offset >= n:
break
# type-last (current): type is at end_offset
type_last = data[end_offset]
# type-first (old): type is at i+1
type_first_val = data[i + 1]
last_valid = _is_valid_entry_type(type_last)
first_valid = _is_valid_entry_type(type_first_val)
if first_valid and not last_valid:
return True
if last_valid and not first_valid:
return False
# Both valid or neither — try parsing the payload to disambiguate
if first_valid and last_valid:
payload_first = data[i + 2 : i + 1 + entry_len]
payload_last = data[i + 1 : i + 1 + entry_len - 1]
for payload, is_first in [(payload_first, True), (payload_last, False)]:
if len(payload) >= 12:
ts = struct.unpack_from('<Q', payload, 0)[0]
# Plausible if timestamp is 2020-2030 in ms
if 1577836800000 < ts < 1893456000000:
return is_first
# Also check if the float at offset 8 is a reasonable voltage (0-60V)
v = struct.unpack_from('<f', payload, 8)[0]
if 0.5 < v < 60.0:
return is_first
# Advance to next entry and keep trying
i = end_offset + 1
attempts += 1
return False
def autodetect_and_parse(blob: bytes, fsm_states: dict = None) -> tuple: def autodetect_and_parse(blob: bytes, fsm_states: dict = None) -> tuple:
""" """
Auto-detect whether blob is HTTP response format or raw flash binary. Auto-detect whether blob is HTTP response format, old partition dump,
or raw flash binary.
Returns (json_meta_or_None, tail_or_None, head_or_None, entries). Returns (json_meta_or_None, tail_or_None, head_or_None, entries).
""" """
# HTTP format: first 4 bytes = BE uint32 json_len, byte 4 should be '{' # HTTP format: first 4 bytes = BE uint32 json_len, byte 4 should be '{'
if len(blob) >= 5: if len(blob) >= 5:
candidate_len = struct.unpack_from('>I', blob, 0)[0] candidate_len = struct.unpack_from('>I', blob, 0)[0]
if candidate_len < 8192 and blob[4:5] == b'{': if candidate_len < len(blob) and blob[4:5] == b'{':
meta, tail, head, entries = parse_response(blob, fsm_states) meta, tail, head, entries = parse_response(blob, fsm_states)
return meta, tail, head, entries return meta, tail, head, entries
# Raw binary # Bare tail+head format: [4B tail BE][4B head BE][raw log data]
entries = parse_entries(blob, fsm_states) # Detect by checking if head - tail == len(blob) - 8
if len(blob) >= 16:
tail_val, head_val = struct.unpack_from('>II', blob, 0)
if head_val > tail_val and (head_val - tail_val) == len(blob) - 8:
log_data = blob[8:]
type_first = _try_detect_type_first(log_data)
entries = parse_entries(log_data, fsm_states, type_first=type_first)
return None, tail_val, head_val, entries
# Old partition dump: 8-byte header + 0x4000 params + log entries (type-first)
log_offset = _detect_old_partition_dump(blob)
if log_offset > 0:
log_data = blob[log_offset:]
type_first = _try_detect_type_first(log_data)
entries = parse_entries(log_data, fsm_states, type_first=type_first)
return None, None, None, entries
# Raw binary — auto-detect type placement
type_first = _try_detect_type_first(blob)
entries = parse_entries(blob, fsm_states, type_first=type_first)
return None, None, None, entries return None, None, None, entries

Binary file not shown.