diff --git a/src/defib/protocol/hisilicon_cv6xx.py b/src/defib/protocol/hisilicon_cv6xx.py index 1f20eca..e0b34e8 100644 --- a/src/defib/protocol/hisilicon_cv6xx.py +++ b/src/defib/protocol/hisilicon_cv6xx.py @@ -45,6 +45,20 @@ DDR_LOAD_ADDR = 0x41000000 UBOOT_LOAD_ADDR = 0x41000000 DDR_TRAINING_WAIT = 1.5 # seconds +# How long past DDR_TRAINING_WAIT to keep waiting once the SPL has printed the +# table header but not yet "DDR size". A board that trains does it within tens +# of milliseconds of the header (a stock CV610 boot: ~35 ms), so this is slack +# for a slow link, not for slow training. +DDR_TRAINING_TIMEOUT = 10.0 # seconds + +# What the SPL prints over UART while it brings up DDR from the uploaded table +# (#148). It names the table first, and once the controller has trained it +# prints the size; a table it will not use -- one built for another chip -- +# it calls incorrect, and it then trains from the boot table in flash and +# starts the U-Boot there, so nothing will take the upload that follows. +SPL_TABLE_HEADER = "boot table file name" +SPL_DDR_TRAINED = "DDR size" +SPL_TABLE_REJECTED = "The table is incorrect" def _emit(callback: Callable[[ProgressEvent], None] | None, event: ProgressEvent) -> None: @@ -164,10 +178,15 @@ def build_ddr_table(parts: CV6xxBootParts, board_id: int = 0) -> bytes: class HiSiliconCV6xx(BootProtocol): """HI3516CV6xx series boot protocol.""" - def __init__(self, ddr_training_wait: float = DDR_TRAINING_WAIT) -> None: + def __init__( + self, + ddr_training_wait: float = DDR_TRAINING_WAIT, + ddr_training_timeout: float = DDR_TRAINING_TIMEOUT, + ) -> None: self._board_id: int = 0 self._cpu_id: int | None = None self._ddr_training_wait = ddr_training_wait + self._ddr_training_timeout = ddr_training_timeout @classmethod def name(cls) -> str: @@ -404,8 +423,25 @@ async def send_firmware( stage=Stage.DDR_TRAINING, bytes_sent=0, bytes_total=1, message="Waiting for DDR training...", )) + # The SPL's own account of the training, kept whole: a marker can be + # split across two reads. + spl_text = "" start = time.monotonic() - while time.monotonic() - start < self._ddr_training_wait: + while True: + elapsed = time.monotonic() - start + if elapsed >= self._ddr_training_wait: + # The usual window is enough unless the SPL has named its table + # and has neither trained nor refused it yet -- then give it + # the slack, and stop the moment it answers. + pending = ( + SPL_TABLE_HEADER in spl_text + and SPL_DDR_TRAINED not in spl_text + and SPL_TABLE_REJECTED not in spl_text + ) + if not pending or elapsed >= ( + self._ddr_training_wait + self._ddr_training_timeout + ): + break try: waiting = await transport.bytes_waiting() if waiting > 0: @@ -416,12 +452,41 @@ async def send_firmware( ascii_str = "".join( chr(b) for b in chunk if 32 <= b <= 126 or b in (10, 13) ) + spl_text += ascii_str if ascii_str.strip(): logger.info("DDR training: %s", ascii_str.strip()) except TransportTimeout: pass await asyncio.sleep(0.05) + # Only on the SPL's word. Silence proves nothing -- not every SPL is + # known to narrate -- so a training that printed nothing goes on to + # the U-Boot upload exactly as before. + if SPL_TABLE_REJECTED in spl_text: + # Not retryable: the SPL checks the table against the chip, so + # the same image is refused the same way after any power cycle. + return RecoveryResult( + success=False, stages_completed=stages, retryable=False, + error=( + "The SPL rejected the DDR table (\"The table is " + "incorrect\"): this boot image is for another chip or " + "variant. The SPL fell back to the boot table in flash " + "and starts the U-Boot there, so it will not take an " + "upload." + ), + ) + if SPL_TABLE_HEADER in spl_text and SPL_DDR_TRAINED not in spl_text: + return RecoveryResult( + success=False, stages_completed=stages, + error=( + "DDR training did not finish: the SPL accepted the DDR " + "table and went silent without printing \"DDR size\". " + "This table does not train this board's memory; try " + "another variant, or the boot table from the board's own " + "flash." + ), + ) + _emit(on_progress, ProgressEvent( stage=Stage.DDR_TRAINING, bytes_sent=1, bytes_total=1, message="DDR training complete", diff --git a/src/defib/recovery/events.py b/src/defib/recovery/events.py index f8e4617..f729cb1 100644 --- a/src/defib/recovery/events.py +++ b/src/defib/recovery/events.py @@ -63,6 +63,10 @@ class RecoveryResult: stages_completed: list[Stage] = field(default_factory=list) error: str | None = None elapsed_ms: float = 0.0 + # False when the device has given a definite answer that another power + # cycle cannot change -- a CV6xx SPL refusing the DDR table, say -- so the + # session's early-failure retry would only send the same image again. + retryable: bool = True # Bytes consumed off the wire during the post-upload break/autoboot-detection # phase. Without this, the U-Boot banner that streams between TAIL ACK and # the autoboot countdown is silently swallowed by the send_break loop and diff --git a/src/defib/recovery/session.py b/src/defib/recovery/session.py index 1a8dbd0..b3083a0 100644 --- a/src/defib/recovery/session.py +++ b/src/defib/recovery/session.py @@ -273,7 +273,7 @@ async def run( is_early = ( Stage.DDR_INIT not in send_result.stages_completed ) - if is_early and attempt < attempts: + if is_early and send_result.retryable and attempt < attempts: last_attempt_error = err continue diff --git a/tests/test_handshake_resilience.py b/tests/test_handshake_resilience.py index 2196b39..a31f293 100644 --- a/tests/test_handshake_resilience.py +++ b/tests/test_handshake_resilience.py @@ -430,3 +430,43 @@ async def always_fail(self, transport, firmware, on_progress=None, assert "PRESTEP0" in (result.error or "") assert call_count["send_firmware"] == 3 assert power.cycle_count == 3 + + +@pytest.mark.asyncio +async def test_session_does_not_retry_a_failure_marked_final(monkeypatch): + """A CV6xx SPL that refuses the DDR table refuses it after every power + cycle (#148): with automated power the session used to cycle the board + and send the same image again. One attempt, one cycle.""" + from defib.protocol.hisilicon_cv6xx import HiSiliconCV6xx + + transport = _ScriptedTransport() + power = _FakePowerController() + call_count = {"send_firmware": 0} + + async def rejected(self, transport, firmware, on_progress=None, + uboot_override=None): # noqa: ARG001 + call_count["send_firmware"] += 1 + return RecoveryResult( + success=False, + error="The SPL rejected the DDR table", + stages_completed=[Stage.GSL, Stage.DDR_TABLE], + retryable=False, + ) + + monkeypatch.setattr(HiSiliconCV6xx, "send_firmware", rejected) + monkeypatch.setattr(HiSiliconCV6xx, "handshake", _fake_handshake_ok) + + session = RecoverySession( + chip="hi3516cv610", + firmware_data=b"\x00" * 1024, + power_controller=power, + poe_port="", + ) + logs: list[LogEvent] = [] + result = await session.run(transport, on_log=logs.append, max_handshake_attempts=2) + + assert not result.success + assert "rejected the DDR table" in (result.error or "") + assert call_count["send_firmware"] == 1 + assert power.cycle_count == 1 + assert not [e for e in logs if "retry" in e.message.lower()] diff --git a/tests/test_protocol_cv6xx.py b/tests/test_protocol_cv6xx.py index a96f18e..f0f5c55 100644 --- a/tests/test_protocol_cv6xx.py +++ b/tests/test_protocol_cv6xx.py @@ -174,3 +174,100 @@ async def test_send_firmware(self): assert result.success assert Stage.GSL in result.stages_completed + + +def _transport_through_ddr_table(spl_output: bytes, then_acks: int = 0) -> MockTransport: + """A device that ACKs the GSL, answers the board-ID query, ACKs the DDR + table, prints `spl_output` while it trains, and ACKs `then_acks` more + frames after that. The padding is read away by the board-ID query and the + training window, as in test_send_firmware.""" + transport = MockTransport(flush_clears_buffer=False) + parts = parse_cv6xx_boot(_build_cv6xx_firmware()) + transport.enqueue_rx(ACK_BYTE * (1 + (len(parts.gsl_data) + 1023) // 1024 + 1)) + board_response = bytearray(11) + board_response[0] = 0xCE + board_response[1] = 0x01 + board_response[10] = 0xAA + transport.enqueue_rx(bytes(board_response)) + transport.enqueue_rx(ACK_BYTE * 2000) + transport.enqueue_rx(spl_output) + if then_acks: + transport.enqueue_rx(ACK_BYTE * then_acks) + return transport + + +# What a CV6xx SPL printed on a CV608 over UART (#148): the header, then the +# size once the table trained. +SPL_TRAINED = ( + b"boot table version :V0.1\r\n" + b"boot table build time :2026/03/01 17:22:29\r\n" + b"boot table file name :Hi3516CV608-DMEB_4L_DDR2_1333M_64MB_16bit-A7_950M_QFN.xlsm\r\n" + b"DDR size: 0x00000040\r\n" +) +# A CV610 table sent to that CV608: refused, then trained from flash. +SPL_REJECTED = ( + b"boot table version :V0.2\r\n" + b"boot table build time :2026/03/01 17:22:42\r\n" + b"boot table file name :Hi3516CV610-DMEB_4L_DDR3_2133M_128MB_16bit-A7_950M_QFN.xlsm" + b"The table is incorrect.\r\nflash\r\n" + b"boot table board switch:0x00000000\r\n" + b"DDR size: 0x00000040\r\nSystem startup\r\n" +) +# What #148 reported from a CV610 module: the header, then nothing at all. +SPL_SILENT = ( + b"boot table version :V0.2\r\n" + b"boot table build time :2026/03/01 17:22:42\r\n" + b"boot table file name :Hi3516CV610-DMEB_4L_DDR3_2133M_128MB_16bit-A7_950M_QFN.xlsm\r\n" +) + + +class TestCV6xxDdrTrainingVerdict: + """The SPL says how DDR training went; send_firmware must listen (#148). + + Before, the stage slept a fixed window and sent U-Boot regardless, so a + table that never trained and a table the SPL refused both surfaced as + "Failed to send U-Boot" four seconds later.""" + + @pytest.mark.asyncio + async def test_a_trained_table_goes_on_to_uboot(self): + transport = _transport_through_ddr_table(SPL_TRAINED, then_acks=5000) + protocol = HiSiliconCV6xx(ddr_training_wait=1.0, ddr_training_timeout=0.5) + result = await protocol.send_firmware(transport, _build_cv6xx_firmware()) + + assert result.success, result.error + assert Stage.UBOOT in result.stages_completed + + @pytest.mark.asyncio + async def test_a_rejected_table_says_so_and_sends_no_uboot(self): + transport = _transport_through_ddr_table(SPL_REJECTED) + protocol = HiSiliconCV6xx(ddr_training_wait=1.0, ddr_training_timeout=0.5) + result = await protocol.send_firmware(transport, _build_cv6xx_firmware()) + + assert not result.success + assert "rejected the DDR table" in result.error + assert not result.retryable + assert Stage.DDR_TABLE in result.stages_completed + assert Stage.UBOOT not in result.stages_completed + + @pytest.mark.asyncio + async def test_a_table_that_never_trains_says_so(self): + transport = _transport_through_ddr_table(SPL_SILENT) + protocol = HiSiliconCV6xx(ddr_training_wait=1.0, ddr_training_timeout=0.5) + result = await protocol.send_firmware(transport, _build_cv6xx_firmware()) + + assert not result.success + assert "DDR training did not finish" in result.error + # A marginal training could pass on another power-up, and one more + # attempt is cheap, so this one is left to the session's retry. + assert result.retryable + assert Stage.UBOOT not in result.stages_completed + + @pytest.mark.asyncio + async def test_a_quiet_spl_still_gets_uboot(self): + """No header, no verdict: nothing to go on, so the upload happens as + it always has.""" + transport = _transport_through_ddr_table(b"", then_acks=5000) + protocol = HiSiliconCV6xx(ddr_training_wait=1.0, ddr_training_timeout=0.5) + result = await protocol.send_firmware(transport, _build_cv6xx_firmware()) + + assert result.success, result.error