fix(state_portal): remove filler + accept Wayland damage-driven delivery (fixes #15, fixes #18)

Paradigm shift: stop treating KWin's damage-driven frame delivery as an
anomaly. Static content = no new frames is correct Wayland behavior.

Root causes (combined #15 + #18):

#15: stall detection threshold was 100ms (max(100ms, 3*frame_interval)).
KWin/PipeWire damage-driven delivery meant normal static periods triggered
WARN 'compositor frame delivery stalled' continuously. Test3 data showed
55% stall rate during active streaming (38 stalls in 69s). User perceived
severe stutter pattern 'cardboard-effect freeze-release-freeze'.

#18: filler mechanism (maybe_send_filler_frame) cloned 3MB NV12 data and
sent to encode thread during stalls. Encode thread hashed Y plane, found
duplicate, skipped via dedup. Net: wasted CPU + channel bandwidth with
zero visual benefit (the dedup path was already catching it).

Oracle review revealed the two issues are causally linked: filler is the
failed response to the false stall alarm. Removing both together is correct.

Fixes (all in state_portal.rs):

1. Remove filler mechanism entirely:
   - Remove fields: last_fillable_frame, next_filler_at, filler_frames_sent
   - Remove method: maybe_send_filler_frame (49 lines)
   - Remove constant: MAX_FILLER_DURATION
   - Remove fillable_frame clone cascade in handle_pw_frame (10 lines
     of 3MB NV12 cloning per frame, the largest CPU/memory win)
   - Remove filler_frames_sent from stats output

2. Redefine stall as idle (Oracle-revised):
   - Rename: stall_start -> idle_log_start (semantic clarity)
   - Change threshold: 100ms -> 5s (CAPTURE_IDLE_LOG_THRESHOLD)
   - Change log level: WARN -> DEBUG
   - Change wording: 'compositor frame delivery stalled' ->
     'portal capture idle; no damage frames received (normal Wayland behavior)'
   - One-shot log per idle episode (not repeated every second)
   - Use last_capture_arrival as idle start for accurate elapsed duration
     (old code set stall_start=now at first detection, undercounting by
     threshold value)

Explicit product decision (Oracle flagged trade-off):

  Static-content PLI repair is deferred. When WebRTC client sends PLI
  during static content:
  - Server sets force_keyframe_pending in encode thread
  - Encode thread blocks on input_rx.recv() (no frames coming)
  - Client may send more PLIs (all rate-limited by #23 to 1/sec)
  - When user interacts -> KWin delivers frame -> encode thread produces IDR

  This means during fully static content, client may wait for next damage
  to receive keyframe. Acceptable because static content is by definition
  unchanged - the last received frame is still visually accurate. If user
  reports unacceptable PLI latency on static screens, follow-up with
  event-driven one-shot IDR mechanism (Option B per Oracle).

Verification expectation:
  - Zero WARN 'stalled' messages during normal session
  - Optional DEBUG 'portal capture idle' after 5s of no frames
  - Optional DEBUG 'portal capture resumed after idle period' on recovery
  - capture_fps will still vary with content activity (this is correct)
  - encoded_fps will only count real frames (filler no longer inflates it)

Out of scope:
  - Event-driven cached-frame IDR (Option B): follow-up if needed
  - PipeWire CursorFromCache negotiation: separate enhancement
  - capture_fps expectations documentation: defer to #20 stats rework

Tests:
  - cargo build --release: clean, no new warnings
  - cargo test: 91 passed + 3 passed + 0 failed
  - SAFETY comments preserved verbatim
  - Net change: -80 lines (20 insertions, 100 deletions)

Closes #15, closes #18.
This commit is contained in:
dailz
2026-06-20 20:56:34 +08:00
parent 9a522e2f99
commit 2f0b858920
+20 -100
View File
@@ -62,11 +62,7 @@ pub struct StatePortal {
webrtc_thread: Option<WebrtcThread>, webrtc_thread: Option<WebrtcThread>,
webrtc_paused: Option<Arc<AtomicBool>>, webrtc_paused: Option<Arc<AtomicBool>>,
last_capture_arrival: Option<Instant>, // timestamp of last real frame arrival last_capture_arrival: Option<Instant>, // timestamp of last real frame arrival
stall_start: Option<Instant>, // when current stall began idle_log_start: Option<Instant>, // when current idle period began (one-shot DEBUG log guard)
last_stall_log: Option<Instant>, // rate-limiting for stall warnings
last_fillable_frame: Option<CpuNv12Frame>, // cached last frame for filler duplication
next_filler_at: Option<Instant>, // when to send next filler frame
filler_frames_sent: u64,
shutdown_started: bool, // idempotency guard; plain bool because &mut self is exclusive (not AtomicBool) shutdown_started: bool, // idempotency guard; plain bool because &mut self is exclusive (not AtomicBool)
} }
@@ -109,11 +105,7 @@ impl StatePortal {
webrtc_thread: None, webrtc_thread: None,
webrtc_paused, webrtc_paused,
last_capture_arrival: None, last_capture_arrival: None,
stall_start: None, idle_log_start: None,
last_stall_log: None,
last_fillable_frame: None,
next_filler_at: None,
filler_frames_sent: 0,
shutdown_started: false, shutdown_started: false,
}) })
} }
@@ -355,14 +347,7 @@ impl StatePortal {
} }
} }
let snap = self.stats.snapshot_and_reset(); let snap = self.stats.snapshot_and_reset();
if self.filler_frames_sent > 0 { tracing::info!("stats: {snap}");
tracing::info!(
"stats: {snap} filler_frames_sent={}",
self.filler_frames_sent
);
} else {
tracing::info!("stats: {snap}");
}
} }
Ok(true) Ok(true)
@@ -374,89 +359,33 @@ impl StatePortal {
}; };
let now = Instant::now(); let now = Instant::now();
let frame_interval = Duration::from_secs_f64(1.0 / f64::from(self.args.fps.max(1))); // Wayland damage-driven delivery: static content means no new frames.
let stall_threshold = Duration::from_millis(100).max(frame_interval * 3); // This is normal Wayland behavior, not a compositor hang. Only log DEBUG
if now.duration_since(last_capture_arrival) <= stall_threshold { // after a meaningful idle period, and only once per idle episode.
// See issues #15 and #18.
const CAPTURE_IDLE_LOG_THRESHOLD: Duration = Duration::from_secs(5);
if now.duration_since(last_capture_arrival) <= CAPTURE_IDLE_LOG_THRESHOLD {
return; return;
} }
if self.stall_start.is_none() { if self.idle_log_start.is_none() {
self.stall_start = Some(now); // Use last_capture_arrival as idle start for accurate elapsed duration.
self.last_stall_log = Some(now); self.idle_log_start = Some(last_capture_arrival);
tracing::warn!("compositor frame delivery stalled"); tracing::debug!(
} else { elapsed_ms = now.duration_since(last_capture_arrival).as_millis(),
let should_log = self.last_stall_log.map_or(true, |last_log| { "portal capture idle; no damage frames received (normal Wayland behavior)"
now.duration_since(last_log) >= Duration::from_secs(1) );
});
if should_log {
self.last_stall_log = Some(now);
tracing::warn!("compositor frame delivery stalled");
}
}
self.maybe_send_filler_frame();
}
fn maybe_send_filler_frame(&mut self) {
if self.webrtc_thread.is_none() || self.stall_start.is_none() {
return;
}
let Some(cached) = &self.last_fillable_frame else {
return;
};
const MAX_FILLER_DURATION: Duration = Duration::from_secs(2);
if let Some(stall_start) = self.stall_start {
if stall_start.elapsed() > MAX_FILLER_DURATION {
return;
}
}
let now = Instant::now();
let frame_interval = Duration::from_secs_f64(1.0 / f64::from(self.args.fps.max(1)));
let Some(next) = self.next_filler_at else {
self.next_filler_at = Some(now + frame_interval);
return;
};
if now < next {
return;
}
let filler = CpuNv12Frame {
y_data: cached.y_data.clone(),
uv_data: cached.uv_data.clone(),
y_stride: cached.y_stride,
uv_stride: cached.uv_stride,
pts: self.frames_encoded as i64,
};
if let Some(enc_thread) = &self.enc_thread {
match enc_thread.input_tx.try_send(filler) {
Ok(()) => {
self.frames_encoded += 1;
self.filler_frames_sent += 1;
self.next_filler_at = Some(next + frame_interval);
}
Err(crossbeam_channel::TrySendError::Full(_)) => {}
Err(crossbeam_channel::TrySendError::Disconnected(_)) => {
tracing::error!("Encode thread disconnected during filler");
self.errored = true;
}
}
} }
} }
fn record_frame_arrival(&mut self) { fn record_frame_arrival(&mut self) {
if let Some(stall_start) = self.stall_start.take() { if let Some(idle_start) = self.idle_log_start.take() {
tracing::info!( tracing::debug!(
"compositor frame delivery resumed after {:.0}ms", idle_ms = idle_start.elapsed().as_millis(),
stall_start.elapsed().as_secs_f64() * 1000.0 "portal capture resumed after idle period"
); );
self.last_stall_log = None;
} }
self.last_capture_arrival = Some(Instant::now()); self.last_capture_arrival = Some(Instant::now());
self.next_filler_at = None;
} }
/// 为当前帧解析可用的 DRM 渲染设备 /// 为当前帧解析可用的 DRM 渲染设备
@@ -589,17 +518,9 @@ impl StatePortal {
"internal invariant broken: encode thread missing while async import is active" "internal invariant broken: encode thread missing while async import is active"
) )
})?; })?;
let fillable_frame = CpuNv12Frame {
y_data: cpu_nv12.y_data.clone(),
uv_data: cpu_nv12.uv_data.clone(),
y_stride: cpu_nv12.y_stride,
uv_stride: cpu_nv12.uv_stride,
pts: 0,
};
match enc_thread.input_tx.try_send(cpu_nv12) { match enc_thread.input_tx.try_send(cpu_nv12) {
Ok(()) => { Ok(()) => {
self.frames_encoded += 1; self.frames_encoded += 1;
self.last_fillable_frame = Some(fillable_frame);
} }
Err(crossbeam_channel::TrySendError::Full(_)) => { Err(crossbeam_channel::TrySendError::Full(_)) => {
tracing::debug!("Encode thread input full, dropping portal frame"); tracing::debug!("Encode thread input full, dropping portal frame");
@@ -625,7 +546,6 @@ impl StatePortal {
} }
self.shutdown_started = true; self.shutdown_started = true;
self.last_fillable_frame = None;
// 1. Stop encode thread (drops webrtc_tx → signals WebRTC thread to exit) // 1. Stop encode thread (drops webrtc_tx → signals WebRTC thread to exit)
if let Some(mut enc_thread) = self.enc_thread.take() { if let Some(mut enc_thread) = self.enc_thread.take() {
drop(enc_thread.input_tx); drop(enc_thread.input_tx);