packaging/windows/drivers/pf-vdisplay/src/callbacks.rs

@@ -253,19 +253,67 @@ pub unsafe extern "C" fn monitor_query_modes2(
     STATUS_SUCCESS
 }
 
-/// Diagnostic only — assign drives everything. STEP 4 logs the committed paths.
+/// Read an `IDDCX_PATH*`'s `Flags` field as its underlying `u32`, without depending on the bindgen
+/// enum shape (newtype vs constified int): the field is a 4-byte `#[repr]` over `u32` either way, so
+/// a byte-read of it is the flag bits. `IDDCX_PATH_FLAGS_CHANGED = 0x1`, `_ACTIVE = 0x2` (IddCx.h).
+///
+/// # Safety
+/// `flags` must point at a live `IDDCX_PATH{,2}::Flags` field (4 readable bytes).
+unsafe fn path_flag_bits<T>(flags: &T) -> u32 {
+    // SAFETY: the caller passes a live `Flags` field; every IDDCX_PATH_FLAGS binding is a 4-byte
+    // scalar over u32, so reading it as u32 yields the flag bits regardless of the wrapper shape.
+    unsafe { core::ptr::read((flags as *const T).cast::<u32>()) }
+}
+
+/// Commit is a no-op for assign to drive — but the OS stamps each path ACTIVE/CHANGED here, and an
+/// active→inactive flip on OUR head (while a sibling stays active) is the driver-visible form of
+/// Enrico's hypothesis: the OS idles the virtual head like a physical one and the drain loop then
+/// sees only E_PENDING with no unassign. Log every commit's per-path flags so a hole can be lined
+/// up against a path the OS just deactivated. Low frequency (topology changes only).
 pub unsafe extern "C" fn adapter_commit_modes(
     _adapter: iddcx::IDDCX_ADAPTER,
-    _p_in: *const iddcx::IDARG_IN_COMMITMODES,
+    p_in: *const iddcx::IDARG_IN_COMMITMODES,
 ) -> NTSTATUS {
+    // SAFETY: the framework supplies a valid, live input-args pointer for the call.
+    let in_args = unsafe { &*p_in };
+    let count = in_args.PathCount;
+    for i in 0..count as usize {
+        // SAFETY: `pPaths` points to `PathCount` valid `IDDCX_PATH` entries (framework contract).
+        let path = unsafe { &*in_args.pPaths.add(i) };
+        // SAFETY: `path.Flags` is a live IDDCX_PATH_FLAGS field on the framework's path array.
+        let bits = unsafe { path_flag_bits(&path.Flags) };
+        dbglog!(
+            "[pf-vd] commit_modes: path[{i}/{count}] monitor={:?} active={} changed={} flags={bits:#x}",
+            path.MonitorObject,
+            bits & 0x2 != 0,
+            bits & 0x1 != 0
+        );
+    }
     STATUS_SUCCESS
 }
 
-/// HDR (`*2`) commit over `IDDCX_PATH2`. Mandatory under FP16.
+/// HDR (`*2`) commit over `IDDCX_PATH2`. Mandatory under FP16, and the one the OS actually calls
+/// once `CAN_PROCESS_FP16` is set — so this is where the ACTIVE/CHANGED flags land in practice.
+/// Same per-path logging as [`adapter_commit_modes`] (see its doc for why the flip matters).
 pub unsafe extern "C" fn adapter_commit_modes2(
     _adapter: iddcx::IDDCX_ADAPTER,
-    _p_in: *const iddcx::IDARG_IN_COMMITMODES2,
+    p_in: *const iddcx::IDARG_IN_COMMITMODES2,
 ) -> NTSTATUS {
+    // SAFETY: the framework supplies a valid, live input-args pointer for the call.
+    let in_args = unsafe { &*p_in };
+    let count = in_args.PathCount;
+    for i in 0..count as usize {
+        // SAFETY: `pPaths` points to `PathCount` valid `IDDCX_PATH2` entries (framework contract).
+        let path = unsafe { &*in_args.pPaths.add(i) };
+        // SAFETY: `path.Flags` is a live IDDCX_PATH_FLAGS field on the framework's path array.
+        let bits = unsafe { path_flag_bits(&path.Flags) };
+        dbglog!(
+            "[pf-vd] commit_modes2: path[{i}/{count}] monitor={:?} active={} changed={} flags={bits:#x}",
+            path.MonitorObject,
+            bits & 0x2 != 0,
+            bits & 0x1 != 0
+        );
+    }
     STATUS_SUCCESS
 }
 

packaging/windows/drivers/pf-vdisplay/src/swap_chain_processor.rs

@@ -44,7 +44,7 @@ use windows::{
             Direct3D11::{D3D11_TEXTURE2D_DESC, ID3D11Texture2D},
             Dxgi::{IDXGIDevice, IDXGIResource},
         },
-        System::Performance::QueryPerformanceCounter,
+        System::Performance::{QueryPerformanceCounter, QueryPerformanceFrequency},
         System::Threading::{
             AvRevertMmThreadCharacteristics, AvSetMmThreadCharacteristicsW, GetCurrentThread,
             SetThreadPriority, THREAD_PRIORITY_TIME_CRITICAL, WaitForSingleObject,
@@ -202,6 +202,26 @@ fn qpc() -> u64 {
     }
 }
 
+/// QPC ticks → whole milliseconds. Signed: a frame's display time can sit AFTER our acquire.
+fn qpc_ms(ticks: i64) -> i64 {
+    use std::sync::OnceLock;
+    static FREQ: OnceLock<i64> = OnceLock::new();
+    let f = *FREQ.get_or_init(|| {
+        let mut f = 0i64;
+        // SAFETY: out-pointer to a valid local; the frequency is fixed at boot.
+        let _ = unsafe { QueryPerformanceFrequency(&mut f) };
+        f.max(1)
+    });
+    ticks.saturating_mul(1000) / f
+}
+
+/// Wall-clock milliseconds since the Unix epoch — lines a driver-log witness up with host.log.
+fn unix_ms() -> u128 {
+    std::time::SystemTime::now()
+        .duration_since(std::time::UNIX_EPOCH)
+        .map_or(0, |d| d.as_millis())
+}
+
 /// A minimal newtype to move a raw pointer / handle across the thread boundary. The wrapped value is a
 /// raw IddCx swap-chain handle or an event HANDLE (both raw pointers, framework-managed) — sending them
 /// to the worker is sound because only this thread touches them and the framework synchronises lifetime.
@@ -475,6 +495,11 @@ impl SwapChainProcessor {
         // First `IddCxSwapChainReportFrameStatistics` outcome, logged once (the rest of the
         // session reports silently) so a field log answers "did the stats path engage".
         let mut logged_stats = false;
+        // Frame witness (see the success branch): the previous acquire's OS frame number and
+        // wall time, plus the last late-frame line's time (its throttle).
+        let mut last_pfn: u32 = 0;
+        let mut last_frame_at: Option<Instant> = None;
+        let mut last_late_log: Option<Instant> = None;
         // The frame-channel delivery gate (see `monitor::frame_channel_gen`): the loop only takes
         // the monitors mutex when a delivery LANDED since it last looked. Seeded one behind the
         // current generation so a delivery that arrived before this worker started (host delivered
@@ -621,6 +646,35 @@ impl SwapChainProcessor {
                 break;
             } else if hr_success(hr) {
                 let acquire_qpc = qpc();
+                // Frame witness: the two stamps the OS puts on every frame (`IDDCX_METADATA2`),
+                // which split a FRAME-GENERATION hole from inside the swap-chain. Logged when a
+                // frame ends >= 1 s of silence, or arrives >= 250 ms after its display time (at
+                // most one line per 2 s). Read the line as: a PresentationFrameNumber JUMP = DWM
+                // composed frames this swap-chain never received; +1 with a large `late` = the
+                // frames were composed on time and delivered late; +1 and fresh = DWM composed
+                // nothing for this head. `dirty=1` on a static desktop is the OS's no-update repeat.
+                let pfn = buffer.MetaData.PresentationFrameNumber;
+                let display_qpc = buffer.MetaData.PresentDisplayQPCTime;
+                #[allow(clippy::cast_possible_wrap)]
+                let late_ms =
+                    (display_qpc != 0).then(|| qpc_ms(acquire_qpc as i64 - display_qpc as i64));
+                let silence = last_frame_at.map_or(Duration::ZERO, |t| t.elapsed());
+                if silence >= Duration::from_secs(1)
+                    || (late_ms.is_some_and(|l| l >= 250)
+                        && last_late_log.is_none_or(|t| t.elapsed() >= Duration::from_secs(2)))
+                {
+                    dbglog!(
+                        "[pf-vd] frame-witness (target={target_id}) t={} silence={}ms pfn={pfn} (+{}) late={} dirty={}",
+                        unix_ms(),
+                        silence.as_millis(),
+                        pfn.wrapping_sub(last_pfn),
+                        late_ms.map_or("n/a".to_string(), |l| format!("{l}ms")),
+                        buffer.MetaData.DirtyRectCount
+                    );
+                    last_late_log = Some(Instant::now());
+                }
+                last_pfn = pfn;
+                last_frame_at = Some(Instant::now());
                 if !logged_frame {
                     dbglog!(
                         "[pf-vd] swap-chain run_core: FIRST FRAME acquired (target={target_id}) — DWM IS compositing the virtual display!"