fix(transport): handle CMD_WTX wait-extension frames, don't misread them as replies

The firmware sends an async CMD_WTX ("wait N ms") control frame on FPGA bitstream
reload (fpgaloader.c: send_wtx(FPGA_LOAD_WAIT_TIME=1500)). The first HF command after
connect triggers the HF-bitstream load, so a WTX frame lands before the real reply.
Our read loops skipped only DEBUG_PRINT_* frames, so they returned the WTX frame as
the command reply -- leaving the real reply pending and permanently desyncing every
later read (each command then got the *previous* command's response).

This was the root cause of the intermittent "15693 garbage/shift" reads. ping (no
bitstream load) and well-coupled 14a were unaffected, which is why it looked
RF/coupling-specific -- it never was, and it is not a firmware bug: the firmware
behaves correctly and the C client already handles WTX (comms.c). pm3py just was not
a spec-compliant client.

Mirror the C client: on CMD_WTX, add the wtx value to the wait and keep reading.
Applied to both read_response and _read_any_response.

Verified on hardware: an ICODE SLIX GET_SYSTEM_INFO/READ stress went from 100% anomaly
(permanent shift) to 0% (187/187 correct). Adds a regression test.

Co-Authored-By: Claude Opus 4.8 <noreply@anthropic.com>
This commit is contained in:
michael
2026-07-16 12:15:06 -07:00
parent 6ab8582308
commit c675f6b278
2 changed files with 41 additions and 2 deletions

View File

@@ -23,6 +23,20 @@ _ASYNC_FRAME_CMDS = frozenset({
_MAX_ASYNC_SKIP = 64 # bound the skip loop so a chatty/looping device can't hang a read
def _wtx_ms(resp) -> int | None:
"""Waiting-Time-eXtension value (ms) if ``resp`` is a CMD_WTX control frame, else ``None``.
The firmware emits CMD_WTX to ask the host to *keep waiting* — notably on FPGA bitstream
reload (``send_wtx(FPGA_LOAD_WAIT_TIME)``, 1500ms), which the first HF command after connect
triggers. It is NOT a command reply. The C client extends its response timeout by this value
and reads on (comms.c). pm3py must do the same: otherwise the WTX frame is returned as the
reply, and — because every later read then grabs the *previous* command's response — one WTX
permanently desyncs the whole session (the bug behind the '15693 garbage/shift' reports)."""
if resp.cmd == Cmd.WTX and len(resp.data) >= 2:
return struct.unpack_from("<H", resp.data)[0]
return None
def _crc_to_wire(crc: int) -> int:
"""Byte-swap CRC to match PM3 wire format: (low << 8) | high."""
return ((crc & 0xFF) << 8) | ((crc >> 8) & 0xFF)
@@ -211,9 +225,10 @@ class PM3Transport:
as the reply — the cause of garbage sample counts and desynced downloads."""
if not self._reader:
raise PM3Error("Not connected")
extra = 0.0 # accumulated WTX wait-extension (seconds)
for _ in range(_MAX_ASYNC_SKIP):
try:
raw = await asyncio.wait_for(self._read_response_frame(), timeout=timeout)
raw = await asyncio.wait_for(self._read_response_frame(), timeout=timeout + extra)
except asyncio.TimeoutError:
self._resync_needed = True # late response would desync the next read — drain it
raise PM3Error("Response timeout", status=-4)
@@ -221,6 +236,10 @@ class PM3Transport:
resp = PM3Response.from_dict(decode_response_frame(raw))
except ValueError:
continue # malformed frame — resync on the next magic
wtx = _wtx_ms(resp)
if wtx is not None:
extra += wtx / 1000.0 # device asked to wait longer — keep reading
continue
if resp.cmd in _ASYNC_FRAME_CMDS:
continue # device debug output — not our reply
return resp
@@ -364,9 +383,10 @@ class PM3Transport:
"""Read one NG-or-OLD frame, skipping async debug-print frames (as read_response does)."""
if not self._reader:
raise PM3Error("Not connected")
extra = 0.0 # accumulated WTX wait-extension (seconds)
for _ in range(_MAX_ASYNC_SKIP):
try:
raw = await asyncio.wait_for(self._read_any_frame(), timeout=timeout)
raw = await asyncio.wait_for(self._read_any_frame(), timeout=timeout + extra)
except asyncio.TimeoutError:
self._resync_needed = True # late response would desync the next read — drain it
raise PM3Error("Response timeout", status=-4)
@@ -380,6 +400,10 @@ class PM3Transport:
data=d["data"], oldarg=d["oldarg"])
except ValueError:
continue
wtx = _wtx_ms(resp)
if wtx is not None:
extra += wtx / 1000.0 # device asked to wait longer — keep reading
continue
if resp.cmd in _ASYNC_FRAME_CMDS:
continue # device debug output — not our reply
return resp

View File

@@ -186,6 +186,21 @@ def test_read_response_skips_multiple_debug_then_reply():
assert resp.cmd == int(Cmd.PING) and resp.data == b"pong"
def test_read_response_skips_wtx_frame_not_returns_it():
# a CMD_WTX "wait N ms" control frame (firmware sends it on FPGA bitstream reload) must be
# skipped like a debug frame — returning it as the reply is what permanently desynced every
# subsequent 15693 read (each command then grabbed the previous command's response)
from unittest.mock import AsyncMock as _AM
t = PM3Transport("/dev/null")
t._reader = object()
wtx = _resp_frame(int(Cmd.WTX), struct.pack("<H", 1500)) # FPGA_LOAD_WAIT_TIME
reply = _resp_frame(int(Cmd.HF_ISO15693_COMMAND), b"\x00\x0f\x6b\xc0")
t._read_response_frame = _AM(side_effect=[wtx, reply])
resp = _run(t.read_response())
assert resp.cmd == int(Cmd.HF_ISO15693_COMMAND)
assert resp.data == b"\x00\x0f\x6b\xc0" # the real tag reply, not the WTX frame
def test_read_timeout_sets_resync_next_send_drains():
# a read timeout flags a resync; the next send drains the late response before writing
import asyncio as _a