diff --git a/CLAUDE.md b/CLAUDE.md index 676dbe1..448c7e9 100644 --- a/CLAUDE.md +++ b/CLAUDE.md @@ -41,6 +41,7 @@ There is no source-code lint target or unit-test suite; ESPHome config validatio - `keypad_protocol_types.md` — packet type catalogue (known vs inferred meanings) - `arm_disarm_state_machine.md` / `output_select_state_machine.md` — state machine design rationale - `protocol_investigations.md` — raw observations and open questions +- `known_quirks.md` — user-facing translation of the above: symptoms a user could actually notice (log warnings, delayed disarms), why they happen, and whether action is needed. Update it when an investigation finding has a user-visible symptom, not just internal byte-level detail. Distinguish observed facts from inferred hypotheses when adding to these docs or to log messages; unknown packet meanings are labeled conservatively. `skills/protocol-reverse-engineering/skill.md` defines the analysis methodology used for trace work. diff --git a/components/crow_alarm_panel/README.md b/components/crow_alarm_panel/README.md index 667272c..e646476 100644 --- a/components/crow_alarm_panel/README.md +++ b/components/crow_alarm_panel/README.md @@ -248,3 +248,7 @@ logger: logs: crow_alarm_panel: DEBUG ``` + +Seeing an occasional `WARN` line or a disarm/arm that takes a few extra seconds? Check +[`docs/known_quirks.md`](docs/known_quirks.md) before assuming it's a new bug — most +recurring log noise from this component is already understood and benign. diff --git a/components/crow_alarm_panel/crow_alarm_panel.cpp b/components/crow_alarm_panel/crow_alarm_panel.cpp index b4aab47..ac6b2fd 100644 --- a/components/crow_alarm_panel/crow_alarm_panel.cpp +++ b/components/crow_alarm_panel/crow_alarm_panel.cpp @@ -917,6 +917,15 @@ void CrowAlarmPanel::loop() { } break; } + case RF_REMOTE_EVENT: { + if (data.size() < 5) { + ESP_LOGW(TAG, "RF remote event too short, discarding"); + break; + } + ESP_LOGD(TAG, "[RF Remote %02x:%02x:%02x] Button event, code %02x:%02x [%02x.%s]", data[0], data[1], + data[2], data[3], data[4], type, format_hex_pretty(data).c_str()); + break; + } default: ESP_LOGD(TAG, "Unknown [%02x.%s]", type, format_hex_pretty(data).c_str()); break; diff --git a/components/crow_alarm_panel/crow_alarm_panel.h b/components/crow_alarm_panel/crow_alarm_panel.h index ba0a7d5..d3a6ed5 100644 --- a/components/crow_alarm_panel/crow_alarm_panel.h +++ b/components/crow_alarm_panel/crow_alarm_panel.h @@ -36,6 +36,11 @@ static const uint8_t OUTPUT_STATE = 0x50; static const uint8_t CURRENT_TIME = 0x54; static const uint8_t KEYPAD_PING = 0x23; // Observed recurring keypad keep-alive/ping traffic static const uint8_t KEYPAD_REGISTRATION = 0xA0; // Keypad announce: [a0.address.00]; sent on power-up/reset + +// RF remote button-press event, not tied to any keypad address. data[0..2] is a fixed per-remote +// identity; data[3..4] is a per-remote, per-button code (not portable across remote units — see +// docs/protocol_wire_format.md's 0x7C entry). +static const uint8_t RF_REMOTE_EVENT = 0x7C; static const uint8_t BOUNDARY = 0x7E; // static const uint8_t KEYPRESS = 0xD1; // This is from upstream, but doesn't get sent by arrowhead panels that I can see static const uint8_t KEYPRESS = 0xA1; diff --git a/components/crow_alarm_panel/docs/arm_disarm_state_machine.md b/components/crow_alarm_panel/docs/arm_disarm_state_machine.md index 458056b..704496c 100644 --- a/components/crow_alarm_panel/docs/arm_disarm_state_machine.md +++ b/components/crow_alarm_panel/docs/arm_disarm_state_machine.md @@ -580,6 +580,56 @@ settle it. **Practical takeaway:** no code change proposed. Still waiting on a disarm that coincides with a confirmed-stuck `CURRENT_TIME` state to further test the correlation — none occurred in this window. +### Update (2026-09-07): an 8h36m-armed disarm retried (2/6) with `CURRENT_TIME` confirmed *normal* the whole time — a genuine counter-example on the other side of the correlation + +**Source:** the frigate long-term logger, window 2026-09-05 20:47 → 2026-09-07 05:14 UTC (~32.5h, spans an OTA reboot at 2026-09-05 22:22:48 UTC — docs/comment-only, no functional change, see `protocol_investigations.md`'s 2026-09-07 update). + +**Observed facts — three arm/disarm cycles this window:** + +| Disarm (UTC) | Initiator | Armed since | Duration armed | Retries | `CURRENT_TIME` at disarm | +| --- | --- | --- | --- | --- | --- | +| 09-06 01:17:02 | physical (`AAP Keypad`) | 09-05 23:26:39 (physical arm) | ~1h50m | none, instant | normal | +| 09-07 03:20:50 | integration (`disarm()`, `ESPHome Keypad`) | 09-06 18:44:23 (physical arm) | ~8h36m | **2/6, ~6.7s (backoff 1s→2s)** | normal, confirmed (surrounding `Controller time update`/glitch-recovery broadcasts all self-correct cleanly, no stuck-state broadcast anywhere near the retry) | +| 09-07 04:08:02 | integration (`disarm()`, `ESPHome Keypad`) | 09-07 03:21:37 (physical arm) | ~46m25s | none, instant | normal | + +(A third arm event, 09-06 18:44:23, and its corresponding disarm above bracket the retried cycle; all three arms this window were physical-keypad-initiated, consistent with prior windows where most arms are physical and most disarms are the integration.) + +**Inference (medium confidence — revises the 2026-09-03/09-05 correlation):** the middle row is a clean counter-example on the side of the correlation that had, until now, no exceptions: every previously-confirmed-normal-time disarm resolved instantly (2026-09-03 table: 2/2; 2026-09-05 update: 2/2), while every retry case had either confirmed-stuck time or unknown status. This is the first retry observed with `CURRENT_TIME` *confirmed normal* throughout. Combined with the existing 2026-08-31 counter-example on the other side (confirmed-stuck time, instant 3s-later disarm), the `CURRENT_TIME`-stuck correlation no longer looks like even a partial predictor — stuck time is neither necessary nor sufficient for a retry, across the full sample gathered so far. Duration-armed also doesn't split cleanly: this window's longest-armed case (8h36m) retried while a prior window's longest (5h26m) didn't, and this window's two instant cases (1h50m, 46m) bracket the retried one without an obvious threshold. + +**Assumption (unverified):** what actually distinguishes the small number of retry cases from the larger number of instant ones is now back to being an open question rather than one with a leading candidate. No other signal (bus corruption rate, watchdog activity, time-of-day) has been checked yet for correlation with this specific retry. + +**Practical takeaway:** no code change proposed — the retry/backoff machinery again resolved correctly (2/6, ~6.7s) regardless of cause. Given `CURRENT_TIME`-stuck no longer looks predictive, future sessions should stop treating it as the leading hypothesis and instead capture whatever else is observable at the moment of a retry (recent `ff.`/`fe.` corruption, watchdog trips, or anything else nearby in the log) to look for a different pattern from scratch. + +### Update (2026-09-09): first data point for the "other signals" search — a retry ~5 minutes after a corruption-burst/watchdog-trip episode, vs. three bus-clean instant cycles + +**Source:** the frigate long-term logger, window 2026-09-08 08:40 → 2026-09-09 05:09 UTC. Three arm/disarm sequences this window; the first two were confirmed by the user to be triggered by the official RF remote (distinct chime pattern: once on arm, twice on disarm) rather than a keypad or this integration — at the time of this entry, an `ARMED_STATE` broadcast considered in isolation couldn't distinguish remote-fob input from any other non-integration source, since both simply appear as Controller `ARMED_STATE` broadcasts with no accompanying keypress/command traffic. (A direct RF-remote signature, the `0x7C` frame preceding the broadcast, was decoded later — see `protocol_wire_format.md`'s `0x7C` entry — but wasn't yet identified when this window was analyzed.) + +**Observed facts:** + +| Sequence | Arm (UTC) | Disarm (UTC) | Duration armed | Retries | Nearby `ff.`/`fe.`/watchdog activity | +| --- | --- | --- | --- | --- | --- | +| 1 (remote) | 23:23:41 → confirmed 23:24:10 (09-08) | 23:25:00 | ~50s | none, instant | none within ±10min | +| 2 (remote) | 02:11:49 → confirmed 02:12:17 (09-09) | 02:12:30 | ~13s | none, instant | none within ±10min | +| 3 (integration) | `arm_away()` 03:48:43 → confirmed 03:49:11 | `disarm()` 04:43:55 | ~54m44s | **2/6, ~6.2s (backoff 1s→2s)** | clustered burst `04:37:40–42` (8 lines) → watchdog trip `04:38:40` → 3 repeated `Armed Away` re-broadcasts, all ending **~5min before** the `04:43:55` disarm call; nothing closer, nothing during the retry window itself | + +**Inference (low confidence — one data point):** this is the first retry-associated case where a bus-corruption/watchdog episode occurred anywhere near the event, in either direction — the two remote-triggered cycles (bus-clean, instant) and the earlier `CURRENT_TIME`-normal instant cases from prior windows give no reason to expect corruption alone to force a retry, but this is also the first time anyone has actually looked. The ~5-minute gap is a meaningful caveat against reading too much into it: nothing in the doc's existing model gives an episode that already resolved (watchdog trip fired, ping resumed) a mechanism for causing trouble 5 minutes later — a "controller side-effects from the re-registration/state-resend persist briefly" theory is speculative, not evidenced. Equally consistent with pure coincidence given this integration's baseline retry rate is already nonzero without any corruption present (e.g. the 2026-09-07 8h36m-armed retry had a fully bus-clean surrounding window). + +**Practical takeaway:** no code change. Record as the first candidate data point for the "other signals" search opened in the 2026-09-07 update, but do not treat corruption/watchdog proximity as a working hypothesis yet — one data point with a 5-minute gap is far weaker than the exact-concurrency signature that would make it convincing. Next retry should be checked specifically for whether corruption/watchdog activity is concurrent (same or adjacent minute) rather than just "somewhere in the preceding window," which would be the actual bar for this to become a real lead. + +### Update (2026-09-14): a 9h31m-armed disarm retried (2/6) with zero `ff.`/`fe.` corruption or watchdog activity anywhere in the entire surrounding ~27h window — the cleanest data point yet against the corruption-proximity lead + +**Source:** the frigate long-term logger, window 2026-09-13 04:14 → 2026-09-14 07:26 UTC (~27h13m). Only one integration-initiated arm/disarm sequence this window. + +**Observed facts:** + +| Disarm (UTC) | Initiator | Armed since | Duration armed | Retries | `CURRENT_TIME` at disarm | Nearby `ff.`/`fe.`/watchdog activity | +| --- | --- | --- | --- | --- | --- | --- | +| 09-14 04:29:50 | integration (`disarm()`, `ESPHome Keypad`) | 09-13 18:58:41 (physical arm) | ~9h31m | **2/6, ~6.4s (backoff 1s→2s)** | normal, confirmed (glitch-recovery and `Controller time update` broadcasts self-correcting cleanly seconds before and after) | **none** — zero `ff.`/`fe.` occurrences anywhere in the entire 27h13m window, not just nearby (see `protocol_investigations.md`'s 2026-09-14 update) | + +**Inference (medium confidence — reinforces the 2026-09-07 revision, further undermines the 2026-09-09 corruption-proximity lead):** this retry occurred in a window with no bus corruption at all, ruling out even loose proximity as an explanation this time — stronger than the 2026-09-09 data point, which at least had a corruption/watchdog episode 5 minutes prior. Combined with the 2026-09-07 8h36m-armed/normal-time retry, this is now the second long-armed, normal-`CURRENT_TIME`, bus-clean retry on record. Neither `CURRENT_TIME`-stuck state, corruption proximity, nor duration-armed alone has held up as a predictor across the full sample; the "other signals" search opened 2026-09-07 has now run through its most obvious candidates without finding one. + +**Practical takeaway:** no code change proposed — retry/backoff resolved correctly again (2/6, ~6.4s). Given corruption proximity, `CURRENT_TIME` state, and armed-duration have each been tried and each produced clean counter-examples, a future session should treat this as a lower-priority open question rather than actively hunting for a new candidate signal each time — revisit if a strikingly different case shows up (e.g. a retry that fails to resolve within the existing 6-attempt budget), but routine single retries no longer need dedicated investigation each occurrence. + ## Notes - ARM/STAY/DISARM sequences are simpler than OUTPUT because there's no ACK handshake @@ -588,3 +638,4 @@ settle it. - ARMED_STATE messages (0x11) are published independently regardless of `arm_disarm_state_` (entities always reflect them). As of 2026-08-22, an ARMED_STATE broadcast matching the request's intent resolves the sequence from **any** non-IDLE state (including a retry backoff wait) — see "Retry backoff + intent-matched ARMED_STATE resolution" above. `CODE_ENTER_PENDING` remains the only state that *requires* one to succeed (`ARM_AWAY_PENDING`/`ARM_STAY_PENDING` still resolve on their KEYPAD_COMMAND ack). - All three keypads receive Command broadcasts during arming/disarming; only the originating keypad controls the sequence - `disarm()` also guards against calling when already disarmed — it returns early if `is_armed()` is false +- Audible chime count on the official RF remote distinguishes it from other input sources when reading a trace: **one chime on arm, two chimes on disarm** (confirmed by the user, 2026-09-09). This was historically the only way to tell, since an `ARMED_STATE` broadcast considered in isolation looks the same as any other non-integration source — no accompanying keypress/command traffic, unlike physical-keypad or integration-initiated sequences which leave a `Code sequence:`/keypress trail. A direct on-bus signature now also exists: the `0x7C` RF-remote-event frame (see `protocol_wire_format.md`) precedes the resulting `ARMED_STATE` broadcast, typically by ~100–150ms (one case logged in the same millisecond, `0x7C` still ordered first), so a trace no longer has to rely on the chime alone diff --git a/components/crow_alarm_panel/docs/known_quirks.md b/components/crow_alarm_panel/docs/known_quirks.md new file mode 100644 index 0000000..f4ccf51 --- /dev/null +++ b/components/crow_alarm_panel/docs/known_quirks.md @@ -0,0 +1,155 @@ +# Known Quirks + +Plain-language descriptions of quirks a user of this integration might actually notice — +in Home Assistant, in the ESPHome logs, or physically at the panel. These are all +already-understood behaviors from the reverse-engineering notes in this `docs/` folder; +each entry links to the detailed technical writeup for anyone who wants the full analysis. + +None of these currently need a code change — they're either genuinely benign bus/panel +behavior, or already handled correctly by existing retry/recovery logic. This page exists +so a symptom doesn't get mistaken for a new bug. + +--- + +## Disarming (or arming) sometimes takes a few extra seconds + +**What you'll see:** calling `disarm()` (or `arm_away()`/`arm_stay()`) from Home Assistant +usually resolves in well under a second, but occasionally takes several seconds longer — +the alarm control panel entity may sit in a transitional state briefly before landing on +the final one. The log (at `DEBUG`) will show lines like: + +```text +[W] Arm/disarm: timeout in state 3, retrying (1/6) in 1000 ms +[D] Arm/disarm: starting retry 1/6 +``` + +**Cause:** the component's retry/backoff logic re-sends the keypress sequence when the +controller doesn't confirm in time. Since the retry budget was raised from 5 to 6 (with a +growing 1s–13s backoff), every case observed has resolved successfully within budget +(worst case seen: ~42s, a full 6/6-retry sequence). No root cause has been confirmed — a +`CURRENT_TIME` correlation theory and a bus-corruption/watchdog-proximity theory were each +tested and later ruled out by counter-examples (most recently a retry that occurred during +a full ~27h window with zero corruption or watchdog activity anywhere). The cause remains +genuinely open and is currently a low-priority thread, not an active lead. See +`arm_disarm_state_machine.md` for the full retry investigation history. + +**What to do:** nothing — this is the retry logic working as intended. Before the budget +was raised, two `disarm()` calls did exhaust the then-5-retry budget and abort +(`arm_disarm_state_machine.md`, 2026-08-19 entry) — the motivation for the fix. Since the +budget increase to 6, exhaustion (`Arm/disarm: timeout in state %u, aborting after %u +retries`) has not recurred in any capture; if it ever does, that would be worth reporting. + +--- + +## Output changes (e.g. garage door) occasionally retry once before completing + +**What you'll see:** calling `set_output()` (garage door, gate, etc. from Home Assistant) +usually completes in well under a second, but occasionally the log shows a couple of +WARN-level lines partway through before it finishes successfully a moment later: + +```text +[W] Output-select: timeout in state 3, retrying (output select) +[W] Output-select: KEYPAD_COMMAND in OUTPUT_PENDING (no 0x1D), recovering +``` + +**Cause:** the same bus-corruption noise documented below (`Unknown [ff.]`/`Unknown [fe.]`) +can occasionally land in the slot where the controller's next confirmation was expected +during an output-select sequence. The state machine's built-in timeout/retry and +out-of-sequence recovery logic re-synchronizes and completes the sequence normally — +confirmed in a real capture (`protocol_investigations.md`, 2026-09-13 entry), where the +output still switched correctly ~1.4s after the corruption event. (The arm/disarm retries +above look similar but corruption proximity was specifically tested as a cause there and +ruled out by counter-examples — this output-select mechanism is confirmed, arm/disarm's +isn't.) + +**What to do:** nothing — the output still ends up in the correct state. Only worth +reporting if an output-select sequence ever fails outright rather than retrying through. + +--- + +## Occasional `Unknown [ff.]` / `Unknown [fe.]` log lines + +**What you'll see:** at `DEBUG` level, occasional lines like `Unknown [ff.]` or +`Unknown [fe.]`, usually in short clustered bursts of several lines within about a second, +roughly once every 1–2 hours in long-term captures. + +**Cause:** the controller retransmitting a frame (its own ACK-detection quirk, not +anything this integration does) faster than our receiver can cleanly decode it — the +receiver sees the retransmission burst as corrupted data rather than as a repeated valid +frame. Documented and bit-level-confirmed in `protocol_investigations.md`. + +**What to do:** nothing for an isolated line — that's purely cosmetic log noise from +bus-level behavior outside this integration's control. A clustered burst is the same +underlying cause but can occasionally trigger the watchdog re-announce or an output-select +retry documented elsewhere on this page; those are self-recovering too, so still nothing +to act on, just don't be surprised if one of those other entries' symptoms shows up right +after a burst. + +--- + +## Occasional "No ping for 60 s, re-sending registration announce" warning + +**What you'll see:** a `WARN`-level log line, at a rate that's varied a lot between +capture windows — roughly 0.05–0.9/h in most windows, with some full 21–27h windows at +zero — followed immediately by the integration re-registering itself on the bus. No +functional interruption — entities keep working normally. + +**Cause:** established with no exceptions across many observed instances — this fires +exactly when an `Unknown [ff.]`/`[fe.]` corruption burst (see above) happens to land in +this integration's own poll slot, so the controller's periodic "ping" is missed for one +cycle. The component's watchdog notices and re-announces, recovering automatically. + +**What to do:** nothing — this is the existing watchdog recovering exactly as designed. +The observed baseline has varied between capture windows, including at least one full +~21-27h window with zero trips, so treat "roughly hourly" as a loose upper bound rather +than a stable rate; a sustained rate well above that would still be worth a fresh look. + +--- + +## Occasional "Current time has invalid ..." log lines + +**What you'll see:** lines like `Current time has invalid day/month value 36/36` or +`invalid seconds value 90` (logged at `DEBUG`), or `invalid minutes-since-midnight value +1470` (logged at `WARN`, since it means the whole frame's time-of-day is unusable, not +just one field). Not visible anywhere in Home Assistant — the panel's `CURRENT_TIME` +broadcast isn't exposed as an entity. + +**Cause:** a well-characterized bus-level bit glitch on the `CURRENT_TIME` (`0x54`) +broadcast (a spurious extra bit shifts later fields by one position, indistinguishable +from those fields being doubled). Several specific corrupted values recur consistently +rather than varying randomly, and the minutes-since-midnight variant has recurred at the +same ~2-minute wall-clock window on multiple consecutive days — see the dated +`CURRENT_TIME` sections of `protocol_investigations.md` for the full byte-level analysis. + +**What to do:** nothing — for day/month/year the component tries to recover the known +doubled-bit glitch first (cross-checked against the frame's own weekday field before +trusting the recovery) and only discards the frame if that check fails; other invalid +fields are discarded outright. No entity depends on this data either way, so even the +theoretical edge case where a rarer `×4`-corrupted date could pass the weekday check by +chance (`protocol_wire_format.md`'s `CURRENT_TIME` entry) isn't user-actionable. + +--- + +## Rare truncated-frame warnings (`... too short, discarding` / `... invalid length, discarding`) + +**What you'll see:** very occasionally (roughly once every several hours in long-term +captures), a `WARN` line like `Controller status too short, discarding`, `Zone state +invalid length, discarding`, `Output state too short, discarding`, or `Current time too +short, discarding`. + +**Cause:** an incomplete/truncated frame reached the parser — likely a byproduct of the +same class of bus-level corruption as the `ff.`/`fe.` lines above. Too rare so far to +characterize further. + +**What to do:** nothing — the component correctly discards the malformed frame rather +than acting on partial data. + +--- + +## Cross-references + +| Topic | Document | +| --- | --- | +| Arm/disarm retry investigation | `arm_disarm_state_machine.md` | +| Bus corruption, watchdog, `CURRENT_TIME` glitches, RF remote findings | `protocol_investigations.md` | +| Message type reference (`0x50` OUTPUT_STATE, `0x54` CURRENT_TIME, `0x7C`, etc.) | `protocol_wire_format.md` | diff --git a/components/crow_alarm_panel/docs/protocol_investigations.md b/components/crow_alarm_panel/docs/protocol_investigations.md index 4e62011..f41dbaf 100644 --- a/components/crow_alarm_panel/docs/protocol_investigations.md +++ b/components/crow_alarm_panel/docs/protocol_investigations.md @@ -475,6 +475,36 @@ This does not currently appear to cause the `CODE_ENTER_PENDING` arm/disarm fail **Practical takeaway:** no code change proposed. Worth checking future long-term pulls for whether this rate holds steady, and whether it's specific to this installation (a from-scratch capture on a different panel install, if one ever becomes available, would help separate "always been like this here" from "something changed here recently"). +### Update (2026-09-13): first field case of `ff.`/`fe.` corruption disrupting an in-flight Output-select sequence — timeout/retry and recovery logic both confirmed working under real corruption + +**Source:** frigate long-term logger, window 2026-09-10 04:55 → 2026-09-13 04:14 UTC ([[project-crow-alarm-protocol-trace]]). + +**Findings (observed facts):** at `2026-09-11 21:46:41.777` UTC, a single `Unknown [ff.]` frame landed 84ms after the interface sent output-select digit `4` (`7E.A1.05.04.7E`) for a garage-door (`set_output(4, true)`) sequence, in the exact slot where the controller's `KEYPAD_COMMAND` digit-confirmation was expected. 963ms later (`21:46:42.740`), the state machine logged `Output-select: timeout in state 3, retrying (output select)` and re-sent the `KEY_OUTPUT` packet. The controller's next `KEYPAD_COMMAND` (`14.05.07...`) then arrived while the state machine was back in `OUTPUT_PENDING`, triggering the separate recovery path: `Output-select: KEYPAD_COMMAND in OUTPUT_PENDING (no 0x1D), recovering`. From there the sequence proceeded normally — digit re-sent, `OUTPUT_STATE` confirmed `08`, `ENTER` sent, `Output-select: sequence complete` at `21:46:43.196` — total elapsed time from the corruption event to a completed, successful output toggle: ~1.4s, with the Garage Door switch/output entity landing correctly `ON`. + +**Inference (high confidence):** this is the first observed real-world instance of the `ff.`/`fe.` corruption mechanism (well-established as a cause of registration-watchdog trips via poll-slot collisions, see the updates above) also colliding with an outbound keypress state machine's confirmation window, rather than just a keypad's ping slot. Both of the Output-select machine's defensive paths — the state-3 timeout/retry, and the "unexpected `KEYPAD_COMMAND` while `OUTPUT_PENDING`" recovery branch — fired back-to-back on the same real corruption event and produced a fully successful outcome with no user-visible failure, only WARN-level log lines. This is a genuine confirmation the existing recovery logic works as designed under organic (not scripted/injected) corruption, not just a theoretical code path. + +**Practical takeaway:** no code change — this is the retry/recovery logic doing exactly what it's for. Worth adding a `known_quirks.md` entry alongside the existing arm/disarm retry one, since a user could plausibly notice an output-select action (e.g. garage door via HA) taking slightly longer than usual with a WARN in the logs, same as the already-documented arm/disarm case. Also worth keeping in mind for the still-open disarm-retry "other signals" investigation ([[project-crow-alarm-protocol-trace]]): this is now a second, independent case (after the 2026-09-09 5-minute-proximity one) of bus corruption interacting with a keypress state machine's confirmation window — concurrent corruption during a retry is looking more plausible as a mechanism, though still not directly demonstrated for an actual arm/disarm retry. + +### Update (2026-09-13, cont.): second-ever occurrence of the malformed 7-byte `ARMED_STATE` decode — this time with no adjacent arm/disarm activity, ruling out a disarm-after-arm-specific trigger + +**Source:** same window as above. + +**Findings (observed facts):** at `2026-09-12 21:47:55.561` UTC, the interface logged `Armed state unknown [11.83.01.46.81.00.80.11 (7)]` — byte-for-byte the same malformed payload first documented in `protocol_trace_2026-08-05_disarm_after_arm.md` (a 7-byte payload where `ARMED_STATE` is normally 4 bytes), which at the time was seen exactly once, immediately after a clean disarm. This occurrence has no arm/disarm activity anywhere nearby — the system was idle/disarmed with only routine `KEYPAD_PING`/`CURRENT_TIME`/`OUTPUT_STATE` traffic in the surrounding minute on both sides. + +**Inference (medium-high confidence):** this revises the original framing. The 2026-08-05 write-up associated the artifact with the disarm-after-arm context because that was the only sample available; a second occurrence with an identical byte payload but zero adjacent arm/disarm activity shows the association was coincidental, not causal. Consistent with the original theory that this is a receiver-side corrupted decode (our interface's own receiver diverging from ground truth, per the original entry's cross-check against a passive monitor) — just one that isn't gated on arm/disarm timing specifically. + +**Practical takeaway:** no code change — already a log-only, non-actionable artifact. Update `protocol_trace_2026-08-05_disarm_after_arm.md`'s framing if it comes up again, to describe this as a rare receiver-side decode glitch rather than a disarm-after-arm-specific one. + +### Update (2026-09-14): `ff.`/`fe.` corruption and watchdog trips both drop to zero for a full ~27h window; a third occurrence of the same malformed 7-byte payload appears with a different type byte, this time as an `Unknown [0x13]` frame rather than `ARMED_STATE` + +**Source:** frigate long-term logger, window 2026-09-13 04:14 → 2026-09-14 07:26 UTC (~27h13m, no reboot/OTA in-window) ([[project-crow-alarm-protocol-trace]]). + +**Findings (observed facts):** zero `Unknown [ff.]`/`[fe.]` lines anywhere in the entire window — a sharper version of the 2026-09-06 dip (2-in-21h) with no corruption at all this time, against an established baseline of ~0.84–0.94/h. Registration-watchdog trips: also zero, consistent with (not a counter-example to) the poll-slot/watchdog mechanism, since there was no corruption burst to trigger one. Frame-FIFO backlog/overflow counters stayed at zero throughout, and no truncated-frame WARNs (`Controller status too short`, `Zone state invalid length`, `Output state too short`, `Current time too short`) occurred. A third instance of the same malformed 7-byte payload appeared at `2026-09-13 15:40:25` UTC — `[13.83.01.46.81.00.80.11 (7)]`, identical to the previous two except the leading type byte is `0x13` rather than `0x11` (bytes 2–7 unchanged). Since `0x13` doesn't match the `ARMED_STATE` (`0x11`) case, this one falls through the parser's `default:` branch and logs as `Unknown [13.83...]`, not `Armed state unknown` — again with no adjacent arm/disarm activity, consistent with the 2026-09-13 revision to "rare receiver-side glitch, not context-gated." + +**Inference (medium confidence):** the zero-corruption window is a second data point that the `ff.`/`fe.` rate is genuinely variable session-to-session rather than a stable ~1/h baseline — worth tracking as its own signal rather than assuming a dip is anomalous. The new `0x13`-typed occurrence of the same payload is consistent with the existing "single/few-bit corruption on the type byte" framing used elsewhere in this doc (e.g. the `0x91` family) — `0x11` and `0x13` differ by one bit (`0x02`) — rather than suggesting a new, distinct artifact. + +**Practical takeaway:** no code change. Next log-mining check should start from **2026-09-14 07:26 UTC**. Standing checklist: poll-slot/watchdog exceptions (still 15+/15+, zero exceptions on record), the October month-value flip (due on/after 2026-10-01, see the `×4`-multiplier entry below), any new arm/disarm retry (see `arm_disarm_state_machine.md`'s 2026-09-14 update — this window's retry had zero corruption/watchdog activity anywhere in the surrounding 27h, a clean data point against the corruption-proximity lead), and whether the `ff.`/`fe.` rate returns to baseline or this dip persists. + ## `Unknown [91.]` — new unlabeled packet type **Source:** `traces/esphome-aap-alarm-interface-logs-34.txt`, a ~1h47m standard-debug-level session with four keypads live (`AAP`, `ESPHome`, `Control 4`, `IP`), otherwise unremarkable (normal disarmed-state zone activity, the already-documented `CURRENT_TIME` glitch, one controller reset with the usual re-registration signature). @@ -658,3 +688,222 @@ By contrast, this window's two other `Unknown [ff.]`/[fe.]` occurrences (2026-09 **Assumption (unverified):** whether the `ff.`/`fe.` rate genuinely varies this much day-to-day (vs. some measurement artifact) is unconfirmed — only one low-rate window has been observed so far. The three new short-frame WARNs are too rare (1-2 instances each) to characterize beyond "rare, exists." **Practical takeaway:** no code change. Next window should keep tracking the `ff.`/`fe.` baseline rate specifically (is 2026-09-05 an outlier or the new normal?) alongside the existing poll-slot/watchdog and month=36/day-value checks, and watch for another `invalid minutes-since-midnight` instance to see if it's always this same 32/64-crossing-midnight signature or something else. + +### Update (2026-09-07): `ff.`/`fe.` rate back to baseline; every clustered burst this window precedes a watchdog trip, including one burst that cost two consecutive trips + +**Source:** the frigate long-term logger, `crow-alarm.log`/`crow-alarm.log.1`, window 2026-09-05 20:47 → 2026-09-07 05:14 UTC (~32.5h). An OTA (already noted in [[project-crow-alarm-protocol-trace]], commit `7e8044f`'s docs/comment-only follow-up) landed mid-window at **2026-09-05 22:22:48 UTC** — clean reboot, no gap, raw bit trace + debug confirmed running continuously before and after. Rates below are computed only for the ~30h51m post-OTA span; the ~1h35m pre-OTA span is too short to be meaningful on its own (0 events, consistent with either baseline). + +**Findings (observed facts):** + +- `Unknown [ff.]`/`[fe.]`: 29 lines total (26 `ff.`, 3 `fe.`) in ~30h51m post-OTA, ≈0.94/h — back in the ~24–48/day range documented before 2026-09-06's anomalous 2-in-21h low, confirming that window was a one-off dip rather than a new normal. +- Of those 29 lines, all but one arrive in exactly 3 tight multi-line bursts (8–10 lines each, all within the same ~1s): `08:36:10–11`, `08:59:40–41`, `19:18:10–11` (all 2026-09-06). The remaining line is a single isolated `fe.` at `01:27:55` (2026-09-07), landing immediately after a normal `[ESPHome Keypad] Ping` already logged that cycle — matching the harmless "isolated line, no trip" pattern from the 2026-09-05 entry above. +- All 3 bursts are followed by a "No ping for 60 s" watchdog trip 45–60s later, with zero exceptions — extending the 2026-09-05 finding's 2/2 sample to 3/3 clustered-burst→trip pairs, still with the single isolated line correctly *not* causing one: + + | Burst (UTC) | Lines | What preceded it | Watchdog trip(s) | + | --- | --- | --- | --- | + | 08:36:10–11 | 9 (1 fe. + 8 ff.) | `Controller time update`, no `AAP Keypad` ping logged yet that cycle — burst starts where the poll rotation's first ping would be | 08:36:55 (1) | + | 08:59:40–41 | 8 (all ff.) | `AAP Keypad` and `ESPHome Keypad` pings both succeeded that cycle; burst follows immediately after | 09:00:40 **and** 09:01:40 (2, consecutive) | + | 19:18:10–11 | 8 (1 fe. + 7 ff.) | `Controller time update`, no `AAP Keypad` ping logged yet that cycle | 19:18:55 (1) | + +- The 08:59:40 burst is a new wrinkle: unlike every previously-documented instance (one burst, one trip), no `[ESPHome Keypad] Ping` line appears anywhere in the full 60s between the first re-announce (09:00:40) and the second (09:01:40) — the address stayed unpolled through two consecutive watchdog cycles from a single corruption event, only recovering (`[ESPHome Keypad] Ping` resumes at 09:01:41) immediately after the second re-announce. No second burst or other corruption is present in that gap to explain it independently. +- Frame-FIFO counters (`frame_backlog_events_`, `frame_overflow_events_`) stayed at 0 for the entire window — the `7e8044f` fix continues to hold regardless of the burst/trip activity above. +- One new truncated-frame WARN variant, not in the 2026-09-06 catalogue: `Current time too short, discarding` (×1, `07:33:25` UTC 2026-09-06) — a `CURRENT_TIME`-specific truncation, distinct from the three `Controller status`/`Zone state`/`Output state` short-frame warnings already catalogued. Still too rare (1 instance) to characterize further. +- `invalid day/month value */36` recurred 57 times, month still exclusively `36`/`0x24`; day values were `24`/`0x18` (25×) and **`28`/`0x1C`** (32×, new — extends the previously-observed `{12,16,20,24}` set by one more +4 step, still fitting the fixed-marginal-bit theory with no exceptions). +- One more `invalid minutes-since-midnight` episode (2nd ever observed, `11:25:55`–`11:27:40` UTC 2026-09-06 — note this is a *different day* than the first instance reported in the 2026-09-06 update, which was also timestamped `11:25:55`–`11:27:40` but on 2026-09-05; the fault appears to recur at a similar wall-clock time on consecutive days). Same shape as the first: 8 occurrences over ~105s, values `1470`/`1503`, self-clears cleanly. This is now a 2nd confirming instance of the bit-32/64-crossing-midnight explanation, not yet distinguishable from a once-daily trigger condition (e.g. a specific bus/controller cycle near local midnight) versus coincidence. +- No `31/16`-style persistent stuck `CURRENT_TIME` state anywhere in the window (still last seen self-clearing 2026-09-01) — all day/month and minutes anomalies this window were the already-characterized transient/self-correcting glitch types. + +**Inference (medium-high confidence):** the poll-slot/watchdog mechanism from 2026-09-05 continues to hold with no exceptions across a larger sample (5/5 clustered bursts now correlated with a trip, across two windows), and the 08:59:40 case shows the effect isn't always confined to a single 60s cycle — a burst can apparently leave the address unpolled long enough to cost two watchdog cycles before recovering, not just one. + +**Assumption (unverified):** why the 08:59:40 burst caused a double-length outage while the other two (and the two from 2026-09-05) caused only a single one isn't established — could be burst severity/duration, or where exactly in the poll rotation it lands, but the sample (1 double-length instance) is too small to distinguish. + +**Practical takeaway:** no code change proposed. Keep tracking clustered-burst→trip pairs for any future exception to the now 5/5 pattern, and watch whether the double-length-outage case recurs (would help characterize what makes some bursts worse than others). Also worth checking on the next `invalid minutes-since-midnight` occurrence whether the ~11:2x UTC timing keeps recurring — two data points at the same wall-clock time on consecutive days is suggestive but not yet enough to call it periodic. + +### Update (2026-09-07, bit-level follow-up): all 3 `ff.` bursts decode to the same repeating corrupted frame pair; the isolated single line hits a different keypad's slot; and the raw bit trace itself turns out to drop bits under load + +**Source:** manual bit-level decoding of the `Raw bit trace:` lines (see `crow_alarm_panel.h`'s `BIT_TRACE_BUFFER_BITS`/`bit_trace_buffer2_`, and the ISR at `crow_alarm_panel.cpp:139-230`) surrounding all 4 `ff.`/`fe.` events from the update above, using the documented LSB-first byte packing (`buffer[idx] = (buffer[idx] >> 1) | (bit << 7)`) and `0x7E` boundary convention from `protocol_wire_format.md`. + +**Findings (observed facts):** decoding each 128-bit snapshot independently (byte-aligned from every `01111110` occurrence in the raw string) across all three bursts (`08:36:10`, `08:59:40`, `19:18:10`) turns up the *same* two corrupted "sentences" recurring snapshot after snapshot within a burst, and across all three bursts: + +- `7e ff fb 21 05 03 8c 02 01 00 23 0e 7e` — a `0x7E`-bounded span whose last 8 payload bytes (`05 03 8c 02 01 00 23 0e`) are byte-for-byte identical to `ESPHome Keypad`'s own real `KEYPAD_PING` payload (`Ping [23.05.03.8C.02.01.00.23.0E (8)]`), just preceded by `ff fb 21` where the real frame has only `23` (one type byte, not three). +- `7e 48 c1 00 a3 40 00 c0 88 83 df ff 7e ...` — a second, less identifiable garbled frame that recurs immediately after the first in every snapshot. + +The isolated single `fe.` line (`01:27:55`, no burst, no watchdog trip) decodes the same way to `7e fe fb 21 07 03 8c 02 01` / `7e c8 c1 00 a3 40 00` — the *same* corrupted-header shape, but with keypad address `07` (`IP Keypad`) in the payload instead of `05` (`ESPHome Keypad`). + +A second attempt built a fully stateful, bit-accurate replica of the real ISR parser (mirroring `boundary_buffer_`/`num_bits_`/`buffer[]` exactly, including the `BUFFER_LENGTH=20`-byte overflow reset) and ran it over the raw-trace lines concatenated in log order for the `08:59:40` burst. It does **not** reproduce the real logged counts for that window (8× `Unknown [ff.]`, 0× `fe.`/other types) — it instead produces 4× `ff.`, 2× `fe.`, 2× an unlogged type `0x48`, and one spurious 1-byte `0x7e` "frame". Tracing why: `crow_alarm_panel.cpp:160` gates bit-trace pushes on `!bit_trace_ready_` and the code's own comment states "bits are simply dropped while the consumer is behind" — i.e., whenever `loop()` hasn't yet drained a completed 128-bit snapshot, *every* bit arriving in the meantime is silently absent from the trace, even though the independent, always-running frame parser sees and processes them normally. Two consecutive raw-trace lines in this exact burst are timestamped only 1ms apart (`08:59:41.020`/`.021`) — implausible for two genuinely sequential 128-bit-at-833µs/bit windows (~107ms minimum each), and consistent with `loop()` having fallen behind and only later draining a backlog of already-stale snapshots. + +**Inference (medium confidence):** the repeating `ff fb 21 05 03 8c 02 01 00 23 0e` / `48 c1 00 a3 40 00 c0 ...` pattern recurring identically, burst after burst, across three unrelated times of day is very unlikely to be coincidental noise — it reads as the controller repeatedly retransmitting the same frame(s) addressed to `ESPHome Keypad` (`05`) and whatever immediately follows it in the poll rotation, with our own receiver decoding each retransmission the same corrupted way. This lines up with the already-documented mechanism at `crow_alarm_panel.cpp:88-103` ("the controller resending the same `KEYPAD_COMMAND` to us ~10x within ~1s ... our own receiver decoding that burst as garbage", `logs-11/36`) — this is the first bit-level confirmation of that mechanism actually recurring in long-term field data, not just the original scripted-trace session. The isolated-line case hitting address `07` instead of `05` is a clean confirming detail for the existing "corruption landing outside our own poll slot is harmless" distinction from the 2026-09-05 update. + +**Assumption (unverified):** the fully stateful replica's mismatch against the real logged counts means the *exact* real-time frame boundaries/types the live parser saw during a burst can't be reconstructed with confidence from the trace alone — only the coarser, per-snapshot pattern-matching above is trustworthy. What the `0x48`-headed second garbled frame actually corresponds to (which keypad/type) is not established. + +**Practical takeaway:** no code change proposed for the `ff.`/`fe.` corruption itself — it remains a bus/controller-side phenomenon outside this integration's control, and the ACK-edge handling already documented in the ISR comment is the current best mitigation. However, **the raw bit trace's bit-dropping-under-load behavior is a previously undocumented limitation of the diagnostic tool itself**, separate from (and not fixed by) the `7e8044f` frame-FIFO fix — that fix protects the frame *queue*, not the bit-trace *buffer*, which has no equivalent backlog protection. Treat the raw bit trace as a reliable coarse activity/timing indicator (confirmed useful for exactly that throughout this doc) but not as a lossless capture suitable for exact frame-boundary reconstruction during high-activity bursts — precisely the windows most interesting for this kind of analysis. Worth deciding later whether the bit-trace buffer is worth extending to a small FIFO of its own if byte-exact burst reconstruction becomes a priority. + +### Update (2026-09-08): third `invalid minutes-since-midnight` episode lands at the exact same wall-clock window three days running; poll-slot/watchdog now 7/7 with no exceptions + +**Source:** the frigate long-term logger, `crow-alarm.log`/`crow-alarm.log.1`, window 2026-09-07 05:14 → 2026-09-08 08:40 UTC (~27.5h, no reboot/OTA in-window). + +**Findings (observed facts):** + +- `Unknown [ff.]`/`[fe.]`: 23 lines (18 `ff.`, 5 `fe.`) in ~27.5h, ≈0.84/h — consistent with the post-2026-09-05-OTA baseline (~0.94/h) re-established in the 2026-09-07 update, confirming 2026-09-06's 2-in-21h reading stays an isolated one-off, not a new normal. +- All but 3 of those lines arrive in exactly 2 tight clustered bursts: `20:11:25–26` (9 lines: 1 `fe.` + 8 `ff.`) and `2026-09-08 00:33:10` (10 lines: 1 `fe.` + 9 `ff.`). Both are followed ~45s later by a single "No ping for 60 s" watchdog trip (`20:12:10`, `00:33:55`), with `[ESPHome Keypad] Ping` conspicuously absent from every intervening poll cycle in both cases — the same signature used to confirm poll-slot hits in the 2026-09-05/09-07 entries above. This extends the clustered-burst→trip correlation to **7/7**, still zero exceptions; both trips this window were single-length (no repeat of the 2026-09-06 double-trip case). +- Third `invalid minutes-since-midnight` episode (line 581, `hour >= 24`): `11:25:55`–`11:27:40` UTC **2026-09-07** — the exact same wall-clock window as the first two instances (2026-09-05 and 2026-09-06 updates above), now three days running. Identical shape again: 8 occurrences over ~105s, values `1470`/`1503`, clean self-clearing resume at `11:27:55`. Three consecutive daily occurrences at the same ~2-minute window is much stronger evidence of a periodic trigger (e.g. a specific controller/bus cycle near local midnight) than coincidence. +- `invalid day/month value */36` recurred 44 times, month still exclusively `36`/`0x24`; day value **`32`/`0x20`** appears for the first time (35×, alongside `28`/`0x1C` ×9) — extends the fixed +4-apart set from `{12,16,20,24,28}` to `{12,16,20,24,28,32}` with no exceptions to the pattern. +- `invalid seconds value`: 278 occurrences, distribution `{60:74, 61:44, 89:40, 90:74, 91:44}` matching the established set, plus one `73` (already a known rare outlier per the 2026-08 full-log grep) and one genuinely new outlier, `67`, at `20:11:31` UTC — landing 6s into the `20:11:25` clustered burst above, i.e. inside a severe-corruption window rather than steady-state, consistent with the existing "outliers cluster inside bursts" characterization rather than a new corruption class. +- `Controller status too short, discarding` fired once (`06:32:22` UTC) — a 4th instance of this already-catalogued rare truncated-frame WARN (2026-09-06 update), still too infrequent (now 4 total across ~3 windows) to characterize further. +- Frame-FIFO counters (`frame_backlog_events_`, `frame_overflow_events_`) stayed at 0 throughout — the `7e8044f` fix continues to hold. +- Two arm and two disarm events this window, all four via physical `AAP Keypad` key presses (`ARM`/PIN+`ENTER`), not integration-initiated — no data point for the disarm-retry investigation (still needs an HA-triggered disarm with debug logging on). + +**Inference (medium-high confidence):** the poll-slot/watchdog mechanism is now confirmed with no exceptions across 7 clustered bursts spanning three windows (2026-09-05, 09-07, 09-08) — treat it as established rather than a hypothesis going forward. The three same-time-of-day `invalid minutes-since-midnight` episodes make periodicity the leading explanation for that fault's *timing*, though the trigger mechanism itself (what happens near `11:26` UTC specifically) is still unidentified. + +**Assumption (unverified):** whether the `11:2x` UTC timing reflects UTC, some local-time boundary at the controller, or a fixed elapsed-time-since-some-event trigger isn't distinguishable yet from three same-UTC-time data points alone — would need either a instance landing off that time to falsify the daily-periodic theory, or independent evidence of what the controller does on a ~24h cycle. + +**Practical takeaway:** no code change. Next window should start from 2026-09-08 08:40 UTC. Keep watching for: a 4th `invalid minutes-since-midnight` instance (same time-of-day again, or a break in the pattern); any exception to the now-7/7 poll-slot/watchdog correlation; further extension of the day/month `+4` set past `32`; and an integration-initiated (not keypad-initiated) disarm to finally get a fresh data point for the abandoned-then-reopened retry question. + +### Update (2026-09-09): 4th consecutive `invalid minutes-since-midnight` at the exact same wall-clock window confirms periodicity; poll-slot/watchdog now 9/9; day/month set extends to `36`; first integration disarm retry with a nearby bus-disruption episode (see `arm_disarm_state_machine.md`) + +**Source:** the frigate long-term logger, `crow-alarm.log`/`crow-alarm.log.1`, window 2026-09-08 08:40 → 2026-09-09 05:09 UTC (~20.5h, no OTA in-window — one device reboot at `23:21:16` UTC, same firmware `2026.8.2` compiled `2026-09-06 10:21:31`, so a restart not a redeploy; treated as a boundary, not spanned for rate purposes since it's only ~2.5min before the first arm/disarm sequence below). + +**Findings (observed facts):** + +- 4th consecutive daily `invalid minutes-since-midnight` episode, again `11:25:55`–`11:27:40` UTC (this time 2026-09-08) — identical shape to the prior three (8 occurrences over ~105s, values `1470`/`1503`, clean self-clearing resume). Four consecutive days at the exact same ~2-minute wall-clock window is strong enough now to treat daily periodicity as established, not a hypothesis — flagging this directly per the 2026-09-08 entry's note to do so once a 4th instance landed. The underlying trigger (what happens on the controller near `11:26` UTC) is still unidentified. +- `Unknown [ff.]`/`[fe.]`: 18 lines (17 `ff.`, 1 `fe.`) in ~20.5h, ≈0.88/h — consistent with the established post-`7e8044f` baseline (~0.84–0.94/h), no change. +- All 18 lines fall into exactly 2 clustered bursts — `2026-09-09 00:28:10` (10 lines) and `2026-09-09 04:37:40–42` (8 lines) — zero isolated lines this window. Both bursts are followed ~45–60s later by a single "No ping for 60 s" watchdog trip (`00:28:55`, `04:38:40`), `[ESPHome Keypad] Ping` again absent from the intervening poll cycle both times. This extends the clustered-burst→trip correlation to **9/9**, still zero exceptions. +- Both bursts/trips this window also coincide with the Controller re-broadcasting its *current* (unchanged) `ARMED_STATE` two or three times in a row a few seconds apart — three repeated `Armed Away` broadcasts bracketing the `04:37:40` burst (`04:37:46`, `04:38:02`, `04:38:40`), and three repeated `Disarmed` broadcasts bracketing the `00:28:10` burst (`00:28:15`, `00:28:32`, `00:28:55`). Not a new mechanism (the registration-watchdog re-announce triggering a full state resend to the freshly-reregistered keypad is the working theory — see [[project-crow-alarm-protocol-trace]]), but the first time it's been tied this cleanly to the poll-slot/watchdog burst pattern by timestamp rather than noted as a separate coincidence. +- `invalid day/month value */36`: 40 occurrences; day value **`36`/`0x24`** appears for the first time (32×, alongside `32`/`0x20` ×8) — extends the fixed +4-apart set from `{12,16,20,24,28,32}` to `{12,16,20,24,28,32,36}`, still no exceptions. (Coincidentally equal to the fixed corrupted month value, `36`, in this one instance — not itself significant, just the next step in the existing arithmetic progression.) +- `invalid seconds value`: 236 occurrences, distribution `{60:58, 61:40, 89:40, 90:58, 91:40}` — exactly the established set, no new outliers this window (unlike 2026-09-08's `67`). +- `Controller status too short, discarding` fired once (`04:46:08` UTC) — 5th instance of this rare truncated-frame WARN, still too infrequent to characterize. +- Frame-FIFO counters (`frame_backlog_events_`, `frame_overflow_events_`) stayed at 0 throughout — the `7e8044f` fix continues to hold. +- Three arm/disarm sequences this window — full detail and the retry data point in `arm_disarm_state_machine.md`'s 2026-09-09 update. Summary: two quick remote-fob-triggered arm+disarm cycles (`23:23:41`–`23:25:00` on 09-08, `02:11:49`–`02:12:30` on 09-09, both instant/no-retry, both bus-clean nearby) and one integration-initiated cycle (`arm_away()` at `03:48:43`, instant; `disarm()` at `04:43:55`, **2/6 retries**) — the retry is the first integration-initiated disarm retry observed since the `CURRENT_TIME`-correlation was abandoned (2026-09-07), and it lands ~5 minutes after the `04:37:40` corruption-burst/watchdog-trip/triple-rebroadcast episode above, the first candidate "recent bus disruption" data point for the reopened retry question. + +**Inference (medium confidence):** the poll-slot/watchdog mechanism and the day/month arithmetic progression both continue exactly as established, no revision needed. The minutes-since-midnight periodicity is now high-confidence. The retry/bus-disruption timing link is a single data point (~5 min gap, not concurrent) — suggestive enough to record and watch for, not yet enough to call a pattern; see `arm_disarm_state_machine.md` for the reasoning on why it's not concurrent-strength evidence. + +**Practical takeaway:** no code change. Next window should start from 2026-09-09 05:09 UTC. Keep watching for: any exception to the now-9/9 poll-slot/watchdog correlation; further extension of the day/month `+4` set past `36`; whether the minutes-since-midnight fault ever lands off the `11:2x` UTC window (would falsify strict daily periodicity); and further disarm retries to test whether a recent corruption/watchdog episode keeps showing up nearby. + +### Update (2026-09-10): the `invalid day/month value */36` set isn't a fixed-marginal-bit progression — it's the panel's real calendar date read through a consistent `×4` corruption multiplier, caught transitioning live across local midnight + +**Source:** the frigate long-term logger, `crow-alarm.log`/`crow-alarm.log.1`, window 2026-09-09 05:09 → 2026-09-10 04:55 UTC (~23h47m, no reboot/OTA in-window). + +**Findings (observed facts):** the `invalid day/month value` fault fired 37 times this window — 9× `36/36` (05:09–11:59 UTC) then, after a gap, 28× `40/36` (14:39 UTC onward) — the **first time this fault's day value has been observed changing within a single monitoring window** rather than only between separately-dated checks. The transition is tightly bracketed: the last `36/36` sample is at `11:59:10` UTC, and the panel's own (correctly-decoded, valid) `CURRENT_TIME` broadcasts show the real local date rolling over from Wednesday 2026-09-09 to Thursday 2026-09-10 at exactly `11:59:55` UTC (`Controller time update: Thursday 2026-09-10 00:00:00` — local midnight = `12:00:00` UTC, NZST). The first post-rollover fault sample, at `14:39:10`, already reads `40/36`. `36 = 9×4` (September = the 9th month, and the fault occurred while the real day-of-month was 9) and `40 = 10×4` (the day-of-month immediately after rollover) — both endpoints match a `real_value × 4` relationship exactly. + +Re-checked against the fixed-marginal-bit progression tracked since 2026-09-03 (`{12,16,20,24,28,32,36}`, one new value added roughly once per calendar day/session): every value in that set equals `4 ×` the real day-of-month that was current during the session window it was first observed in (`12=4×3`/Sept 3, `16=4×4`/Sept 4, `20=4×5`/Sept 5, `24=4×6`/Sept 6, `28=4×7`/Sept 7, `32=4×8`/Sept 8, `36=4×9`/Sept 9) — the "+4 per day" pattern was never an independent arithmetic progression, it was one-sample-per-real-day of this same `×4` relationship, previously under-sampled. + +The fixed corrupted *month* value, `36`, fits the identical formula: `36 = 4×9`, and every observation to date falls within September (month 9) — i.e. the month byte was never "stuck," it has been correctly reading `9` (real September) the whole time, corrupted by the same `×4` multiplier as the day byte, and just hadn't had an opportunity to visibly change because the entire multi-week observation period so far has stayed within one calendar month. + +Mechanistically, this ties directly into the already-documented "recovered doubled-bit glitch" (the *recoverable* case in `crow_alarm_panel.cpp`, `day = data[4]/2` when both `data[4]` and `data[5]` are even and halve into valid ranges): a real day/month `×4`-corrupted pair is *also* evenly divisible by 2 (`36/2=18`, `40/2=20`), so the existing recovery code's halving step gets it only halfway there — `rec_month = 18` fails the `1–12` validity check (since real month × 4 / 2 = real month × 2, which exceeds 12 for any month ≥ 7) and recovery correctly bails out to the raw-value WARN path. This is the same "double-halving" shape flagged as a one-off oddity in the `logs-35` entry (2026-09-03) and confirmed as a repeating pattern (2026-09-05) — both were this `×4` mechanism, just not yet identified as such. + +**Inference (high confidence):** the day field of this fault variant is `real_day_of_month × 4`; the month field is `real_month × 4`. This is confirmed at high confidence for *day* (live-caught transition, both endpoints matching exactly) and medium-high confidence for *month* (consistent with every sample to date, but untested against an actual month change — the whole dataset has been within September). **Testable prediction:** the corrupted month value should become `40` (`4×10`) when the real calendar rolls into October; if it instead stays `36` or does something else, that would disprove the month half of this theory without touching the day half. + +**Practical takeaway:** no code change — `CURRENT_TIME` still isn't published to any entity, and the existing recovery/discard logic already handles this correctly regardless of the underlying arithmetic (it discards any day/month/year that doesn't halve into a valid, weekday-consistent date, which this fault correctly never does). This is documented because it resolves what `protocol_investigations.md` had been treating as an open "why does month stay fixed at exactly 36" mystery (2026-09-05 entry) into a fully explained, predictable relationship — the "fixed marginal bit" framing used in every entry from 2026-09-03 through 2026-09-09 is superseded by this `×4` explanation, though no prior entry needs correcting since the raw data itself was always reported accurately. Flag for whoever checks logs around 2026-10-01: confirm whether the month value flips to `40`. + +Other signatures this window, all continuing established patterns with no exceptions: + +- **Poll-slot/watchdog:** exactly 1 instance — an `ff.`/`fe.` burst (1 `fe.` + 9 `ff.` lines, `00:33:40.471`–`00:33:42.258` UTC) landing in `[ESPHome Keypad]`'s poll slot (confirmed absent from the following poll cycle), followed by a single "No ping for 60 s" trip for that same keypad at `00:34:25` (~43–45s later). Extends the correlation to **10/10**, still zero exceptions. One additional isolated `fe.` line (`05:17:55` UTC, outside any keypad's poll slot per the surrounding cycle) produced no trip, consistent with the established "isolated lines are harmless, only slot-aligned bursts trip the watchdog" distinction. +- **`invalid minutes-since-midnight`:** 5th consecutive daily episode, again `11:25:55`–`11:27:40` UTC (2026-09-09), same 8-occurrence/`1470`→`1503` shape as the prior four days. Daily periodicity now 5/5. +- **`ff.`/`fe.` background rate:** 11 lines total (9 `ff.` + 2 `fe.`) in ~23h47m ≈ 0.46/h — on the low end of, but within, the established ~0.46–0.94/h post-fix range. +- **`CURRENT_TIME` `31/16`-style persistent stuck state:** zero occurrences (still last seen self-clearing 2026-09-01). +- **Truncated-frame WARNs:** 1 (`Controller status too short, discarding`, `07:56:44` UTC) — still too rare to characterize. +- **Frame-FIFO health:** zero `Frame completed while previous still queued` / `Frame queue overflow` log lines — counters stayed at 0 throughout, `7e8044f` fix still holding. +- **Arm/disarm activity:** one integration-initiated disarm (`04:12:43` UTC, via `ESPHome Keypad`, digit sequence + ENTER) completed on the **first attempt, no retry**, with no bus corruption or watchdog activity anywhere nearby — consistent with, not revising, the existing understanding (disarms succeed cleanly absent nearby disruption). One physical-keypad-initiated arm (`18:40:22`, `AAP Keypad`, ENTER+ARM keys), instant. Two additional `Disarmed` broadcasts (`12:08:25`, `13:59:55`) had no preceding `Arming` or keypress/command context in-window and are almost certainly duplicate `ARMED_STATE` rebroadcasts of an already-disarmed state (the same phenomenon noted in the 2026-09-09 entry above, one coinciding with an `IP Keypad` registration re-announce) rather than fresh disarm events — not counted as retry data points. No new evidence either way for the reopened corruption-proximity retry question. +- Today's earlier RF-remote scripted test session (`04:17`–`04:18` UTC) falls inside this window but is already fully written up separately above (2026-09-10 RF-remote entries) — not re-covered here. + +**Practical takeaway:** no code change. Next window should start from 2026-09-10 04:55 UTC. Keep watching for: the month-value prediction above (expect `40` after the October rollover, a ways off yet); any exception to the now-10/10 poll-slot/watchdog correlation; and another integration disarm retry to keep testing the corruption-proximity question. + +## RF remote (`0x7C`) button-press event — investigation thread + +### Update (2026-09-09, follow-up): the two remote-triggered sequences both carry a previously-unseen `Unknown [7c...]` packet pair, exclusively — new unlabeled type documented in `protocol_wire_format.md` + +**Source:** re-checked ~3 days of frigate capture (`crow-alarm.log.2.gz`/`.1`/current) around all arm/disarm events after the user flagged that an `Unknown` log line might be the RF remote's chime. + +**Findings (observed facts):** a type `0x7C` frame — never seen before in any prior session or doc — appears exactly 8 times across the whole ~3-day sample, all 8 clustered into the two remote-triggered arm/disarm cycles from the entry above (2 lines per arm, 2 per disarm, ~0.6–0.7s apart per pair). It does **not** appear at any of the several physical-keypad or integration-initiated arm/disarm events in the same window — a clean 8/8-vs-0/many split. Full byte-level breakdown and the arm/disarm-distinguishing `+4`-offset fields are in `protocol_wire_format.md`'s new `0x7C` entry — read that directly rather than this summary. + +**Inference (medium confidence on correlation, low on mechanism):** given the perfect exclusivity to remote-triggered events, `0x7C` is very likely tied to whatever hardware handles the RF remote (probably a receiver module wired into the panel outside the normal keypad-address scheme) reporting the arm/disarm event — plausibly what drives the chime's beep count, though the packet itself doesn't obviously encode "1 vs 2 beeps" (one arm-flavored pair, one disarm-flavored pair, not a variable-length or variable-count structure). Not yet decoded beyond that. + +**Practical takeaway:** no code change — not keypad-address-scoped, no entity to attach it to. Worth capturing a few more remote-triggered cycles (different dates, and `arm_stay` if the remote supports it) to pin down what the per-cycle-stable trailing byte (`DE` vs `BE`, one value per day observed so far) actually tracks. + +### Update (2026-09-09, second follow-up): the real chime signal is likely `OUTPUT_STATE` (0x50) Output 1 — pulses once on remote-triggered arm, twice on remote-triggered disarm, and does neither for keypad/integration events + +**Source:** full (non-`Unknown`) log context around all four remote-triggered event boundaries from the two updates above, compared against the surrounding `03:48:43`/`04:43:55` integration cycle and two physical-keypad cycles (`2026-09-08 04:05:43`/`04:06:11` arm, `05:16:33` disarm) in the same capture. + +**Findings (observed facts):** already-documented `OUTPUT_STATE` (0x50) broadcasts for Output 1 (`protocol_wire_format.md` — bit 0 of the output bitmap) briefly pulse `0 → 1 → 0` exactly once at each remote-triggered arm, and `0 → 1 → 0 → 1 → 0` (two full pulses, each ~150–260ms) at each remote-triggered disarm — in both observed cycles, with no exceptions: + +| Event | Output 1 transitions (relative to the ARMED_STATE broadcast) | +| --- | --- | +| Arm, seq 1 (23:23:41) | `01` at +0ms, `00` at +102ms — 1 pulse | +| Disarm, seq 1 (23:25:00) | `01` +41ms, `00` +202ms, `01` +382ms, `00` +643ms — 2 pulses | +| Arm, seq 2 (02:11:49) | `01` +23ms, `00` +199ms — 1 pulse | +| Disarm, seq 2 (02:12:30) | `01` +37ms, `00` +195ms, `01` +451ms, `00` +597ms — 2 pulses | + +Checked the same field across the integration-initiated cycle (`arm_away()` 03:48:43, `disarm()` 04:43:55) and two physical-keypad cycles (`04:05:43`/`04:06:11`, `05:16:33`) in the same capture: `OUTPUT_STATE` stays flat at `00` throughout every one of them — no pulse at all, on either arm or disarm, for any non-remote-triggered event. + +**Correction:** Output 1 on this installation is the **external siren** and Output 2 is the **internal siren** (confirmed by the user), not a dedicated buzzer/chime relay — updated in `protocol_wire_format.md`'s `0x50` entry alongside the existing Output 4/garage-door mapping. Rechecked the raw bitmap values at all four pulse events: only bit 0 (`0x01`) ever appears — the value alternates strictly between `00` and `01`, never `02` or `03` — so Output 2 (internal siren) does **not** chirp; only the external siren does. + +**Inference (medium-high confidence):** Output 1's pulse count still matches the user-confirmed chime count exactly (1 arm / 2 disarm) and is completely absent for every other trigger source observed — a much stronger and independently-decodable correlate than the `0x7C` packet from the update above (whose payload doesn't obviously vary between arm and disarm the way a 1-vs-2 count would). With Output 1 identified as the external siren, the mechanism is now a brief siren chirp used for audible confirmation — a common pattern on alarm panels for RF-remote feedback specifically, since (unlike a keypad) the remote has no local buzzer or display of its own to confirm the command landed. Whether this is fixed factory behavior or a programmable controller option (e.g. an "exit/entry chirp by fob" setting) specific to how this panel is configured isn't established either way — not something the bus traffic alone can distinguish. That would also explain why physical-keypad and integration-initiated events never pulse it: those already have their own confirmation path (keypad buzzer, or the integration's own state feedback) and don't need the siren to chirp. Not yet established whether `0x7C` and the siren chirp are cause-and-effect (controller reacts to `0x7C` by chirping the siren) or two independent effects of the same underlying remote-triggered arm/disarm. + +**Practical takeaway:** no code change — Output 1 is a normal, already-parsed `OUTPUT_STATE` field; nothing new to add to the parser. Worth flagging to the user: since this pulses the *external siren* specifically (internal siren, Output 2, never joins in), any future feature that reacts to Output 1 activity (e.g. a "siren active" binary sensor) needs to expect these brief chirps as normal remote-driven noise, not a genuine alarm condition — a naive "Output 1 = alarm sounding" mapping would misfire on every remote-triggered arm/disarm. Next remote-triggered capture should confirm the 1-pulse/2-pulse pattern holds a 3rd time, and check whether `arm_stay` (if the remote supports it) produces a different pulse count than `arm_away`. + +### Update (2026-09-10): scripted two-remote button test decodes all four RF remote buttons — arm/disarm/gate/garage, each with its own `0x7C` code and confirming `OUTPUT_STATE` pulse + +**Source:** the user ran a deliberate test sequence on both of their RF remotes back-to-back (button 1 arm, button 2 disarm, button 3 ×3, button 4 ×3, then the same sequence on the second remote), captured on the frigate long-term logger, and told Claude which physical function each button number performs: 1 = arm, 2 = disarm, 3 = gate, 4 = garage. + +**Findings (observed facts):** each of the 8 presses per remote (1 arm + 1 disarm + 3 gate + 3 garage = 8, doubled for two remotes = 16 total) produced a pair of `0x7C` lines, matching the pair-per-event pattern from the two updates above. data[0..2] is a fixed per-remote identity — `90 00 36` for one remote, `42 00 C4` for the other — and data[3..4] gives a distinct, remote-specific code per button. Critically, `OUTPUT_STATE` (`0x50`) independently confirms every button/function mapping the user gave: button 1/2 pulse Output 1 (the already-documented external-siren chirp, once on arm / twice on disarm), button 3 pulses **Output 3** (`0x04`, previously undocumented — now added to the `0x50` entry) and is followed within ~1s by a `ZONE_STATE` "Zone 3 active" transition each time, and button 4 pulses **Output 4** (`0x08`), matching the already-documented garage-door relay. Full byte table and examples moved into `protocol_wire_format.md`'s `0x7C` entry (rewritten in place, not appended) — read that directly for the byte-level breakdown, including a reproducible anomaly where button 3's retransmit pair shifts differently (data[5..7]) than the other three buttons, on both remotes. + +**Inference (high confidence):** the button↔function↔output mapping is now solidly established — two physically distinct remotes, each independently confirmed by a second field (`OUTPUT_STATE`) that isn't derived from `0x7C` at all. This retroactively confirms the 2026-09-09 arm/disarm-only finding was a special case of a general "any RF remote button press produces an exclusive `0x7C` pair" mechanism, not something specific to arm/disarm. + +**Practical takeaway:** no code change — same reasoning as the 2026-09-09 entries above (not keypad-scoped, no entity to attach it to). The Output 3 = gate relay mapping is worth remembering for any future "what does this output mean" work, alongside the existing Output 1/2/4 mappings. Open thread: why button 3 (gate) alone breaks the `+N`/`-N` retransmit pattern in `0x7C` data[5..7] — not investigated further this session, flagged in `protocol_wire_format.md` instead of chased down, since it doesn't block anything user-facing. + +### Update (2026-09-10, cont.): `0x7C` precedes the controller's action by ~100–150ms in all 8 button/remote combinations — resolves the cause-vs-parallel-effect question left open on 2026-09-09 + +**Source:** user asked directly whether the `0x7C` frames arrive before the action they correlate with; checked sub-millisecond ordering for one representative press per button/remote combination (8 total, not all 16 physical presses) from the update above. + +**Findings (observed facts):** the first `0x7C` frame of every pair precedes the controller's resulting broadcast/output change, never the reverse: + +| Button | Remote | `0x7C` → action | Delta | +|---|---|---|---| +| 1 arm | A | → `Arming` broadcast | same log ms, `0x7C` logged first | +| 1 arm | B | → `Arming` broadcast | +147ms | +| 2 disarm | A / B | → `Disarmed` broadcast | +133ms / +115ms | +| 3 gate | A / B | → `OUTPUT_STATE` Output 3 pulse | +108ms / +131ms | +| 4 garage | A / B | → `OUTPUT_STATE` Output 4 pulse | +99ms / +98ms | + +**Inference (high confidence):** this directly answers the open question from the 2026-09-09 second-follow-up entry above ("not yet established whether `0x7C` and the siren chirp are cause-and-effect... or two independent effects") — `0x7C` is upstream: the RF receiver hardware reports the button press to the controller, which then acts on it and broadcasts the state change roughly 100–150ms later (one case logged in the same millisecond, `0x7C` still ordered first). Not a parallel/simultaneous echo of an action already decided elsewhere. Written into `protocol_wire_format.md`'s `0x7C` entry as a new "Causality" paragraph. + +**Practical takeaway:** no code change. Closes the last open mechanism question from the RF-remote `0x7C` thread; only the gate-specific retransmit-pattern anomaly (data[5..7]) remains open. + +### Update (2026-09-10, cont.): vendor manual (`ESL-2 Install & Program Manual (E.V).pdf`) confirms the RF-remote attribution and explains why `0x7C` isn't keypad-scoped + +**Source:** the user asked Claude to check the panel's official install/programming manual (`../ESL-2 Install & Program Manual (E.V).pdf`, relative to this repo) for how remotes are integrated, to cross-check the trace-only findings above. + +**Findings (documented facts, not inference):** the manual (pages 17–19, "RX-16 MF349 Remote Upgrade/Learning"; pages 48–54, "User Programming") establishes, as vendor-documented ground truth rather than trace inference: + +- RF is handled by a separate plug-in receiver card (RX-16 MF349), wired via an "ARRI4" cable — the manual states that if this cable is unavailable, the receiver can instead "be wired the same as a keypad," i.e. it shares the keypad clock/data bus. This is the likely reason `0x7C` frames appear in the same wire format as keypad traffic despite not originating from a keypad. +- Remotes are enrolled as **Radio Users** in User slots 21–100 — an entirely separate addressing space from keypad bus addresses. This directly explains the 2026-09-09 observation that no `data[0..2]` byte pattern matches the keypad-address convention: it was never a keypad address to begin with. +- Each 4-button pendant is documented as up to **five independently-learned radio-user identities** — one per function (Arm-only, Disarm-only, "Door 2 Control" linked to Output 3, "Door 1 Control" linked to Output 4, and Panic), each learned separately via its own program address (e.g. `P18E40E`–`P18E49E` for the Arm-only button across pendants 0–9). This structurally explains why `data[3..4]` differs per button even on the same physical remote — every button is its own enrolled radio user, not a sub-code of a single remote identity. +- The manual's "Door 1"/"Door 2" terminology and Output 4/Output 3 linkage matches the 2026-09-10 button 4 (garage)/button 3 (gate) → Output 4/Output 3 findings above exactly, confirming "gate" in this installation is the panel's generic "Door 2 Control" function. +- A fifth pendant function, **Panic** (`P18E80E`–`P18E89E`, triggers internal + external siren; immediate, delayed, or entry-delay-only variants configurable at `P8E`), is documented but has no corresponding `0x7C` sample captured yet. + +**Inference:** none needed for attribution — this section is vendor documentation, promoted from "inference" to "confirmed" in `protocol_wire_format.md`'s `0x7C` entry. The exact on-wire byte layout (data[5..7] retransmit/checksum behavior, the gate-specific anomaly) is not covered by the manual and remains trace-only. + +**Practical takeaway:** no code change — updates `protocol_wire_format.md`'s `0x7C` entry with a new "Manual cross-reference" section and raises its confidence rating. Confirms there's a fifth remote function (Panic) not yet seen on the bus; worth a trace sample if the user is willing to test it, since panic behavior (immediate vs. delayed, entry-delay-only, duress) has real user-facing implications an eventual feature would need to get right. + +### Update (2026-09-10, cont.): manual resolves the last open question from the 2026-09-09 siren-chirp entry — it's a dedicated, programmable "Pendant Chirp" feature (`P50E`–`P53E`), not incidental + +**Source:** continued read of the same manual, "Areas Continued" section (pages 66–67, summarized again at page 113). + +**Findings (documented facts):** the manual has four dedicated program addresses for exactly this behavior: **Pendant Arm Chirp to Output** (`P50E`, "one chirp to the output for arm"), **Pendant Stay Arm Chirp** (`P51E`), **Pendant Disarm Chirp** (`P52E`, "two chirps to the output for disarm"), and **Pendant Stay Disarm Chirp** (`P53E`). Each assigns the chirp to any of Outputs 1–8, pulsed at the `P39E` pulse-time setting; the manual explicitly states the reason it exists at all: *"When Arming the alarm using a Radio Key it is necessary to have some form of Arm indication"* — i.e. a radio pendant has no local buzzer or display, so the panel is the one giving audible feedback, exactly as guessed in the entry above. It also confirms the exact 1-chirp/2-chirp split independently designed into the panel (not inferred from chime count): arm = one chirp, disarm = two chirps. The same page also documents a related-but-distinct **Arm/Disarm Pulse to Output** (`P54E`–`P57E`, single pulse, no chirp count semantics) for things like triggering a video recorder — a different config option that would produce single-pulse `OUTPUT_STATE` activity with no chirp-count meaning, worth keeping in mind if a future output ever pulses without matching this arm=1/disarm=2 pattern. + +**Inference:** none needed — this is the vendor's own documented mechanism name, matching the trace behavior exactly. Promotes the 2026-09-09 "Inference (medium-high confidence)" siren-chirp finding to confirmed: it is the panel's `P50E`/`P52E` Pendant Chirp feature, output-assignable and enabled on this installation to Output 1 (the external siren). + +**Practical takeaway:** no code change — updates the "Whether this is fixed factory behavior or a programmable controller option... isn't established either way" line from the 2026-09-09 entry above: it's now known to be the latter, a programmable option (`P50E`–`P53E`), confirmed enabled to Output 1 on this panel. Doesn't change any parsing, since `OUTPUT_STATE` was already correctly decoded — this only firms up the *why*. + +## `CURRENT_TIME` daily periodicity investigation — what triggers the `invalid minutes-since-midnight` episode at the same wall-clock window every day + +### Update (2026-09-10, cont.): manual's Automatic Test Call feature is a plausible (unconfirmed) trigger for the daily `invalid minutes-since-midnight` episode — the first candidate mechanism for the "what happens near 11:26 UTC" question open since 2026-09-05 + +**Source:** user asked whether the manual documents any panel-initiated self-tests (battery check, walk test, etc.) that could disturb the keypad bus. Checked the "Diagnostic & Default Options" and "Dialler" sections (pages 92–96, 107–127) for anything periodic or automatic — most diagnostics there (Walk Test Mode `P200E6E`, RSSI read `P200E14E`, EEPROM read/write, factory-default restores) are installer-triggered one-off actions, not spontaneous/periodic, so don't fit a *daily* trigger. One candidate does fit: the dialler's **Automatic Test Call** (`P175E4E` Test Call Start Time, `P175E5E` Test Call Time Period, default 24 hours) — a scheduled daily call to the monitoring station to verify line/panel integrity, reported via Contact ID (`P195E10E` "Automatic Test" 4+2 code) or SIA. The manual's own worked example for the start-time field picks a value deliberately chosen to fall in a "quiet period... (eg 2300)". + +**Findings (not yet confirmed, flagging as a hypothesis):** the `invalid minutes-since-midnight` fault's now-5/5-established daily window, `11:25:55`–`11:27:40` UTC, is `23:25:55`–`23:27:40` NZST (UTC+12) — within half an hour of the manual's own illustrative `2300` test-call example. The dialler and keypad-bus interface are different physical channels (phone line vs. two-wire clock/data bus), so there's no *direct* protocol link, but a plausible mechanism exists: if the panel's single MCU handles DTMF/modem tone generation for the outbound test call via bit-banging or a blocking routine, that could starve or jitter the timing-sensitive keypad-bus ISR/poll loop for long enough to produce exactly this kind of periodic bit-corruption glitch — consistent with the fault's already-documented root cause (a single spurious bit shifting frame alignment, see the `CURRENT_TIME` entry in `protocol_wire_format.md`) and its short (~105s), clean, self-clearing shape (a call attempt completing, not a persistent fault). + +**Confidence:** low-medium. This is circumstantial (a ~30min-off illustrative example value from the manual, not this installation's actual configured `P175E4E` setting, which isn't known) plus a plausible-but-unverified mechanism (MCU contention between dialler and bus timing) — not a confirmed cause. It is, however, the first candidate mechanism proposed for a question every dated entry since 2026-09-05 has explicitly left open ("the underlying trigger... is still unidentified"). + +**Practical takeaway:** no code change — this doesn't change how the fault is handled (already correctly discarded, not user-facing). Worth checking directly if the user has installer access to the panel: read `P175E4E` (Test Call Start Time) and see whether it's set anywhere near `23:25`–`23:28` local. If confirmed, this closes the "why does it happen at this specific time" thread outright; if the configured time doesn't match, this hypothesis is disproven and the trigger remains genuinely unknown. Either outcome is useful — record it next time the panel's installer-mode settings are checked for any reason. + +**Follow-up (2026-09-10, same day): hypothesis disproven, and doubly so.** User checked `P175E4E` directly on the physical LCD keypad — the panel's configured Test Call Start Time is `02:00` (NZST), not anywhere near `23:25`–`23:28`. On top of that, the user believes the dialler itself (`P175E1E` Option 1, "Dialler is Enabled") is not active at all — no monitoring service/phone line in use on this installation — so even the `02:00` value is a vestigial default that never actually fires a call. This rules out the Automatic Test Call as the trigger for the daily `invalid minutes-since-midnight` episode on two independent grounds (wrong time, *and* the feature isn't even running). `02:00` NZST = `14:00` UTC doesn't line up with any other currently-documented daily-timed signature either (checked against this file and `arm_disarm_state_machine.md` — no match). The "what happens near `11:26` UTC daily" question reverts to fully unidentified, with the dialler-contention mechanism ruled out specifically — worth remembering not to re-propose that particular explanation, including any dialler-related mechanism generally (test calls, DTMF, modem tones), since the dialler isn't believed to be active on this panel at all. If a future session wants another candidate, look elsewhere in the panel's periodic/scheduled behaviors (e.g. the radio-detector supervised-timer check-in cycle, `P25E4E`, default 240 min — divides evenly into a once-daily period at the default (240 × 6 = 1440 min), so phase/configuration is the open question, not periodicity — worth a look if it's been reconfigured). diff --git a/components/crow_alarm_panel/docs/protocol_wire_format.md b/components/crow_alarm_panel/docs/protocol_wire_format.md index d852698..64e97ef 100644 --- a/components/crow_alarm_panel/docs/protocol_wire_format.md +++ b/components/crow_alarm_panel/docs/protocol_wire_format.md @@ -376,7 +376,15 @@ semantics are unknown. Variant A is the normal operational poll. | 0 | 1 | `output_bitmap` | Bit N-1 = output N active | High | Output numbering matches the zone bitmap convention (bit 0 = output 1). -Output 4 (garage door relay) = `0x08`. +Output 1 (external siren) = `0x01`. Output 2 (internal siren) = `0x02`. +Output 3 (gate relay) = `0x04`. Output 4 (garage door relay) = `0x08`. + +The single-pulse-per-arm / double-pulse-per-disarm burst seen on RF-remote-triggered +events (see the `0x7C` entry below, and `protocol_investigations.md`) is a vendor-documented, +output-assignable panel feature — "Pendant Arm/Disarm Chirp to Output" (`P50E`–`P53E` in the +ESL-2 manual) — confirmed enabled to Output 1 on this installation, not incidental behavior. +A separate single-pulse-no-chirp-count option also exists (`P54E`–`P57E`, e.g. for triggering +a video recorder); an output pulse that doesn't fit the arm=1/disarm=2 pattern may be this. **Examples:** ``` @@ -418,9 +426,24 @@ alignment by one position for the rest of the frame — for `day`/`month`/`year` of those three bytes being doubled. It recurs deterministically once per minute, at the `seconds = 15` broadcast. See `protocol_investigations.md` ("`CURRENT_TIME` (0x54) periodic bit-corruption glitch") for the full -byte-level analysis. All fields must be validated individually before use, -and corrupted frames should be discarded rather than corrected (a doubled -value can coincidentally land back in a valid range). +byte-level analysis. Naive per-field range validation alone isn't enough — a doubled +value can coincidentally land back in a valid range — so the implementation only +"corrects" this specific known glitch (halve day/month/year, then cross-check the +recovered date's weekday against the frame's own untouched weekday byte before trusting +it) and discards the frame outright if that cross-check fails. Any other corruption not +matching this exact recovered-and-verified pattern is discarded, not guessed at. + +A related but distinct variant exists: `day`/`month` corrupted by a `×4` (not `×2`) +multiplier. Confirmed (2026-09-10) as `real_value × 4`, not arbitrary garbage — see +`protocol_investigations.md`'s 2026-09-10 update for the live midnight-crossing capture +that pins this down. Every occurrence observed so far has had `real_month ≥ 7` +(September in the confirming capture), where the single-halving recovery above computes +`rec_month = real_month × 2`, which is `>12` and so out of range — the frame is correctly +discarded rather than silently mis-recovered. For `real_month ≤ 6` this range check alone +would *not* catch it (`rec_month` would land in-range but wrong); only the weekday +cross-check would have a chance of rejecting it, and only probabilistically (~1/7). This +case hasn't been observed in any capture yet — flagged here as a theoretical gap in the +recovery logic's guarantees, not a confirmed live bug. **Verified example:** ``` @@ -431,6 +454,66 @@ value can coincidentally land back in a valid range). --- +### 0x7C — RF remote button-press event + +*Direction:* RF receiver card → Controller (confirmed by the causality analysis below; not a keypad address — see the manual cross-reference below for why `data[0..2]` never matches the keypad-address convention) +*Trigger:* A button press on one of the official RF remotes — never observed for any physical-keypad or integration-initiated command +*Min length:* 5 payload bytes (`data[0..2]` identity + `data[3..4]` button code — all the parser decodes; 8 bytes seen in practice in every capture) +*Confidence:* Confirmed on the RF-remote attribution and on which button was pressed (vendor manual, cross-checked below against four independent trace-derived signals per button); low on the exact byte-level encoding mechanism + +**Manual cross-reference (`ESL-2 Install & Program Manual (E.V).pdf`, pages 17–19, 48–54):** the panel's RF path is a separate plug-in receiver card, the RX-16 MF349, connected via the "ARRI4" cable — the manual notes explicitly that if this cable is unavailable, "you can wire the receiver the same as a keypad," i.e. the receiver rides the same physical clock/data bus as keypads and presumably reuses the same frame format, which is why `0x7C` shows up as a normal-looking frame despite not coming from a keypad. Remotes are enrolled as **Radio Users** in User slots 21–100 — a completely different addressing space from keypad bus addresses — which is *why* `data[0..2]` never matches the keypad-address convention: it isn't a malformed/omitted keypad address, radio users are categorically not keypads. Each physical 4-button pendant is manual-documented as up to **five separate learned radio-user identities**, one per function class, each with its own program-address block and independent "press the button you wish to learn in" enrollment step: Arm-only (`P18E40E`–`P18E49E` for pendants 0–9), Disarm-only (`P18E50E`–`P18E59E`), **Door 2 Control, linked to Output 3** (`P18E60E`–`P18E69E`), **Door 1 Control, linked to Output 4** (`P18E70E`–`P18E79E`), and Panic (`P18E80E`–`P18E89E`). This structurally explains why `data[3..4]` differs per button even on the *same* physical remote (observed below): each button isn't a sub-code of one remote identity, it's independently enrolled as its own radio user. It also independently confirms the output mapping found by trace: "Door 1" (garage, Output 4) and "Door 2" (Output 3 — wired to the user's gate in this installation, but generically named "Door 2" by the panel) match our button 4/button 3 findings exactly. The manual doesn't document `0x7C`'s on-wire byte layout (it's user/installer-facing, not a protocol reference) — the retransmit-pattern and checksum-byte details below remain trace-only. + +**Observed facts (2026-09-09, frigate long-term logger, [[project-crow-alarm-protocol-trace]]):** across ~3 days of continuous capture spanning two remote-triggered arm/disarm cycles (confirmed by the user via the remote's distinct chime — one beep on arm, two on disarm), exactly 8 `Unknown [7c...]` lines appeared, and *only* at those two cycles — never at any physical-keypad or integration-initiated arm/disarm event in the same capture. + +**Observed facts (2026-09-10 follow-up, scripted two-remote capture, [[project-crow-alarm-protocol-trace]]):** the user ran a deliberate test sequence on both of their RF remotes — button 1 (arm), button 2 (disarm), button 3 ×3 (gate), button 4 ×3 (garage) — repeated once per remote. Each press produces a pair of near-identical `0x7C` lines ~0.5–0.8s apart (the bus's usual same-event retransmit-for-reliability pattern seen elsewhere, e.g. `KEYPAD_COMMAND` bursts). data[0..2] is a fixed per-remote identity tuple — `90 00 36` for remote A, `42 00 C4` for remote B — constant across every button on that remote and never seen from the other remote. data[3..4] identifies the button, but the value is per-remote (not a shared code across remotes): + +| Button | Remote A (`90 00 36`) data[3..4] | Remote B (`42 00 C4`) data[3..4] | +|---|---|---| +| 1 — arm | `BC F6` | `7C ED` | +| 2 — disarm | `C0 FA` | `00 FB` | +| 3 — gate | `B4 EE` | `F4 EE` | +| 4 — garage | `84 3E` | `C4 3E` | + +``` +04:17:41 7c 90 00 36 BC F6 45 DC F6 remote A, arm +04:17:42 7c 90 00 36 BC F6 49 D8 F6 remote A, arm, retransmit +04:17:47 7c 90 00 36 C0 FA 46 CC EE remote A, disarm +04:17:47 7c 90 00 36 C0 FA 4A C8 EE remote A, disarm, retransmit +04:17:50 7c 90 00 36 B4 EE 43 7C DD remote A, gate, press 1 +04:17:51 7c 90 00 36 B4 EE 25 7C EE remote A, gate, press 1, retransmit +04:18:04 7c 90 00 36 84 3E 47 BC CF remote A, garage, press 1 +04:18:05 7c 90 00 36 84 3E 4B B8 CF remote A, garage, press 1, retransmit + +04:18:33 7c 42 00 C4 7C ED 8B B8 EB remote B, arm +04:18:36 7c 42 00 C4 00 FB 46 CC F5 remote B, disarm +04:18:41 7c 42 00 C4 F4 EE 43 7C F3 remote B, gate, press 1 +04:18:53 7c 42 00 C4 C4 3E 47 BC EE remote B, garage, press 1 +``` + +**Byte-level pattern (observed, semantics not established):** + +- data[0..2] — fixed per-remote identity, see above. +- data[3..4] — per-remote-per-button code (see table above). Not a shared code across remotes and not obviously derived from the remote's identity tuple by any simple transform (XOR, bit-reverse, or addition tried, none match) — consistent with a hardware encoder chip whose per-button output happens to differ between physical units, not a documented protocol field. +- data[5..6] — for buttons 1 (arm), 2 (disarm), and 4 (garage), shifts by a small `+N`/`-N` between the initial send and its retransmit (e.g. `45 DC → 49 D8`, `+4`/`-4`; remote B's arm shows `+8`/`-8` over a longer ~0.75s gap) — plausibly a coarse counter ticking during the retransmit gap, roughly consistent in rate across both remotes and both offsets. Button 3 (gate) breaks this pattern on both remotes: data[5] shifts by a much larger step (`43 → 25`, `-30`) while data[6] stays unchanged (`7C → 7C`) — not yet understood why gate's retransmit encodes differently from the other three buttons. +- data[7] — checksum-like trailing byte. For buttons 1, 2, and 4 it stays identical between the initial send and its retransmit; for button 3 (gate) it changes within the pair too, on both remotes — the same buttons/pattern split as data[5..6] above. + +**Inference (high confidence on attribution and per-button identification):** four independent buttons on two separate remote units all show the same signature: an exclusive `0x7C` pair, occurring only when that specific button is pressed, on top of the corroborating `OUTPUT_STATE` (`0x50`) evidence below — reproduced identically across two physically distinct remotes rules out coincidence. The `+N`/`-N` vs. gate's different retransmit pattern (medium confidence, mechanism unknown) suggests gate's button encoding on the remote itself works differently from the other three, not a receiver-side artifact, since it's consistent across both remotes. + +**Causality (high confidence, resolves the previously-open question):** the first `0x7C` frame of each pair precedes the controller's resulting action (the `ARMED_STATE`/`Disarmed` broadcast, or the `OUTPUT_STATE` pulse) in all 8 button/remote combinations checked (both remotes × all 4 buttons; one representative press per combination, not all 16 physical presses from the scripted test) — never simultaneous-or-after. Measured deltas range from +98ms to +147ms, with one exception (Remote A's arm case landed in the same logged millisecond, `0x7C` still ordered first in the log). `0x7C` is therefore the RF receiver reporting the button press *to* the controller, which then acts on it roughly 100ms later — a cause, not a parallel echo of an action already taken. + +A second, independent signal confirms each button-to-function mapping: `OUTPUT_STATE` (`0x50`) pulses the output that function drives, every time, for every press, on both remotes: + +| Button | `OUTPUT_STATE` pulse | Notes | +|---|---|---| +| 1 — arm | Output 1 (`0x01`), once | External siren chirp — see `protocol_investigations.md` 2026-09-09 | +| 2 — disarm | Output 1 (`0x01`), twice | External siren chirp | +| 3 — gate | Output 3 (`0x04`), once per press | Also followed within ~1s by a `ZONE_STATE` "Zone 3 active" transition each time | +| 4 — garage | Output 4 (`0x08`), once per press | Matches the already-documented garage-door relay mapping (`0x50` above) | + +**Practical takeaway:** no code change — not a keypad-address-scoped message, doesn't fit any existing entity, and the manual confirms this is fundamental (radio users, not keypads). The button-to-output mapping (arm/disarm → Output 1 siren, gate/"Door 2" → Output 3, garage/"Door 1" → Output 4) is now vendor-confirmed and reusable for any future "what did the remote do" feature. A fifth pendant function, Panic, is documented (`P18E80E`–`P18E89E`, triggers internal+external siren, with immediate/delayed/entry-delay-only variants at `P8E`) but not yet observed on the bus — worth a trace if a panic-button `0x7C` sample becomes available. Still open: the gate-specific retransmit-pattern anomaly in data[5..7], and whether `arm_stay` (if either remote supports it) produces a distinct data[3..4] code. + +--- + ### 0xA0 — KEYPAD_REGISTRATION *Direction:* Keypad → controller