From 06f709481a4e5e74bec961544c77e9afcae265db Mon Sep 17 00:00:00 2001 From: Emil Ernerfeldt Date: Fri, 20 Sep 2024 09:17:52 +0200 Subject: [PATCH] Keep track of why `request_discard` was called (#5134) This will help debug spurious calls to it --- crates/eframe/src/web/app_runner.rs | 4 +- crates/egui-winit/src/lib.rs | 4 +- crates/egui/src/context.rs | 98 ++++++++++++++++------- crates/egui/src/data/output.rs | 19 ++++- crates/egui/src/grid.rs | 2 +- crates/egui_demo_app/src/backend_panel.rs | 2 +- 6 files changed, 88 insertions(+), 41 deletions(-) diff --git a/crates/eframe/src/web/app_runner.rs b/crates/eframe/src/web/app_runner.rs index 4b7afebfa3a..00cc8f0c182 100644 --- a/crates/eframe/src/web/app_runner.rs +++ b/crates/eframe/src/web/app_runner.rs @@ -275,8 +275,8 @@ impl AppRunner { ime, #[cfg(feature = "accesskit")] accesskit_update: _, // not currently implemented - num_completed_passes: _, // handled by `Context::run` - requested_discard: _, // handled by `Context::run` + num_completed_passes: _, // handled by `Context::run` + request_discard_reasons: _, // handled by `Context::run` } = platform_output; super::set_cursor_icon(cursor_icon); diff --git a/crates/egui-winit/src/lib.rs b/crates/egui-winit/src/lib.rs index bbd68f8417a..7110ef3fe21 100644 --- a/crates/egui-winit/src/lib.rs +++ b/crates/egui-winit/src/lib.rs @@ -823,8 +823,8 @@ impl State { ime, #[cfg(feature = "accesskit")] accesskit_update, - num_completed_passes: _, // `egui::Context::run` handles this - requested_discard: _, // `egui::Context::run` handles this + num_completed_passes: _, // `egui::Context::run` handles this + request_discard_reasons: _, // `egui::Context::run` handles this } = platform_output; self.set_cursor_icon(window, cursor_icon); diff --git a/crates/egui/src/context.rs b/crates/egui/src/context.rs index 1b8ce29e116..13f1d7c4453 100644 --- a/crates/egui/src/context.rs +++ b/crates/egui/src/context.rs @@ -284,19 +284,28 @@ pub struct ViewportState { pub num_multipass_in_row: usize, } -/// What called [`Context::request_repaint`]? -#[derive(Clone)] +/// What called [`Context::request_repaint`] or [`Context::request_discard`]? +#[derive(Clone, PartialEq, Eq, Hash)] pub struct RepaintCause { /// What file had the call that requested the repaint? pub file: &'static str, /// What line number of the call that requested the repaint? pub line: u32, + + /// Explicit reason; human readable. + pub reason: Cow<'static, str>, } impl std::fmt::Debug for RepaintCause { fn fmt(&self, f: &mut std::fmt::Formatter<'_>) -> std::fmt::Result { - write!(f, "{}:{}", self.file, self.line) + write!(f, "{}:{} {}", self.file, self.line, self.reason) + } +} + +impl std::fmt::Display for RepaintCause { + fn fmt(&self, f: &mut std::fmt::Formatter<'_>) -> std::fmt::Result { + write!(f, "{}:{} {}", self.file, self.line, self.reason) } } @@ -309,13 +318,21 @@ impl RepaintCause { Self { file: caller.file(), line: caller.line(), + reason: "".into(), } } -} -impl std::fmt::Display for RepaintCause { - fn fmt(&self, f: &mut std::fmt::Formatter<'_>) -> std::fmt::Result { - write!(f, "{}:{}", self.file, self.line) + /// Capture the file and line number of the call site, + /// as well as add a reason. + #[allow(clippy::new_without_default)] + #[track_caller] + pub fn new_reason(reason: impl Into>) -> Self { + let caller = Location::caller(); + Self { + file: caller.file(), + line: caller.line(), + reason: reason.into(), + } } } @@ -791,7 +808,7 @@ impl Context { let viewport = ctx.viewport_for(viewport_id); viewport.output.num_completed_passes = std::mem::take(&mut output.platform_output.num_completed_passes); - output.platform_output.requested_discard = false; + output.platform_output.request_discard_reasons.clear(); }); self.begin_pass(new_input.take()); @@ -799,13 +816,13 @@ impl Context { output.append(self.end_pass()); debug_assert!(0 < output.platform_output.num_completed_passes); - if !output.platform_output.requested_discard { + if !output.platform_output.requested_discard() { break; // no need for another pass } if max_passes <= output.platform_output.num_completed_passes { #[cfg(feature = "log")] - log::debug!("Ignoring call request_discard, because max_passes={max_passes}"); + log::debug!("Ignoring call request_discard, because max_passes={max_passes}. Requested from {:?}", output.platform_output.request_discard_reasons); break; } @@ -1641,8 +1658,14 @@ impl Context { /// /// You should be very conservative with when you call [`Self::request_discard`], /// as it will cause an extra ui pass, potentially leading to extra CPU use and frame judder. - pub fn request_discard(&self) { - self.output_mut(|o| o.requested_discard = true); + /// + /// The given reason should be a human-readable string that explains why `request_discard` + /// was called. This will be shown in certain debug situations, to help you figure out + /// why a pass was discarded. + #[track_caller] + pub fn request_discard(&self, reason: impl Into>) { + let cause = RepaintCause::new_reason(reason); + self.output_mut(|o| o.request_discard_reasons.push(cause)); #[cfg(feature = "log")] log::trace!( @@ -1664,7 +1687,7 @@ impl Context { self.write(|ctx| { let vp = ctx.viewport(); // NOTE: `num_passes` is incremented - vp.output.requested_discard + vp.output.requested_discard() && vp.output.num_completed_passes + 1 < ctx.memory.options.max_passes.get() }) } @@ -2197,12 +2220,16 @@ impl Context { if 3 <= num_multipass_in_row { // If you see this message, it means we've been paying the cost of multi-pass for multiple frames in a row. // This is likely a bug. `request_discard` should only be called in rare situations, when some layout changes. - self.debug_painter().debug_text( - Pos2::ZERO, - Align2::LEFT_TOP, - Color32::RED, - format!("egui PERF WARNING: request_discard has been called {num_multipass_in_row} frames in a row"), - ); + + let mut warning = format!("egui PERF WARNING: request_discard has been called {num_multipass_in_row} frames in a row"); + self.viewport(|vp| { + for reason in &vp.output.request_discard_reasons { + warning += &format!("\n {reason}"); + } + }); + + self.debug_painter() + .debug_text(Pos2::ZERO, Align2::LEFT_TOP, Color32::RED, warning); } } } @@ -3734,12 +3761,12 @@ mod test { let output = ctx.run(Default::default(), |ctx| { num_calls += 1; assert_eq!(ctx.output(|o| o.num_completed_passes), 0); - assert!(!ctx.output(|o| o.requested_discard)); + assert!(!ctx.output(|o| o.requested_discard())); assert!(!ctx.will_discard()); }); assert_eq!(num_calls, 1); assert_eq!(output.platform_output.num_completed_passes, 1); - assert!(!output.platform_output.requested_discard); + assert!(!output.platform_output.requested_discard()); } // A single call, with a denied request to discard: @@ -3747,15 +3774,24 @@ mod test { let mut num_calls = 0; let output = ctx.run(Default::default(), |ctx| { num_calls += 1; - ctx.request_discard(); + ctx.request_discard("test"); assert!(!ctx.will_discard(), "The request should have been denied"); }); assert_eq!(num_calls, 1); assert_eq!(output.platform_output.num_completed_passes, 1); assert!( - output.platform_output.requested_discard, + output.platform_output.requested_discard(), "The request should be reported" ); + assert_eq!( + output + .platform_output + .request_discard_reasons + .first() + .unwrap() + .reason, + "test" + ); } } @@ -3769,13 +3805,13 @@ mod test { let mut num_calls = 0; let output = ctx.run(Default::default(), |ctx| { assert_eq!(ctx.output(|o| o.num_completed_passes), 0); - assert!(!ctx.output(|o| o.requested_discard)); + assert!(!ctx.output(|o| o.requested_discard())); assert!(!ctx.will_discard()); num_calls += 1; }); assert_eq!(num_calls, 1); assert_eq!(output.platform_output.num_completed_passes, 1); - assert!(!output.platform_output.requested_discard); + assert!(!output.platform_output.requested_discard()); } // Request discard once: @@ -3786,7 +3822,7 @@ mod test { assert!(!ctx.will_discard()); if num_calls == 0 { - ctx.request_discard(); + ctx.request_discard("test"); assert!(ctx.will_discard()); } @@ -3795,7 +3831,7 @@ mod test { assert_eq!(num_calls, 2); assert_eq!(output.platform_output.num_completed_passes, 2); assert!( - !output.platform_output.requested_discard, + !output.platform_output.requested_discard(), "The request should have been cleared when fulfilled" ); } @@ -3807,7 +3843,7 @@ mod test { assert_eq!(ctx.output(|o| o.num_completed_passes), num_calls); assert!(!ctx.will_discard()); - ctx.request_discard(); + ctx.request_discard("test"); if num_calls == 0 { assert!(ctx.will_discard(), "First request granted"); } else { @@ -3819,7 +3855,7 @@ mod test { assert_eq!(num_calls, 2); assert_eq!(output.platform_output.num_completed_passes, 2); assert!( - output.platform_output.requested_discard, + output.platform_output.requested_discard(), "The unfulfilled request should be reported" ); } @@ -3838,7 +3874,7 @@ mod test { assert!(!ctx.will_discard()); if num_calls <= 2 { - ctx.request_discard(); + ctx.request_discard("test"); assert!(ctx.will_discard()); } @@ -3847,7 +3883,7 @@ mod test { assert_eq!(num_calls, 4); assert_eq!(output.platform_output.num_completed_passes, 4); assert!( - !output.platform_output.requested_discard, + !output.platform_output.requested_discard(), "The request should have been cleared when fulfilled" ); } diff --git a/crates/egui/src/data/output.rs b/crates/egui/src/data/output.rs index 2d967c67be1..94abc1954c6 100644 --- a/crates/egui/src/data/output.rs +++ b/crates/egui/src/data/output.rs @@ -1,6 +1,6 @@ //! All the data egui returns to the backend at the end of each frame. -use crate::{ViewportIdMap, ViewportOutput, WidgetType}; +use crate::{RepaintCause, ViewportIdMap, ViewportOutput, WidgetType}; /// What egui emits each frame from [`crate::Context::run`]. /// @@ -133,7 +133,12 @@ pub struct PlatformOutput { pub num_completed_passes: usize, /// Was [`crate::Context::request_discard`] called during the latest pass? - pub requested_discard: bool, + /// + /// If so, what was the reason(s) for it? + /// + /// If empty, there was never any calls. + #[cfg_attr(feature = "serde", serde(skip))] + pub request_discard_reasons: Vec, } impl PlatformOutput { @@ -167,7 +172,7 @@ impl PlatformOutput { #[cfg(feature = "accesskit")] accesskit_update, num_completed_passes, - requested_discard, + mut request_discard_reasons, } = newer; self.cursor_icon = cursor_icon; @@ -181,7 +186,8 @@ impl PlatformOutput { self.mutable_text_under_cursor = mutable_text_under_cursor; self.ime = ime.or(self.ime); self.num_completed_passes += num_completed_passes; - self.requested_discard |= requested_discard; + self.request_discard_reasons + .append(&mut request_discard_reasons); #[cfg(feature = "accesskit")] { @@ -197,6 +203,11 @@ impl PlatformOutput { self.cursor_icon = taken.cursor_icon; // everything else is ephemeral taken } + + /// Was [`crate::Context::request_discard`] called? + pub fn requested_discard(&self) -> bool { + !self.request_discard_reasons.is_empty() + } } /// What URL to open, and how. diff --git a/crates/egui/src/grid.rs b/crates/egui/src/grid.rs index 9b3a382ee23..3c4986fcad0 100644 --- a/crates/egui/src/grid.rs +++ b/crates/egui/src/grid.rs @@ -440,7 +440,7 @@ impl Grid { if ui.is_visible() { // Try to cover up the glitchy initial frame: - ui.ctx().request_discard(); + ui.ctx().request_discard("new Grid"); } // Hide the ui this frame, and make things as narrow as possible: diff --git a/crates/egui_demo_app/src/backend_panel.rs b/crates/egui_demo_app/src/backend_panel.rs index b1df6f417ea..21c35cd9229 100644 --- a/crates/egui_demo_app/src/backend_panel.rs +++ b/crates/egui_demo_app/src/backend_panel.rs @@ -164,7 +164,7 @@ impl BackendPanel { ui.horizontal(|ui| { if ui.button("Request discard").clicked() { - ui.ctx().request_discard(); + ui.ctx().request_discard("Manual button click"); if !ui.ctx().will_discard() { ui.label("Discard denied!");