Re-lock the mailbox window on lost phase instead of anchoring blind: one loop goroutine per module owns all transport, windows edge-locked from first touch, bringup verifies both modules before either AN restart; corrected charges and link-down reads print raw registers; harness -fuzz repeats lifecycles judging by exit status (30/30 module-clean)

2026-08-13 16:32:14 -07:00
parent fef6b52b74
commit 9301348850
5 changed files with 280 additions and 166 deletions
@@ -43,7 +43,7 @@ Protocol and full verified catalog: [bcm84891l-mdio-commands.md](bcm84891l-mdio-

 | Item | Command | State |
 |---|---|---|
-| EEE / AutogrEEEn | 0x8008/0x8009 | The famous 0x0047 GET reading was the die temperature in DATA1 (firmware scratch — see reliability notes), not an AutogrEEEn mode; GET 0x8008 is unusable. cabletest forces all-off every boot (SET with explicit params `(0, 0, 0x7A12, 0x480, 0)` + AN restart, proven) and verifies 7.60 reads 0 after relink (`phy.go`) |
+| EEE / AutogrEEEn | 0x8008/0x8009 | The famous 0x0047 GET reading was the die temperature in DATA1 (firmware scratch — see reliability notes), not an AutogrEEEn mode; GET 0x8008 is unusable. cabletest forces all-off every boot (SET with explicit params `(0, 0, 0x7A12, 0x480, 0)` + AN restart, proven). The SET programs the advert register directly, so 7.60 reads 0 immediately — bringup verifies it before any AN restart, both µCs quiet; the modules link to each other, so one restart puts both into training, and bringup configures and verifies both before either restart fires (`phy.go`) |
 | EEE wire-truth | arm 0x801A after link-up, read 0x801B | Zero LPI events/duration on idle link; repeat under traffic |
 | Fast retrain | 0x800A (datasheet titles it EMI_MODE; description is fast retrain) | Enabled 10G/5G/2.5G; IEEE 1.147 = 0x0019, count bits zero. Keep enabled; read the 1.147 count per run — a marginal cable that fast-retrains still gets counted |
 | Pair map | 0x8000 | DATA2 = 0x00E4 = identity (A/B/C/D straight through) — MDI wiring verification works |
@@ -61,7 +61,7 @@ Protocol and full verified catalog: [bcm84891l-mdio-commands.md](bcm84891l-mdio-

 **The internal poll's clock, measured on hardware.** One poll every 3.49–4.22 s, regime-dependent but rock-stable within a regime (±15 ms): ≈3.50 s warm and idle, ≈3.70 s, ≈4.01 s cool and idle, ≈4.21 s under continuous host mailbox load — host traffic *defers* the poll, never advances it, and nothing observed brings two polls closer than 3.49 s. The poll is link-independent: it runs straight through an AN restart and the whole retrain without missing a beat. Around each poll's service the bridge serves stale data for ~50 ms: every read returns the last value successfully fetched before the µC went busy (stuck-at-last-fetch, not one-behind), which is exactly how 3.33 inherits 1.147's 0x0011. The window closes *before* the poll is detectable — a CMD read returning the fresh resident 0x0031 is itself proof the µC serviced the fetch, so flip detection doubles as the all-clear.

-**The windowed protocol (`phy.go` `admit`) — contention resolved by time-division.** Since the poll cannot be silenced, the host schedules around it: after bringup, every operation is admitted only inside a fixed 3.4 s window following each observed poll (CMD flipping to resident 0x0031, polled at 10 ms); at the cutoff the host goes quiet until the next flip. 3.4 s sits below every observed cadence, so a regime switch mid-run lands harmlessly in vacated time — no prediction, no period tracking, just the last observed flip plus two constants. The host's own commands re-arm detection (they leave CMD ≠ 0x0031); a missing heartbeat free-runs one window rather than stall (never observed — the heartbeat survives retrains); bringup runs before windowing is enabled and never waits. Validated on hardware in `~/work/phydiag-work/bcm_phaselock_bench.py`: aiming read bursts at the poll reproduces the poisoning on 100% of polls (the "+17" manufactured on demand); windowed operation ran 2,881 back-to-back batches — 16× the production rate, riding the cutoff — with zero stale values, and the production 1 Hz stream is unperturbed (blackout hides inside natural gaps, worst sample gap ~1.6 s). Corrected bursts since windowing no longer decode as neighbor registers (historically every one did) and correlate with amber SNR margin under full-rate traffic — real line corrections; the graded-noise correlation run is the confirmation path.
+**The windowed protocol (`phy.go`) — contention resolved by time-division.** Since the poll cannot be silenced, the host schedules around it. One goroutine per module owns every transport touch (requests execute one at a time on the loop — nothing else can reach the wire, by construction), and each request is admitted only inside a fixed 3.4 s window following an observed poll (CMD flipping to resident 0x0031, polled at 10 ms); at the cutoff the host goes quiet until the next flip. 3.4 s sits below every observed cadence, so a regime switch mid-run lands harmlessly in vacated time — no prediction, no period tracking, just the last observed flip plus two constants. **Re-lock — no window at assumed phase**: edge detection needs CMD ≠ 0x0031, and normal work leaves it armed (every handler command rewrites CMD), but after a gap with no commands — a diag plus its relink wait, an idle stretch, a poll that skipped its GET because the link bit read down — the resident is 0x0031 and the phase is unknown. Admission then arms first (a bare GET_PAIR_SWAP, resident 0x0000) and anchors only on the true edge that follows, so every window is edge-locked from first contact at boot; bringup pays one phase acquisition per module (~2–4 s). A missing heartbeat free-runs one window rather than stall (never observed — the heartbeat survives retrains). Before re-lock the post-diag window anchored blind on the stale resident, and every ghost observed under windowing sat in exactly that window; with re-lock, ghost-free across all bench diags to date. A poisoned batch is self-consistent and forensically visible: the stuck value clears the link bit (SNR skipped, panel shows "-", the ghost-SNR panic sidestepped) while 3.33 charges the same value as errored blocks (0x0011 → the "+17"); every corrected charge and link-down reading prints its raw 1.1/3.33/1.147 on the console, so events self-attribute — a ghost names its neighbor register, real correction decodes as nothing but itself. Validated on hardware in `~/work/phydiag-work/bcm_phaselock_bench.py`: aiming read bursts at the poll reproduces the poisoning on 100% of polls (the "+17" manufactured on demand); windowed operation ran 2,881 back-to-back batches — 16× the production rate, riding the cutoff — with zero stale values, and the production 1 Hz stream is unperturbed (blackout hides inside natural gaps, worst sample gap ~1.6 s).

 ## ECD — recovered from the OpenBCM SDK, proven on hardware

@@ -2,7 +2,7 @@

 ## Committed tree

-AF_PACKET raw sockets everywhere (`sock.go`); flow-director steering; per-packet-MAC-rx-stamped rate buckets (`SO_TIMESTAMPING` cmsg, `rx_filter=ALL` as a hard host check — nics/README.md for what that demands of the NIC; **temporarily bypassed** in `ts.go` so BCM work can run on the X520, which cannot stamp — the check reports yellow and the panel rates read zero there; restore to fatal for the product NIC); read-time-stamped NIC-counter rates; test interfaces pinned to MTU 9000 with a 9018-byte jumbo in the size mix (the modules' jumbo path is exercised, not assumed); BCM module diagnostics (`phy.go`, over the patched-ixgbe `sff_i2c` debugfs, compound-op framing; one per-module lock around every whole operation, and steady-state work time-division-multiplexed with the firmware's own mailbox client — every operation admitted only inside a 3.4 s window after each observed internal temp poll, which ends the stale-read poisoning of the corrected channel — modules/fs/ for the full trap list and validation): bringup identifies both modules and forces EEE off, jumbo on and the master/slave roles (A master / B slave — left to AN the role is a per-training lottery) every boot — no trustworthy readback exists and no cable is guaranteed to probe through; the ECD — per-pair verdicts, lengths and pair maps are the length/wiring path — runs through one async path at startup and on every reset, never blocking the UI, with counters re-baselining only after the diag's own link blip so it is never charged to the run; a 1 Hz poller feeds per-pair SNR margin (vs the ≈26.5 dB operating point; green ≥ 3 dB, amber ≥ 1 dB — provisional until the graded-noise run) and the corrected-error set (PCS 3.33 errored blocks/BER, PMA 1.147 fast-retrain count) to the panel and console; framebuffer UI; harness.
+AF_PACKET raw sockets everywhere (`sock.go`); flow-director steering; per-packet-MAC-rx-stamped rate buckets (`SO_TIMESTAMPING` cmsg, `rx_filter=ALL` as a hard host check — nics/README.md for what that demands of the NIC; **temporarily bypassed** in `ts.go` so BCM work can run on the X520, which cannot stamp — the check reports yellow and the panel rates read zero there; restore to fatal for the product NIC); read-time-stamped NIC-counter rates; test interfaces pinned to MTU 9000 with a 9018-byte jumbo in the size mix (the modules' jumbo path is exercised, not assumed); BCM module diagnostics (`phy.go`, over the patched-ixgbe `sff_i2c` debugfs, compound-op framing; one loop goroutine per module owns every transport touch, and all work is time-division-multiplexed with the firmware's own mailbox client — each request admitted only inside a 3.4 s edge-locked window after an observed internal temp poll, re-acquiring phase whenever it was lost — which ends the stale-read poisoning of the corrected channel; corrected charges and link-down reads print their raw registers so events self-attribute — modules/fs/ for the full trap list and validation): bringup identifies both modules and forces EEE off, jumbo on and the master/slave roles (A master / B slave — left to AN the role is a per-training lottery) every boot — no trustworthy readback exists and no cable is guaranteed to probe through; the ECD — per-pair verdicts, lengths and pair maps are the length/wiring path — runs through one async path at startup and on every reset, never blocking the UI, with counters re-baselining only after the diag's own link blip so it is never charged to the run; a 1 Hz poller feeds per-pair SNR margin (vs the ≈26.5 dB operating point; green ≥ 3 dB, amber ≥ 1 dB — provisional until the graded-noise run) and the corrected-error set (PCS 3.33 errored blocks/BER, PMA 1.147 fast-retrain count) to the panel and console; framebuffer UI; harness.

 ## Stashes

@@ -5,9 +5,11 @@
 package main

 import (
+	"bytes"
 	"flag"
 	"fmt"
 	"image/png"
+	"io"
 	"os"
 	"os/exec"
 	"path/filepath"
@@ -20,19 +22,58 @@ import (
 const (
 	shotsDir = "shots"
 	grace    = 3 * time.Second
+	// The framebuffer's DRM master can outlive the process group by a moment;
+	// an immediate next run finds the device busy.
+	fuzzGap = 2 * time.Second
 )

 func main() {
 	runFor := flag.Duration("for", 15*time.Second, "how long to let cabletest run")
 	at := flag.String("at", "", "offsets to capture the panel at, comma separated, e.g. 3s,10s")
+	fuzzN := flag.Int("fuzz", 0, "repeat the whole lifecycle this many times; full output only for runs that fail or log module events")
 	flag.Parse()

-	if err := run(*runFor, *at, flag.Args()); err != nil {
+	var err error
+	if *fuzzN > 0 {
+		err = fuzz(*fuzzN, *runFor, flag.Args())
+	} else {
+		err = run(*runFor, *at, os.Stdout, flag.Args())
+	}
+	if err != nil {
 		fmt.Fprintln(os.Stderr, err)
 		os.Exit(1)
 	}
 }

+func fuzz(n int, runFor time.Duration, args []string) error {
+	failed := 0
+	for i := 1; i <= n; i++ {
+		if i > 1 {
+			time.Sleep(fuzzGap)
+		}
+		var buf bytes.Buffer
+		start := time.Now()
+		err := run(runFor, "", &buf, args)
+		dur := time.Since(start).Round(100 * time.Millisecond)
+		if err != nil {
+			failed++
+			name := fmt.Sprintf("fuzz-run%02d.log", i)
+			if werr := os.WriteFile(name, buf.Bytes(), 0o644); werr != nil {
+				name = fmt.Sprintf("unsaved: %v", werr)
+			}
+			fmt.Printf("run %02d/%02d: FAILED (%s): %v [%s]\n", i, n, dur, err, name)
+			os.Stdout.Write(buf.Bytes())
+			continue
+		}
+		fmt.Printf("run %02d/%02d: ok (%s)\n", i, n, dur)
+	}
+	fmt.Printf("fuzz: %d/%d ok, %d failed\n", n-failed, n, failed)
+	if failed > 0 {
+		return fmt.Errorf("%d/%d runs failed", failed, n)
+	}
+	return nil
+}
+
 func parseShots(s string, runFor time.Duration) ([]time.Duration, error) {
 	if s == "" {
 		return nil, nil
@@ -52,7 +93,7 @@ func parseShots(s string, runFor time.Duration) ([]time.Duration, error) {
 	return out, nil
 }

-func run(runFor time.Duration, at string, args []string) error {
+func run(runFor time.Duration, at string, out io.Writer, args []string) error {
 	if os.Geteuid() != 0 {
 		return fmt.Errorf("needs root for the raw sockets and the framebuffer: sudo go run ./harness")
 	}
@@ -67,7 +108,7 @@ func run(runFor time.Duration, at string, args []string) error {
 	}

 	cmd := exec.Command("go", append([]string{"run", "."}, args...)...)
-	cmd.Stdout, cmd.Stderr = os.Stdout, os.Stderr
+	cmd.Stdout, cmd.Stderr = out, out
 	// Its own process group: go run's compiled child is reparented rather than
 	// killed when go run dies, and an orphan holding the wire poisons every
 	// measurement after it.
@@ -793,6 +793,11 @@ func run(aName, bName string) (err error) {
 				rows[i] = d.displayView()
 			}
 			v, phy := measureView(diag, modules, totalView(rows))
+			for _, m := range modules {
+				for _, n := range m.takeNotes() {
+					fmt.Println(stats.rule(n))
+				}
+			}
 			for _, line := range stats.emit(totalRow(elapsed, v, target, phy,
 				noise.view())) {
 				fmt.Println(line)
@@ -73,26 +73,52 @@ type bcm struct {
 	ifname string
 	path   string

-	// Every method holds it for its whole logical operation: exactly one
-	// host-side conversation with the module at a time, by construction.
-	mu        sync.Mutex
+	// Every transport touch happens on the loop goroutine: requests execute
+	// one at a time, each admitted into the quiet window first.
+	reqs      chan func()
 	windowEnd time.Time
-	windowed  atomic.Bool
 }

-// The firmware's internal temp poll (every 3.5–4.2 s, never under 3.49) serves
-// stale bridge reads for ~50 ms around it; work stays inside 3.4 s post-poll.
+func (b *bcm) loop() {
+	defer holdPanic()
+	for fn := range b.reqs {
+		b.window()
+		fn()
+	}
+}
+
+func (b *bcm) exec(fn func()) {
+	done := make(chan struct{})
+	b.reqs <- func() { fn(); close(done) }
+	<-done
+}
+
+// The firmware's internal temp poll serves stale bridge reads for ~50 ms
+// around it; work stays inside 3.4 s of an observed poll. A resident 0x0031 at
+// expiry means the phase is unknown, so re-lock: arm, then take the true edge.
 func (b *bcm) window() {
-	if !b.windowed.Load() || time.Now().Add(bcmWindowFit).Before(b.windowEnd) {
+	if time.Now().Add(bcmWindowFit).Before(b.windowEnd) {
 		return
 	}
+	armed := false
 	deadline := time.Now().Add(bcmFlipWait)
 	for {
 		v, err := b.mdioRead(bcmMMDVendor, bcmRegCmd)
 		if err != nil {
 			panic(fmt.Sprintf("%s: heartbeat poll: %v", b.ifname, err))
 		}
-		if v == bcmCmdResidentTemp || time.Now().After(deadline) {
+		if v == bcmCmdResidentTemp {
+			if armed {
+				b.windowEnd = time.Now().Add(bcmWindow)
+				return
+			}
+			b.rearm()
+			armed = true
+			deadline = time.Now().Add(bcmFlipWait)
+			continue
+		}
+		armed = true
+		if time.Now().After(deadline) {
 			b.windowEnd = time.Now().Add(bcmWindow)
 			return
 		}
@@ -100,10 +126,20 @@ func (b *bcm) window() {
 	}
 }

-func (b *bcm) acquire() func() {
-	b.mu.Lock()
-	b.window()
-	return b.mu.Unlock
+func (b *bcm) rearm() {
+	if _, err := b.waitStatus(func(st uint16) bool {
+		return st != bcmStInProgress && st != bcmStBusy
+	}); err != nil {
+		panic(fmt.Sprintf("%s: rearm: %v", b.ifname, err))
+	}
+	if err := b.mdioWrite(bcmMMDVendor, bcmRegCmd, bcmCmdGetPairSwap); err != nil {
+		panic(fmt.Sprintf("%s: rearm: %v", b.ifname, err))
+	}
+	if _, err := b.waitStatus(func(st uint16) bool {
+		return st == bcmStPass || st == bcmStError
+	}); err != nil {
+		panic(fmt.Sprintf("%s: rearm: %v", b.ifname, err))
+	}
 }

 func openBCM(ifname string) (*bcm, error) {
@@ -121,10 +157,12 @@ func openBCM(ifname string) (*bcm, error) {
 	b := &bcm{
 		ifname: ifname,
 		path:   "/sys/kernel/debug/ixgbe/" + filepath.Base(devLink) + "/sff_i2c",
+		reqs:   make(chan func()),
 	}
 	if _, err := os.Stat(b.path); err != nil {
 		return nil, fmt.Errorf("%s: %w (patched ixgbe?)", ifname, err)
 	}
+	go b.loop()
 	return b, nil
 }

@@ -231,76 +269,79 @@ func (b *bcm) waitStatus(want func(uint16) bool) (uint16, error) {
 // GETs must be invoked bare (pre-writing any DATA register leaves the handler
 // executing as a no-op); SETs must pass their full parameter set (the handler
 // executes stale DATA).
-func (b *bcm) command(code uint16, params ...uint16) ([5]uint16, error) {
-	defer b.acquire()()
-
-	var data [5]uint16
-	if _, err := b.waitStatus(func(st uint16) bool {
-		return st != bcmStInProgress && st != bcmStBusy
-	}); err != nil {
-		return data, err
-	}
-	for i, p := range params {
-		if err := b.mdioWrite(bcmMMDVendor, bcmRegData1+uint16(i), p); err != nil {
-			return data, err
+func (b *bcm) command(code uint16, params ...uint16) (data [5]uint16, err error) {
+	b.exec(func() {
+		if _, err = b.waitStatus(func(st uint16) bool {
+			return st != bcmStInProgress && st != bcmStBusy
+		}); err != nil {
+			return
+		}
+		for i, p := range params {
+			if err = b.mdioWrite(bcmMMDVendor, bcmRegData1+uint16(i), p); err != nil {
+				return
+			}
+		}
+		if err = b.mdioWrite(bcmMMDVendor, bcmRegCmd, code); err != nil {
+			return
+		}
+		var st uint16
+		if st, err = b.waitStatus(func(st uint16) bool {
+			return st == bcmStPass || st == bcmStError
+		}); err != nil {
+			return
+		}
+		if st == bcmStError {
+			err = fmt.Errorf("%s: command %#04x returned ERROR", b.ifname, code)
+			return
+		}
+		if len(params) > 0 {
+			return
+		}
+		for i := range data {
+			if data[i], err = b.mdioRead(bcmMMDVendor, bcmRegData1+uint16(i)); err != nil {
+				return
+			}
 		}
-	}
-	if err := b.mdioWrite(bcmMMDVendor, bcmRegCmd, code); err != nil {
-		return data, err
-	}
-	st, err := b.waitStatus(func(st uint16) bool {
-		return st == bcmStPass || st == bcmStError
 	})
-	if err != nil {
-		return data, err
-	}
-	if st == bcmStError {
-		return data, fmt.Errorf("%s: command %#04x returned ERROR", b.ifname, code)
-	}
-	if len(params) > 0 {
-		return data, nil
-	}
-	for i := range data {
-		if data[i], err = b.mdioRead(bcmMMDVendor, bcmRegData1+uint16(i)); err != nil {
-			return data, err
-		}
-	}
-	return data, nil
+	return
 }

-func (b *bcm) identify() (string, error) {
-	defer b.acquire()()
-	hi, err := b.mdioRead(1, 2)
-	if err != nil {
-		return "", err
-	}
-	lo, err := b.mdioRead(1, 3)
-	if err != nil {
-		return "", err
-	}
-	if hi != bcmPHYIDHi || lo != bcmPHYIDLo {
-		return "", fmt.Errorf("%s: PHY ID %#04x:%#04x, want %#04x:%#04x",
-			b.ifname, hi, lo, bcmPHYIDHi, bcmPHYIDLo)
-	}
-	sn, err := b.eeprom(68, 16)
-	if err != nil {
-		return "", err
-	}
-	return "BCM84891L sn " + strings.TrimSpace(string(sn)), nil
+func (b *bcm) identify() (ident string, err error) {
+	b.exec(func() {
+		var hi, lo uint16
+		if hi, err = b.mdioRead(1, 2); err != nil {
+			return
+		}
+		if lo, err = b.mdioRead(1, 3); err != nil {
+			return
+		}
+		if hi != bcmPHYIDHi || lo != bcmPHYIDLo {
+			err = fmt.Errorf("%s: PHY ID %#04x:%#04x, want %#04x:%#04x",
+				b.ifname, hi, lo, bcmPHYIDHi, bcmPHYIDLo)
+			return
+		}
+		var sn []byte
+		if sn, err = b.eeprom(68, 16); err != nil {
+			return
+		}
+		ident = "BCM84891L sn " + strings.TrimSpace(string(sn))
+	})
+	return
 }

 // PMA 1.1 latches low, so the first read reports any drop since it was last
 // read and the second reports the wire as it is now.
-func (b *bcm) linkUp() (bool, error) {
-	defer b.acquire()()
-	if _, err := b.mdioRead(1, 1); err != nil {
-		return false, err
-	}
-	v, err := b.mdioRead(1, 1)
-	if err != nil {
-		return false, err
-	}
-	return v&0x0004 != 0, nil
+func (b *bcm) linkUp() (up bool, raw uint16, err error) {
+	b.exec(func() {
+		if _, err = b.mdioRead(1, 1); err != nil {
+			return
+		}
+		if raw, err = b.mdioRead(1, 1); err != nil {
+			return
+		}
+		up = raw&0x0004 != 0
+	})
+	return
 }

 func (b *bcm) forceEEEOff() error {
@@ -316,33 +357,37 @@ func (b *bcm) forceJumbo() error {
 // Left to AN, master/slave is a per-training lottery and each training's DSP
 // convergence moves per-pair SNR by up to ~3.6 dB; pinned roles at least keep
 // every session measured under identical conditions.
-func (b *bcm) forceRole(master bool) error {
-	defer b.acquire()()
-	v, err := b.mdioRead(7, 32)
-	if err != nil {
-		return err
-	}
-	v |= 0x8000
-	if master {
-		v |= 0x4000
-	} else {
-		v &^= 0x4000
-	}
-	return b.mdioWrite(7, 32, v)
+func (b *bcm) forceRole(master bool) (err error) {
+	b.exec(func() {
+		var v uint16
+		if v, err = b.mdioRead(7, 32); err != nil {
+			return
+		}
+		v |= 0x8000
+		if master {
+			v |= 0x4000
+		} else {
+			v &^= 0x4000
+		}
+		err = b.mdioWrite(7, 32, v)
+	})
+	return
 }

-func (b *bcm) restartAN() error {
-	defer b.acquire()()
-	v, err := b.mdioRead(7, 0)
-	if err != nil {
-		return err
-	}
-	return b.mdioWrite(7, 0, v|0x0200)
+func (b *bcm) restartAN() (err error) {
+	b.exec(func() {
+		var v uint16
+		if v, err = b.mdioRead(7, 0); err != nil {
+			return
+		}
+		err = b.mdioWrite(7, 0, v|0x0200)
+	})
+	return
 }

-func (b *bcm) eeeAdvert() (uint16, error) {
-	defer b.acquire()()
-	return b.mdioRead(7, 60)
+func (b *bcm) eeeAdvert() (v uint16, err error) {
+	b.exec(func() { v, err = b.mdioRead(7, 60) })
+	return
 }

 func (b *bcm) pairMap() (byte, error) {
@@ -365,22 +410,24 @@ func (b *bcm) snr() ([4]float64, error) {
 	return out, nil
 }

-func (b *bcm) pcsLatch() (blocks, ber uint64, err error) {
-	defer b.acquire()()
-	v, err := b.mdioRead(3, 33)
-	if err != nil {
-		return 0, 0, err
-	}
-	return uint64(v & 0xFF), uint64((v >> 8) & 0x3F), nil
+func (b *bcm) pcsLatch() (blocks, ber uint64, raw uint16, err error) {
+	b.exec(func() {
+		if raw, err = b.mdioRead(3, 33); err != nil {
+			return
+		}
+		blocks, ber = uint64(raw&0xFF), uint64((raw>>8)&0x3F)
+	})
+	return
 }

-func (b *bcm) fastRetrainCount() (uint16, error) {
-	defer b.acquire()()
-	v, err := b.mdioRead(1, 147)
-	if err != nil {
-		return 0, err
-	}
-	return v >> 11, nil
+func (b *bcm) fastRetrainCount() (count, raw uint16, err error) {
+	b.exec(func() {
+		if raw, err = b.mdioRead(1, 147); err != nil {
+			return
+		}
+		count = raw >> 11
+	})
+	return
 }

 type ecdResult struct {
@@ -388,48 +435,47 @@ type ecdResult struct {
 	metres   [4]int
 }

-func (b *bcm) cableDiag() (ecdResult, error) {
-	defer b.acquire()()
-
-	var res ecdResult
-	ctrl, err := b.mdioRead(bcmMMDVendor, bcmRegECDCtrl)
-	if err != nil {
-		return res, err
-	}
-	if err := b.mdioWrite(bcmMMDVendor, bcmRegECDCtrl, ctrl&^0xF400|0x8400); err != nil {
-		return res, err
-	}
-	deadline := time.Now().Add(ecdDeadline)
-	for {
-		ctrl, err = b.mdioRead(bcmMMDVendor, bcmRegECDCtrl)
-		if err != nil {
-			return res, err
+func (b *bcm) cableDiag() (res ecdResult, err error) {
+	b.exec(func() {
+		var ctrl uint16
+		if ctrl, err = b.mdioRead(bcmMMDVendor, bcmRegECDCtrl); err != nil {
+			return
 		}
-		if ctrl&0x0800 == 0 {
-			break
+		if err = b.mdioWrite(bcmMMDVendor, bcmRegECDCtrl, ctrl&^0xF400|0x8400); err != nil {
+			return
 		}
-		if time.Now().After(deadline) {
-			return res, fmt.Errorf("%s: cable diag still busy after %s", b.ifname, ecdDeadline)
+		deadline := time.Now().Add(ecdDeadline)
+		for {
+			if ctrl, err = b.mdioRead(bcmMMDVendor, bcmRegECDCtrl); err != nil {
+				return
+			}
+			if ctrl&0x0800 == 0 {
+				break
+			}
+			if time.Now().After(deadline) {
+				err = fmt.Errorf("%s: cable diag still busy after %s", b.ifname, ecdDeadline)
+				return
+			}
+			time.Sleep(ecdPoll)
 		}
-		time.Sleep(ecdPoll)
-	}
-	b.window()
-	v, err := b.mdioRead(1, bcmRegECDResult)
-	if err != nil {
-		return res, err
-	}
-	for i := range res.verdicts {
-		res.verdicts[i] = int(v>>(4*i)) & 0xF
-		if res.verdicts[i] > pairXtalk {
-			panic(fmt.Sprintf("%s: ghost ECD verdict %#04x", b.ifname, v))
+		b.window()
+		var v uint16
+		if v, err = b.mdioRead(1, bcmRegECDResult); err != nil {
+			return
 		}
-		m, err := b.mdioRead(1, bcmRegECDLen+uint16(i))
-		if err != nil {
-			return res, err
+		for i := range res.verdicts {
+			res.verdicts[i] = int(v>>(4*i)) & 0xF
+			if res.verdicts[i] > pairXtalk {
+				panic(fmt.Sprintf("%s: ghost ECD verdict %#04x", b.ifname, v))
+			}
+			var m uint16
+			if m, err = b.mdioRead(1, bcmRegECDLen+uint16(i)); err != nil {
+				return
+			}
+			res.metres[i] = int(m)
 		}
-		res.metres[i] = int(m)
-	}
-	return res, nil
+	})
+	return
 }

 const (
@@ -465,6 +511,7 @@ type phyModule struct {
 	recentDelta  uint64
 	primed       bool
 	retrainCount uint16
+	notes        []string
 }

 // Silent while a measure owns the module.
@@ -472,7 +519,7 @@ func (m *phyModule) poll() error {
 	if m.busy.Load() {
 		return nil
 	}
-	link, err := m.bcm.linkUp()
+	link, linkRaw, err := m.bcm.linkUp()
 	if err != nil {
 		return err
 	}
@@ -487,16 +534,20 @@ func (m *phyModule) poll() error {
 			}
 		}
 	}
-	blocks, ber, err := m.bcm.pcsLatch()
+	blocks, ber, pcsRaw, err := m.bcm.pcsLatch()
 	if err != nil {
 		return err
 	}
-	count, err := m.bcm.fastRetrainCount()
+	count, frRaw, err := m.bcm.fastRetrainCount()
 	if err != nil {
 		return err
 	}

 	m.mu.Lock()
+	if m.link && !link {
+		m.notes = append(m.notes,
+			fmt.Sprintf("%s link read down: 1.1=0x%04x", m.bcm.ifname, linkRaw))
+	}
 	m.sampled = true
 	m.lastOK = time.Now()
 	m.link = link
@@ -505,10 +556,16 @@ func (m *phyModule) poll() error {
 	// The first poll after a baseline drains latches from the bringup/diag
 	// retrain era, so it only sets the origin; the retrain counter is 5 bits.
 	if m.primed {
-		delta := blocks + ber + uint64((count-m.retrainCount)&0x1F)
+		rt := uint64((count - m.retrainCount) & 0x1F)
+		delta := blocks + ber + rt
+		if delta > 0 {
+			m.notes = append(m.notes, fmt.Sprintf(
+				"%s corrected +%d raw: 3.33=0x%04x (blocks %d ber %d) 1.147=0x%04x (retrain +%d) 1.1=0x%04x",
+				m.bcm.ifname, delta, pcsRaw, blocks, ber, frRaw, rt, linkRaw))
+		}
 		m.blocks += blocks
 		m.ber += ber
-		m.retrains += uint64((count - m.retrainCount) & 0x1F)
+		m.retrains += rt
 		m.recentDelta = delta
 	} else {
 		m.recentDelta = 0
@@ -519,6 +576,14 @@ func (m *phyModule) poll() error {
 	return nil
 }

+func (m *phyModule) takeNotes() []string {
+	m.mu.Lock()
+	defer m.mu.Unlock()
+	n := m.notes
+	m.notes = nil
+	return n
+}
+
 func (m *phyModule) run(done *atomic.Bool) {
 	tick := time.NewTicker(phyInterval)
 	defer tick.Stop()
@@ -848,12 +913,11 @@ func moduleChecks(mods []*phyModule, names [2]string) []checkResult {
 			return fail(res.item, err)
 		}
 		out = append(out, res)
-
-		if err := m.bcm.restartAN(); err != nil {
-			return fail(names[i]+" retrain", err)
-		}
 	}

+	// Both modules configured and verified before either AN restart: the
+	// modules link to each other, so one restart puts both µCs into training,
+	// and no read should race that. The restarts fire last, nothing after.
 	res := checkResult{item: "eee advert"}
 	var adv [2]string
 	for i, m := range mods {
@@ -867,10 +931,14 @@ func moduleChecks(mods []*phyModule, names [2]string) []checkResult {
 		}
 	}
 	res.state = adv[0] + "/" + adv[1]
-	for _, m := range mods {
-		m.bcm.windowed.Store(true)
+	out = append(out, res)
+
+	for i, m := range mods {
+		if err := m.bcm.restartAN(); err != nil {
+			return fail(names[i]+" retrain", err)
+		}
 	}
-	return append(out, res)
+	return out
 }

 func cableLine(c cableInfo) string {