task-21 bench evidence: console output byte-level interleaving (2 writers on one line)
image identity  : fw build: Oct 26 2026 16:27:01 suite=NONE dstr=off  (built from 77779d49, detached worktree)
source log      : .dsh/skills/serial-assistant/scripts/state/serial.log (serial-assistant daemon, COM6@115200)
observed by     : bench-runner (task-21), 2026-10-26
mechanism claim : bytes that appear INSIDE a line belong to the HEAD of the NEXT line, which is
                  correspondingly missing that head. A UART/framing error can corrupt a byte but
                  can never make a line longer, and the stolen bytes always show up in order at the
                  front of the neighbour. Therefore two console writers were emitting concurrently.
rate            : 2 spliced lines out of 2807 [RX] lines in this log window; both hits are the same
                  writer pair, and both occurred on boots that were NOT the flash boot:
                    boot A 16:28 (stlink flash -Rst -Run)  -> line CLEAN
                    boot B 16:37 (reset only, -Rst -Run)   -> line SPLICED
                    boot C 16:44 (reset only, -Rst -Run)   -> line SPLICED
                  i.e. 2 of 3 boots; not reproducible by construction, timing dependent.
pair (constant) : writer mid-line = [PROT]  (App/task/protect_task.c, "uncalibrated -> protection
                  blocked (UA/UN/IA VALID not all set)", DBG_INFO)
                  victim head     = [NAND_FTL] "Initializing NAND FTL..." (defaultTask storage bring-up)
                  the two run at boot time in different tasks (protectTask AboveNormal vs defaultTask Normal)


==========================================================================================
OCCURRENCE 1  (serial.log byte offsets 3410..3539 and 3540..3628)
==========================================================================================
--- PROT line, verbatim (may contain spliced bytes) ---
[RX] 2026-10-26T16:37:08.989+08:00 [2026-10-26 08:37:07][PROT] uncalibrated -> protection [blocked (UA/UN/IA VALI2D not all s0et)
--- its hexdump (129 bytes @ 3410) ---
  00000d52  5b 52 58 5d 20 32 30 32 36 2d 31 30 2d 32 36 54  |[RX] 2026-10-26T|
  00000d62  31 36 3a 33 37 3a 30 38 2e 39 38 39 2b 30 38 3a  |16:37:08.989+08:|
  00000d72  30 30 20 5b 32 30 32 36 2d 31 30 2d 32 36 20 30  |00 [2026-10-26 0|
  00000d82  38 3a 33 37 3a 30 37 5d 5b 50 52 4f 54 5d 20 75  |8:37:07][PROT] u|
  00000d92  6e 63 61 6c 69 62 72 61 74 65 64 20 2d 3e 20 70  |ncalibrated -> p|
  00000da2  72 6f 74 65 63 74 69 6f 6e 20 5b 62 6c 6f 63 6b  |rotection [block|
  00000db2  65 64 20 28 55 41 2f 55 4e 2f 49 41 20 56 41 4c  |ed (UA/UN/IA VAL|
  00000dc2  49 32 44 20 6e 6f 74 20 61 6c 6c 20 73 30 65 74  |I2D not all s0et|
  00000dd2  29                                               |)|
--- following line, verbatim (note the missing head) ---
[RX] 2026-10-26T16:37:09.000+08:00 26-10-26 08:37:07][NAND_FTL] Initializing NAND FTL...
--- its hexdump (88 bytes @ 3540) ---
  00000dd4  5b 52 58 5d 20 32 30 32 36 2d 31 30 2d 32 36 54  |[RX] 2026-10-26T|
  00000de4  31 36 3a 33 37 3a 30 39 2e 30 30 30 2b 30 38 3a  |16:37:09.000+08:|
  00000df4  30 30 20 32 36 2d 31 30 2d 32 36 20 30 38 3a 33  |00 26-10-26 08:3|
  00000e04  37 3a 30 37 5d 5b 4e 41 4e 44 5f 46 54 4c 5d 20  |7:07][NAND_FTL] |
  00000e14  49 6e 69 74 69 61 6c 69 7a 69 6e 67 20 4e 41 4e  |Initializing NAN|
  00000e24  44 20 46 54 4c 2e 2e 2e                          |D FTL...|


==========================================================================================
OCCURRENCE 2  (serial.log byte offsets 122942..123069 and 123070..123160)
==========================================================================================
--- PROT line, verbatim (may contain spliced bytes) ---
[RX] 2026-10-26T16:44:20.822+08:00 [2026-10-26 08:44:19][PROT] uncalibrated -> protection blocked (UA/UN/IA VALID[ not all set)
--- its hexdump (127 bytes @ 122942) ---
  0001e03e  5b 52 58 5d 20 32 30 32 36 2d 31 30 2d 32 36 54  |[RX] 2026-10-26T|
  0001e04e  31 36 3a 34 34 3a 32 30 2e 38 32 32 2b 30 38 3a  |16:44:20.822+08:|
  0001e05e  30 30 20 5b 32 30 32 36 2d 31 30 2d 32 36 20 30  |00 [2026-10-26 0|
  0001e06e  38 3a 34 34 3a 31 39 5d 5b 50 52 4f 54 5d 20 75  |8:44:19][PROT] u|
  0001e07e  6e 63 61 6c 69 62 72 61 74 65 64 20 2d 3e 20 70  |ncalibrated -> p|
  0001e08e  72 6f 74 65 63 74 69 6f 6e 20 62 6c 6f 63 6b 65  |rotection blocke|
  0001e09e  64 20 28 55 41 2f 55 4e 2f 49 41 20 56 41 4c 49  |d (UA/UN/IA VALI|
  0001e0ae  44 5b 20 6e 6f 74 20 61 6c 6c 20 73 65 74 29     |D[ not all set)|
--- following line, verbatim (note the missing head) ---
[RX] 2026-10-26T16:44:20.822+08:00 2026-10-26 08:44:19][NAND_FTL] Initializing NAND FTL...
--- its hexdump (90 bytes @ 123070) ---
  0001e0be  5b 52 58 5d 20 32 30 32 36 2d 31 30 2d 32 36 54  |[RX] 2026-10-26T|
  0001e0ce  31 36 3a 34 34 3a 32 30 2e 38 32 32 2b 30 38 3a  |16:44:20.822+08:|
  0001e0de  30 30 20 32 30 32 36 2d 31 30 2d 32 36 20 30 38  |00 2026-10-26 08|
  0001e0ee  3a 34 34 3a 31 39 5d 5b 4e 41 4e 44 5f 46 54 4c  |:44:19][NAND_FTL|
  0001e0fe  5d 20 49 6e 69 74 69 61 6c 69 7a 69 6e 67 20 4e  |] Initializing N|
  0001e10e  41 4e 44 20 46 54 4c 2e 2e 2e                    |AND FTL...|


=== CONTRAST: the same PROT line from boot A (16:28, flash boot) -- CLEAN ===
(from the archived boot log; note identical length minus the 3 spliced bytes)
[+365ms] [2026-10-26 08:28:27][PROT] uncalibrated -> protection blocked (UA/UN/IA VALID not all set)

=== BYTE ACCOUNTING ===
boot B: PROT line gained exactly 3 bytes: '[' , '2' , '0'   (in that order, at 3 different insert points)
        NAND_FTL line lost exactly its first 3 bytes: '[' , '2' , '0'   -> it now starts at "26-10-26 ..."
        correct head would be "[2026-10-26 08:37:07]" -> after losing "[20" it reads "26-10-26 08:37:07]"
boot C: PROT line gained 1 byte '[' ; NAND_FTL line lost its leading '[' -> reads "2026-10-26 08:44:19][NAND_FTL]..."
=> gained bytes == lost head, same order. Two writers, no line-level guard.

=== WHY IT MATTERS (not a cosmetic call) ===
- The B6 archive row in this directory (20261012_B6_prod_boot_log_PROTECT_MISS.txt) recorded the same
  class: protectTask's start line arrived interleaved ("st[art: cycle=220ms elm=70") and was fixed by
  moving that line behind the writer-attach gate. This is the same task (protectTask) emitting an INFO
  line on the SAME boot window as the storage bring-up writer.
- Automation impact: an anchor/marker can be silently broken by splicing. Here the surviving text still
  matched, but '@test' Required markers and the anchor count are only as reliable as this line.
