Skip to content

fix(ci): a crashed emulator fails in seconds instead of hanging 30 minutes - #53

Merged
BitHighlander merged 6 commits into
masterfrom
fix/ci-hang-and-false-green
Aug 22, 2026
Merged

fix(ci): a crashed emulator fails in seconds instead of hanging 30 minutes#53
BitHighlander merged 6 commits into
masterfrom
fix/ci-hang-and-false-green

Conversation

@BitHighlander

Copy link
Copy Markdown
Owner

The integration job has ended cancelled at exactly 30 minutes on every master run for at least six merges, while a green check named "Integration Tests" sat next to it. Four defects stacked.

The hang

The emulator segfaulted mid-suite — the service log reads Application Version 7.10.0 / Segmentation fault (core dumped) — and transport_udp.py never called settimeout(), so _raw_read() blocked in recv() until something outside killed the process.

243 of 662 tests ran in 6 seconds, then 29 minutes of nothing. The next file in collection order is test_msg_ethereum_erc20_uniswap_liquidity.py, which matches the known Uniswap-liquidity defect — so the crash is likely reproducible, and this change is what will let anyone actually see it.

Verified against a socket that is bound but never answers — a crashed emulator whose container still holds the port, the case ICMP port-unreachable does not cover:

took 3.0s  (old behaviour: blocks until the job is killed)
ERROR: No response from the emulator at 127.0.0.1:11998 after 3s -- it is not
running, has crashed, or is wedged on a confirm screen nothing acknowledged.

KK_UDP_TIMEOUT overrides; 0 disables for interactive debugging.

The false green

mikepenz/action-junit-report was given check_name, which makes it publish a separate check run via the Checks API. Its require_tests default is 'false', so the absent junit.xml that a killed pytest leaves behind reported conclusion: success — created already-completed, hence started_at == completed_at, the zero duration.

Now annotate_only with require_tests and fail_on_failure enabled: it annotates and never mints a verdict of its own.

"cancelled" is not "failure"

A job-level timeout ends the job cancelled, which reads as an infra blip — the Fail on test failure step correctly evaluated to failure and was overridden. pytest now carries a 10-minute step timeout, so a hang reports as a failure. Job backstop lowered 30 → 14.

Cycle time

Added a concurrency group with cancel-in-progress, so a new push supersedes the old run instead of both burning a runner to completion.

Not fixed here — and it is why none of this was caught

master has no branch protection at all:

gh api repos/BitHighlander/python-keepkey/branches/master/protection  -> 404
gh api repos/BitHighlander/python-keepkey/rulesets                    -> []

A required check whose conclusion is cancelled would have blocked every one of these merges. Worth enabling separately.

…0 minutes

The integration job has ended "cancelled" at exactly 30 minutes on every
master run for at least six merges, while a green check named "Integration
Tests" sat next to it. Four defects stacked.

THE HANG. The emulator segfaulted mid-suite -- the service log reads
"Application Version 7.10.0 / Segmentation fault (core dumped)" -- and
transport_udp.py never called settimeout(), so _raw_read() blocked in
recv() until something outside killed the process. 243 of 662 tests ran in
6 seconds, then 29 minutes of nothing. The next file in collection order
is test_msg_ethereum_erc20_uniswap_liquidity.py, which matches the known
Uniswap liquidity defect, so the crash is probably reproducible and this
change is what will let anyone see it.

Now raises IOError naming the device, the port and the timeout. Verified
against a socket that is BOUND but never answers -- a crashed emulator
whose container still holds the port, which is the case ICMP does not
cover: 3.0s and a named error, where before it blocked indefinitely.
KK_UDP_TIMEOUT overrides; 0 disables for interactive debugging.

THE FALSE GREEN. mikepenz/action-junit-report was given check_name, which
makes it publish a SEPARATE check run through the Checks API. Its
require_tests default is 'false', so the absent junit.xml a killed pytest
leaves behind reported conclusion:success -- created already-completed, so
started_at == completed_at, the zero duration. Now annotate_only with
require_tests and fail_on_failure on, so it annotates and never mints a
verdict of its own.

CANCELLED IS NOT A FAILURE. A job-level timeout ends the job "cancelled",
which reads as an infrastructure blip; the "Fail on test failure" step
correctly evaluated to failure and was overridden. pytest now carries a
10-minute STEP timeout, so a hang is reported as what it is, with the job
backstop lowered 30 -> 14.

CYCLE TIME. Added a concurrency group with cancel-in-progress so a new
push supersedes the old run rather than both burning a runner.

NOT FIXED HERE, and it is the reason none of this was caught: master has
NO branch protection at all -- `gh api .../branches/master/protection`
returns 404 and rulesets is []. A required check whose conclusion is
"cancelled" would have blocked every one of these merges.
…ing Docker

Two more defects behind the same 30-minute wall, both found by tracing the
crash rather than by reading the workflow.

THE SEGFAULT IS A STALE IMAGE, NOT A FIRMWARE BUG. CI's service container
is `kktech/kkemu:latest`, a FLOATING tag whose current image was built
2026-03-12 and reports firmware 7.10.0 -- six minor versions behind the
suite that runs against it. 7.10.0's zxliquidtx.c formats the Uniswap
deadline with ctime(); the test vectors carry a JavaScript MILLISECOND
timestamp, which as time_t is ~year 53234, and on the image's Alpine 3.8
musl that segfaults. Reproduced inside the image directly. Current
firmware does not call ctime at all -- it snprintf's PRIu64 -- and all
three tests PASS against a locally built 7.15.0.

So the tests were right the whole time. Worse, 80 tests gate on
requires_firmware("7.15.0") and have been SILENTLY SKIPPING against that
image, and it predates -DKK_CLEARSIGN_TEST_ROOT=ON entirely.

Added a version gate that runs before pytest and fails closed if the
emulator is older than the suite. "It answered a ping" is not "it is the
right firmware", and a floating tag cannot tell you which you have.

A TEST WAS KILLING THE DOCKER DAEMON. test_msg_session_trust_lifetime's
_power_cycle() finds "the process bound to udp/11044" with lsof and kills
it. When the emulator runs in a container that process is the port
forwarder -- docker-proxy or dockerd on Linux, com.docker.backend on
macOS -- in a different pid namespace from kkemu, which never appears in
the host namespace at all. Killing it does not reboot anything: it removes
the port forward, and every later test blocks forever on a socket that
will never answer.

It took Docker Desktop down three separate times on this machine tonight
while we were building firmware, which is how it was found.

_emulator_process() now refuses to return any pid whose basename is not
kkemu, so _power_cycle takes its documented skip instead. No coverage is
deleted and the uniswap tests are untouched -- they are correct.

Measured healthy suite runtime: 83.64s for 656 tests, 4 failed, 627
passed, 31 skipped. The job budget was 30 minutes. pytest now bounded at 8
minutes, job backstop 15.
The job pulled kktech/kkemu:latest -- a FLOATING tag whose image was
built 2026-03-12 and reports firmware 7.10.0, five months and six minor
versions behind the suite running against it. That one fact caused every
symptom: 80 tests gating on requires_firmware("7.15.0") skipped in
silence, and one unskipped test drove a ctime() path that segfaults on
that image and does not exist in current firmware.

Publishing a fresher image would only reset the clock and wait for the
same failure. Building from source removes the class -- the emulator under
test is, by construction, the firmware the tests were written against, and
there is nothing to publish, pin, or remember to refresh.

python-keepkey is a submodule OF the firmware repo, so the job now checks
out BitHighlander/keepkey-firmware@alpha alongside it and overlays THIS
checkout of python-keepkey over the pinned one -- otherwise it would test
whatever revision firmware happens to pin rather than the PR under review.

The version gate from the previous commit stays. It is now a belt-and-
braces check rather than the only defence, and it still earns its place:
it catches the day someone points this at a branch that has regressed.

Cost: one emulator build per run, bounded at 20 minutes. Measured healthy
suite runtime is 83.64s, so the build dominates -- and that is the right
trade against a job that spent 30 minutes producing no signal at all.
`submodules: recursive` on the firmware checkout tries to clone
trezor-firmware's micropython vendor tree, whose lib/lwip lives on
git.savannah.gnu.org. That host serves DUMB HTTP and cannot satisfy the
shallow clone actions/checkout asks for:

  fatal: dumb http transport does not support shallow capabilities
  fatal: Failed to recurse into submodule path 'deps/crypto/trezor-firmware'

Nothing in the emulator build needs micropython. The firmware repo's own
CI inits exactly the paths it needs, non-recursively, for this same
reason -- so do that here. deps/python-keepkey is supplied by the overlay
step instead, which is the point of the overlay: test THIS checkout, not
whatever revision firmware pins.
…m the firmware tree

Two failures the emulator-from-source build finally exposed. Both were
always there; the job never got far enough to show them.

requires_structured_eip712() referenced _proto.Failure_UnexpectedMessage.
messages_pb2 has no such attribute -- the FailureType enum is generated
into types_pb2 -- so the helper raised AttributeError and took all four
structured EIP-712 tests down with it. My error, from the commit that
added the helper.

Worth recording alongside it: I claimed in that commit that
requires_message() "only asks whether python-keepkey's own bindings define
a message". That is wrong. It scans the modules AND then probes the
device, skipping on Failure code 1. I stopped reading at the module scan.
The helper is still the better gate -- it names the capability instead of
a message and does not depend on serialising an empty probe -- but it is
an improvement, not a fix for something broken.

The storage-version-gate tests assert against lib/firmware/storage.c,
which they locate by walking UP from the test directory. Run from a
standalone python-keepkey checkout there is no firmware above them and
five tests failed claiming the sources were missing. pytest now runs from
the OVERLAID copy inside the firmware tree, where they resolve -- which
is also the copy the emulator was built from, so the tests and the device
now come from one tree rather than two.
@BitHighlander
BitHighlander force-pushed the fix/ci-hang-and-false-green branch from 28ebad9 to e294164 Compare August 22, 2026 05:22
…anch

python-keepkey is ONE submodule shared by every firmware branch, and CI
now builds the emulator from whichever branch is under test. So a test
pinned to one branch's version reports a failure whose only cause is
which branch you are on. Two did:

  test_active_flash_format_is_v20            assertEqual(20, version)
  test_burned_versions_are_dispatched...     "case StorageVersion_18:"

Both true on the passkeys branch, both FALSE on the 7.15 line, where
STORAGE_VERSION is 17 and nothing is burned. A third, at the reboot test,
was invisible only because CI has no emulator -- and pk-fix already
carried a local patch flipping its 17 to 20, so the rot was being papered
over branch by branch.

A test that reads a source file has to assert properties of what it read.
The ladder, the burned set, LAST_SHIPPED and which versions have readers
are now all derived per tree.

Burnedness cannot be inferred from storage.c alone: deleting the reader
for a SHIPPED version would silently reclassify it as burned and the
suite would bless the wipe. So two independent files are cross-checked --
storage_versions.inc DECLARES burned, storage.c DEMONSTRATES it (returns
SUS_Invalid, no reader) -- and set equality between them is asserted.
test_no_shipped_version_is_burned is the anchor: burned intersected with
[1..LAST_SHIPPED] must be empty, so the declaration can never authorise
wiping a format that reached hardware.

One number is still written down, STORAGE_VERSION_LAST_SHIPPED_FLOOR = 17,
and it is a FLOOR rather than an equality on purpose. 7.15 shipping V17 is
finished history and cannot become false, so it survives 7.16 raising the
constant. assertEqual(17, last_shipped) was the wrong shape: it goes false
the day 7.16 ships, so it rots and gets "fixed" by whoever it inconveniences
-- and lowering LAST_SHIPPED is the highest-severity item in
docs/StorageVersionGate.md, with both operands of its static assert living
in the same header where one commit reaches both.

Verified on BOTH trees from one file: 10 passed / 5 skipped against the
7.15 line, 15 passed against the 7.16 line. Not vacuous: 10 mutations
injected into throwaway copies, 9 fail loudly; the one that passes is a
complete deliberate bump (header + ladder + case + reader), which is
exactly what should pass.
@BitHighlander
BitHighlander merged commit 006142d into master Aug 22, 2026
4 of 5 checks passed
BitHighlander added a commit to BitHighlander/keepkey-firmware that referenced this pull request Aug 22, 2026
…ge gate

Picks up BitHighlander/python-keepkey#53. Two things this branch needs:

The storage-version gate no longer pins V20, so it stops reporting a
failure whose only cause is which firmware branch the emulator was built
from. It derives the ladder, the burned set and LAST_SHIPPED from the
tree under test and is green on both the 7.15 and 7.16 lines.

And the integration job now finishes: 636 passed, 32 skipped, 0 failed in
2m46s, against an emulator built from current firmware. It had been
timing out at 30 minutes with zero assertions run, behind a green check.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant