Rejoin serial markers split by a kernel printk - #37
Merged
Conversation
The guest and the kernel share one UART, so a printk can land in the
middle of a userspace write and cut a marker in half:
ANDROMEDA_SELINU[ 8.687420] snd_hda_codec_generic hdaudioC0D0: ...
X_LABELS_OK
Stripping NUL/CR/ANSI cannot repair that -- the marker is split by another
writer's text, not by escape codes -- so a lifecycle that actually
completed still fails the "each marker exactly once" check.
This is not hypothetical: on Actions run 30740353815 the guest emitted all
ten markers including ANDROMEDA_E2E_OK, and the run failed anyway because
ANDROMEDA_SELINUX_LABELS_OK matched zero times. That failure was read as a
problem with the pull request under test; it was neither, and any pull
request could draw it.
Repair only the splice: a kernel timestamp that begins mid-line, plus the
rest of that physical line and its newline. A kernel message at the start
of a line is ordinary console output and is preserved, so this does not
strip kernel logging in general -- only the fragment that interrupted
somebody else's line. On the run above all 42 removed fragments were
embedded in non-kernel lines, and the raw serial log is kept alongside the
normalized copy, so no evidence is lost.
Verified by running the shipped normalizer over that run's boot-serial.log:
ANDROMEDA_SELINUX_LABELS_OK goes from 0 matches to 1, and all ten markers
then satisfy the exactly-once and ordering checks.
Co-Authored-By: Claude Opus 4.8 <noreply@anthropic.com>
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
1 participant
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
Fixes a latent flake that can fail any pull request, found while diagnosing why #35's lifecycle job failed.
What happened
#35's guest completed the entire lifecycle —
ANDROMEDA_E2E_OKis in its serial log — and the run failed anyway. The marker census shows why:The guest and the kernel share one UART. A
printklanded in the middle of the userspace write and cutANDROMEDA_SELINUX_LABELS_OKin half. The validator requires each of the ten markers exactly once, so it counted zero and failed the run.Existing normalization strips NUL, CR and ANSI escapes — it cannot repair this, because the marker is split by another writer's text, not by control characters. This is the same false-negative class the pipeline review documented (P0 #3), but a different mechanism, and it survives the fix that closed the earlier one.
This is not #35's bug. #35 hardens the timeout-budget guard and touches nothing on this path. Any PR can draw this failure; it depends on printk timing.
Fix
Rejoin the splice: remove a kernel timestamp that begins mid-line, plus the rest of that physical line and its newline. A kernel message at the start of a line is ordinary console output and is preserved — this deliberately does not strip kernel logging in general, only the fragment that interrupted somebody else's line.
Applied in
os/scripts/lib/markers.sh(so both harnesses get it) and mirrored intest-install.sh's Python validator, which re-does the stripping so it stays correct if ever pointed at a raw log.Verification
Ran the shipped
normalize_serial_logover run 30740353815's actualboot-serial.log:ANDROMEDA_SELINUX_LABELS_OKPrecision check on the same log: all 42 removed fragments were embedded in non-kernel lines — i.e. every one was a genuine splice, none was a normal console line. The raw serial log is retained next to the normalized copy, so no evidence is lost.
shellcheck clean.
Note on #35
#35 should be re-run once this lands; its failure was environmental, not a defect in that PR.