From cd01efebc1b0736e22a9bb255668684dceb87815 Mon Sep 17 00:00:00 2001 From: Techmore Date: Wed, 21 Oct 2026 11:40:18 -0400 Subject: [PATCH 1/2] Compositor: cut hotplug debounce from 250 ms to 40 ms Journal timing of eight WD22TB4 plug cycles on the J314S shows the DCP driver sends its connector uevents ~9 ms apart with modes already populated, so the 250 ms wait was pure latency on connect and disconnect. The +1 s follow-up reconcile still covers late-settling connectors. Co-Authored-By: Claude Sonnet 5.5 --- rust/pantheon-compositor/src/hotplug.rs | 23 +++++++++++++++-------- 1 file changed, 15 insertions(+), 8 deletions(-) diff --git a/rust/pantheon-compositor/src/hotplug.rs b/rust/pantheon-compositor/src/hotplug.rs index f66c15451..5d23d58a6 100644 --- a/rust/pantheon-compositor/src/hotplug.rs +++ b/rust/pantheon-compositor/src/hotplug.rs @@ -10,7 +10,14 @@ use std::time::{Duration, Instant}; /// Delay between the first uevent and the reconcile, coalescing event bursts. -pub const EVENT_DEBOUNCE: Duration = Duration::from_millis(250); +/// +/// Measured on the J314S with a WD22TB4 dock (journal, eight plug cycles): +/// the Apple DCP driver emits its connector uevents in a burst about 9 ms +/// apart and the connector already carries its modes when the first arrives, +/// so waiting longer only delays the output (it was 250 ms, half of the +/// compositor's share of the dock-to-picture time). The follow-up reconcile +/// below still catches anything that settles later. +pub const EVENT_DEBOUNCE: Duration = Duration::from_millis(40); /// One extra reconcile after an event-driven one, for late-settling connectors. pub const EVENT_RECHECK: Duration = Duration::from_secs(1); /// Safety poll while the udev monitor is active. @@ -153,15 +160,15 @@ mod tests { let mut s = HotplugScheduler::new(t0, true); assert_eq!(s.on_event(t0), Some(t0 + EVENT_DEBOUNCE)); // A burst is coalesced into the already armed deadline. - assert_eq!(s.on_event(t0 + ms(100)), None); - assert!(!s.tick(t0 + ms(200), None).reconcile); - let first = s.tick(t0 + ms(250), None); + assert_eq!(s.on_event(t0 + ms(9)), None); + assert!(!s.tick(t0 + EVENT_DEBOUNCE - ms(1), None).reconcile); + let first = s.tick(t0 + EVENT_DEBOUNCE, None); assert!(first.reconcile); assert_eq!( first.next_event_deadline, - Some(t0 + ms(250) + EVENT_RECHECK) + Some(t0 + EVENT_DEBOUNCE + EVENT_RECHECK) ); - let second = s.tick(t0 + ms(1250), None); + let second = s.tick(t0 + EVENT_DEBOUNCE + EVENT_RECHECK, None); assert!(second.reconcile); assert_eq!(second.next_event_deadline, None); assert!(!s.tick(t0 + ms(5000), None).reconcile); @@ -172,8 +179,8 @@ mod tests { let t0 = Instant::now(); let mut s = HotplugScheduler::new(t0, true); s.on_event(t0); - s.tick(t0 + ms(250), None); // follow-up due at +1250 - let now = t0 + ms(300); + s.tick(t0 + EVENT_DEBOUNCE, None); // follow-up due one recheck later + let now = t0 + EVENT_DEBOUNCE + ms(50); assert_eq!(s.on_event(now), Some(now + EVENT_DEBOUNCE)); // The new event restarts the reconcile + single follow-up cycle. assert!(s.tick(now + EVENT_DEBOUNCE, None).reconcile); From d70e255b768dea95d32bd5dd207b2457a82f893d Mon Sep 17 00:00:00 2001 From: Techmore Date: Wed, 21 Oct 2026 11:44:03 -0400 Subject: [PATCH 2/2] Record WD22TB4 plug-to-picture latency breakdown Co-Authored-By: Claude Sonnet 5.5 --- .../DOCK-LATENCY-BREAKDOWN.md | 41 +++++++++++++++++++ .../PORT-TIMINGS.md | 4 +- 2 files changed, 44 insertions(+), 1 deletion(-) create mode 100644 mseries/aurora/hardware-tests/2026-10-21-j314s-wip2-first-boot/DOCK-LATENCY-BREAKDOWN.md diff --git a/mseries/aurora/hardware-tests/2026-10-21-j314s-wip2-first-boot/DOCK-LATENCY-BREAKDOWN.md b/mseries/aurora/hardware-tests/2026-10-21-j314s-wip2-first-boot/DOCK-LATENCY-BREAKDOWN.md new file mode 100644 index 000000000..33bdfd54d --- /dev/null +++ b/mseries/aurora/hardware-tests/2026-10-21-j314s-wip2-first-boot/DOCK-LATENCY-BREAKDOWN.md @@ -0,0 +1,41 @@ +# WD22TB4 plug-to-picture latency breakdown — October 21, 2026 + +Millisecond-resolution decomposition from the kernel/compositor journal of one +boot (Aurora 7.2 wip2 kernel, J314S, WD22TB4, 1080p60 monitor). Eight plug +cycles across all three ports; every cycle lands within ±0.03 s of the table, so +the delay is deterministic, not intermittent. Complements the 0.5 s polling +pilot in [PORT-TIMINGS.md](PORT-TIMINGS.md); it does not replace owner +confirmation of visible pixels. + +| Stage | Time | Owner | Evidence in the journal | +| --- | --- | --- | --- | +| ACIO firmware boots, first lane-init attempt | 2.36 s | Apple ACIO firmware | `lane_init.c:936: Timeout reading AT register` ×21 at 100 ms, then `lane_init.c:954: SBX disconnected!` | +| Lane-init retry reaches Connected | 0.10 s | Apple ACIO firmware | `lane_init.c:1024: Entering Connected` | +| Connected to Thunderbolt device found | 0.53 s | firmware + `thunderbolt` | `lane=0/1 entered CL0!`, then `thunderbolt 0-1: new device found` | +| Device found to DCP `connected:1` | 1.00 s | kernel / boltd | retimer +0.24 s, boltd authorize done +0.66 s, DP tunnel (`allocated Type-C DPTX PHY`) +0.68 s, HPD +0.92 s, `dcp_hotplug() connected:1` +1.00 s | +| DCP `connected:1` to output mapped | 0.50 s | **compositor** | 250 ms `EVENT_DEBOUNCE` + ~245 ms synchronous DCP modeset in `initialize_output` | +| Total, firmware start to mapped | 4.50 s | | | + +Findings: + +* About 89 % of the time is below the compositor. The single largest item is + the ACIO firmware waiting 2.1 s for a sideband (AT) register read that the dock + does not answer on the first attempt; the retry succeeds 100 ms later. This is + the `lane_init.c:936` lead recorded on 2026-10-16 in + `mseries/fairydust/usb4/evidence/2026-10-16-hpd-fix-tested-module-only-rebuild.md`, + now attributed to a fixed per-plug cost. It is inside closed firmware; the + open question is whether the dock is simply not ready until ~2.3 s after + partner attach or whether the host could retry sooner. +* DP tunnel setup starts 20 ms after boltd finishes authorizing the dock (and + the PCIe-C cold init that follows), every cycle. USB is not gated by it (the dock hub + enumerates at +0.56 s, before authorization ends). Correlation only: test by + checking whether the DP tunnel can be established before PCIe-C init + (shared tunnel clocks, patch 0005) before changing boltd policy. +* Compositor share: the debounce was pure latency. The DCP uevent pair arrives + ~9 ms apart with all 26 modes already populated, so the debounce is now 40 ms + (about 210 ms saved per connect and per disconnect). The +1 s follow-up + reconcile is unchanged. +* The DCP modeset (~245 ms) blocks the compositor thread, so the internal panel + also stalls during it. Moving it off-thread is the next compositor-side item. +* The `link-status was Bad; reset to Good` write 32 ms after mapping is cheap + (DCP logs `Already set to timingID` and finishes in ~5 ms). diff --git a/mseries/aurora/hardware-tests/2026-10-21-j314s-wip2-first-boot/PORT-TIMINGS.md b/mseries/aurora/hardware-tests/2026-10-21-j314s-wip2-first-boot/PORT-TIMINGS.md index 624c09c15..2787421c7 100644 --- a/mseries/aurora/hardware-tests/2026-10-21-j314s-wip2-first-boot/PORT-TIMINGS.md +++ b/mseries/aurora/hardware-tests/2026-10-21-j314s-wip2-first-boot/PORT-TIMINGS.md @@ -36,7 +36,9 @@ right/rear, and about 0.5 s apart for front. Same-sample means below the observa resolution, not instantaneous disable. Separate detailed kernel/compositor lifecycle instrumentation is the next step for optimization. About 3 s precedes dock enumeration, so compositor-only changes cannot account for that entire -interval. Do not shorten debounce/recovery timers based on this pilot. +interval. Do not shorten debounce/recovery timers based on this pilot; the +millisecond-resolution [DOCK-LATENCY-BREAKDOWN.md](DOCK-LATENCY-BREAKDOWN.md) +is the evidence for the 40 ms hotplug debounce. The read-only poller is `mseries/hardware/dock-port-timing.py`; it requires an identity-bound hardware receipt from the running boot and a fresh private output