Commit 32fbd7e2725c
tarball2 files changed+115-16
@@ -82,16 +82,17 @@ impl Surface {
8282
if refresh == 0 {8383
return None;8484
}85
- let earliest = now + self.budget.ns();86
- let periods = earliest.saturating_sub(last).div_ceil(refresh).max(1);85
+ let budget = self.budget.ns().min(refresh);86
+ let periods = (now + budget).saturating_sub(last).div_ceil(refresh).max(1);8787
let vblank = last + periods * refresh;88
- Some((vblank, vblank - self.budget.ns()))88
+ Some((vblank, vblank - budget))8989
}9090
}9191
92
-/// How long before a vblank rendering must start. The worst recent CPU93
-/// render time covers the CPU side, and a slack that grows on every missed94
-/// vblank and slowly shrinks while frames land covers GPU time and the commit.92
+/// How long before a vblank rendering must start. A high percentile of93
+/// recent CPU render times covers the CPU side without one spike inflating94
+/// it, and a slack that grows on every missed vblank and shrinks over seconds95
+/// while frames land covers GPU time and the commit.9596
struct Budget {9697
renders: VecDeque<u64>,9798
slack_ns: u64,@@ -101,7 +102,7 @@ impl Budget {
101102
const KEEP: usize = 32;102103
const MIN_SLACK_NS: u64 = 1_000_000;103104
const STEP_NS: u64 = 500_000;104
- const DECAY_NS: u64 = 10_000;105
+ const DECAY_NS: u64 = 1_000;105106
106107
fn new() -> Self {107108
Self {@@ -111,7 +112,13 @@ impl Budget {
111112
}112113
113114
fn ns(&self) -> u64 {114
- self.renders.iter().max().copied().unwrap_or(0) + self.slack_ns115
+ let mut renders: Vec<u64> = self.renders.iter().copied().collect();116
+ renders.sort_unstable();117
+ let p90 = renders118
+ .get(renders.len().saturating_sub(1) * 9 / 10)119
+ .copied()120
+ .unwrap_or(0);121
+ p90 + self.slack_ns115122
}116123
117124
fn record(&mut self, render_ns: u64) {@@ -543,6 +550,7 @@ fn render_surface(state: &mut State, crtc: crtc::Handle, target: u64) -> bool {
543550
if local.x >= 0.0 && local.y >= 0.0 && local.x < area.w && local.y < area.h {544551
elements.extend(cursor.elements(renderer, cursor_status, local));545552
}553
+ let scene_began = std::time::Instant::now();546554
elements.extend(crate::scene::build(547555
layout,548556
surface.id,@@ -553,23 +561,38 @@ fn render_surface(state: &mut State, crtc: crtc::Handle, target: u64) -> bool {
553561
&config.decoration,554562
borders,555563
));564
+ let scene_ns = scene_began.elapsed().as_nanos() as u64;556565
let animating = anim.active(now);557566
anim.prune(now);567
+ let render_began = std::time::Instant::now();568
+ let mut queue_ns = 0;558569
match surface559570
.drm560571
.render_frame(renderer, &elements, CLEAR, FrameFlags::DEFAULT)561572
{562
- Ok(result) if !result.is_empty => match surface.drm.queue_frame(()) {563
- Ok(()) => surface.queued = true,564
- Err(e) => tracing::warn!("queueing a frame failed: {e}"),565
- },573
+ Ok(result) if !result.is_empty => {574
+ let queue_began = std::time::Instant::now();575
+ match surface.drm.queue_frame(()) {576
+ Ok(()) => surface.queued = true,577
+ Err(e) => tracing::warn!("queueing a frame failed: {e}"),578
+ }579
+ queue_ns = queue_began.elapsed().as_nanos() as u64;580
+ }566581
Ok(_) => {}567582
Err(e) => tracing::warn!("rendering failed: {e}"),568583
}584
+ let render_ns = render_began.elapsed().as_nanos() as u64 - queue_ns;569585
let took = began.elapsed().as_nanos() as u64;570586
surface.budget.record(took);571587
if took > surface.refresh_ns / 2 {572
- tracing::debug!(output = surface.output.name(), took_ns = took, "slow frame");588
+ tracing::debug!(589
+ output = surface.output.name(),590
+ took_ns = took,591
+ scene_ns,592
+ render_ns,593
+ queue_ns,594
+ "slow frame"595
+ );573596
}574597
if !surface.queued {575598
surface.target_ns = None;@@ -1,5 +1,81 @@
1
- Finished `dev` profile [unoptimized + debuginfo] target(s) in 0.06s2
- Running `target/debug/monolith run --backend drm , vkcube`1
+ Finished `release` profile [optimized] target(s) in 0.07s2
+ Running `target/release/monolith run --backend drm , vkcube`3
+2026-10-16T13:18:42.960033Z INFO monolith::drm: primary GPU path=/dev/dri/card14
+2026-10-16T13:18:43.191440Z INFO monolith::drm: output connected name="DP-2" w=2560 h=1440 refresh=1655
+2026-10-16T13:18:43.191538Z INFO monolith::ipc: control socket path=/run/user/1000/monolith-wayland-2.sock6
+2026-10-16T13:18:43.191556Z INFO monolith: monolith running socket="wayland-2" device="NVIDIA GeForce RTX 3060"7
+2026-10-16T13:18:43.192099Z INFO monolith::commands: spawned pid=339299 argv=[",", "vkcube"]8
+2026-10-16T13:18:43.206596Z DEBUG monolith::drm: slow frame output="DP-2" took_ns=144188239
+2026-10-16T13:18:43.212094Z DEBUG monolith::drm: frame rate output="DP-2" presented=1 vblanks=8355033 budget_us=16418310
Selected WSI platform: wayland411
Selected GPU 0: NVIDIA GeForce RTX 3060, type: DiscreteGpu, apiVersion: 4211017 (1.4.329), driverVersion: -1797652352 (83.416.128) 5
-Io error: Broken pipe (os error 32)12
+2026-10-16T13:18:44.212377Z DEBUG monolith::drm: frame rate output="DP-2" presented=80 vblanks=165 budget_us=178413
+2026-10-16T13:18:45.212592Z DEBUG monolith::drm: frame rate output="DP-2" presented=165 vblanks=164 budget_us=147314
+2026-10-16T13:18:45.497520Z DEBUG monolith::drm: frame missed its vblank output="DP-2" late_ns=6009851 budget_ns=276455615
+2026-10-16T13:18:45.830980Z DEBUG monolith::drm: frame missed its vblank output="DP-2" late_ns=6064851 budget_ns=195591916
+2026-10-16T13:18:46.212848Z DEBUG monolith::drm: frame rate output="DP-2" presented=163 vblanks=164 budget_us=137417
+2026-10-16T13:18:47.190680Z DEBUG monolith::drm: slow frame output="DP-2" took_ns=342637018
+2026-10-16T13:18:47.194947Z DEBUG monolith::drm: frame missed its vblank output="DP-2" late_ns=6049851 budget_ns=492637019
+2026-10-16T13:18:47.213154Z DEBUG monolith::drm: frame rate output="DP-2" presented=164 vblanks=165 budget_us=489620
+2026-10-16T13:18:48.213491Z DEBUG monolith::drm: frame rate output="DP-2" presented=165 vblanks=165 budget_us=174321
+2026-10-16T13:18:49.140885Z DEBUG monolith::drm: frame missed its vblank output="DP-2" late_ns=5945851 budget_ns=196555922
+2026-10-16T13:18:49.213628Z DEBUG monolith::drm: frame rate output="DP-2" presented=164 vblanks=164 budget_us=186023
+2026-10-16T13:18:49.225750Z DEBUG monolith::drm: frame missed its vblank output="DP-2" late_ns=6058851 budget_ns=236021024
+2026-10-16T13:18:49.874409Z DEBUG monolith::drm: frame missed its vblank output="DP-2" late_ns=5916851 budget_ns=388797825
+2026-10-16T13:18:50.214055Z DEBUG monolith::drm: frame rate output="DP-2" presented=163 vblanks=165 budget_us=165326
+2026-10-16T13:18:51.214172Z DEBUG monolith::drm: frame rate output="DP-2" presented=165 vblanks=164 budget_us=163627
+2026-10-16T13:18:51.769798Z DEBUG monolith::input: bind cmd=Fullscreen28
+2026-10-16T13:18:51.830166Z DEBUG monolith::drm: slow frame output="DP-2" took_ns=1102304429
+2026-10-16T13:18:51.838579Z DEBUG monolith::drm: frame missed its vblank output="DP-2" late_ns=30315404 budget_ns=1252304430
+2026-10-16T13:18:52.214455Z DEBUG monolith::drm: frame rate output="DP-2" presented=126 vblanks=164 budget_us=1221331
+2026-10-16T13:18:53.214677Z DEBUG monolith::drm: frame rate output="DP-2" presented=164 vblanks=165 budget_us=143032
+2026-10-16T13:18:54.215041Z DEBUG monolith::drm: frame rate output="DP-2" presented=165 vblanks=165 budget_us=145233
+2026-10-16T13:18:55.215200Z DEBUG monolith::drm: frame rate output="DP-2" presented=165 vblanks=164 budget_us=144234
+2026-10-16T13:18:55.403154Z DEBUG monolith::drm: frame missed its vblank output="DP-2" late_ns=6061851 budget_ns=191401835
+2026-10-16T13:18:56.106336Z DEBUG monolith::drm: frame missed its vblank output="DP-2" late_ns=6057851 budget_ns=194270936
+2026-10-16T13:18:56.215463Z DEBUG monolith::drm: frame rate output="DP-2" presented=163 vblanks=165 budget_us=169337
+2026-10-16T13:18:56.332434Z DEBUG monolith::drm: slow frame output="DP-2" took_ns=340053938
+2026-10-16T13:18:56.336731Z DEBUG monolith::drm: frame missed its vblank output="DP-2" late_ns=6072851 budget_ns=504053939
+2026-10-16T13:18:56.399771Z DEBUG monolith::input: bind cmd=Fullscreen40
+2026-10-16T13:18:56.462019Z DEBUG monolith::drm: slow frame output="DP-2" took_ns=725595741
+2026-10-16T13:18:56.470071Z DEBUG monolith::drm: frame missed its vblank output="DP-2" late_ns=24228404 budget_ns=925595742
+2026-10-16T13:18:56.682281Z DEBUG monolith::drm: frame missed its vblank output="DP-2" late_ns=6073851 budget_ns=261296943
+2026-10-16T13:18:56.694386Z DEBUG monolith::drm: frame missed its vblank output="DP-2" late_ns=6049851 budget_ns=311296944
+2026-10-16T13:18:56.809547Z DEBUG monolith::drm: frame missed its vblank output="DP-2" late_ns=6062851 budget_ns=344296945
+2026-10-16T13:18:57.215731Z DEBUG monolith::drm: frame rate output="DP-2" presented=153 vblanks=165 budget_us=275146
+2026-10-16T13:18:58.161784Z DEBUG monolith::input: bind cmd=Spawn { argv: ["beer"] }47
+2026-10-16T13:18:58.162414Z INFO monolith::commands: spawned pid=339323 argv=["beer"]48
+2026-10-16T13:18:58.197792Z DEBUG monolith::drm: frame missed its vblank output="DP-2" late_ns=6063851 budget_ns=386744849
+2026-10-16T13:18:58.215976Z DEBUG monolith::drm: frame rate output="DP-2" presented=164 vblanks=165 budget_us=383750
+2026-10-16T13:18:58.271072Z DEBUG monolith::drm: slow frame output="DP-2" took_ns=1041169251
+2026-10-16T13:18:58.276596Z DEBUG monolith::drm: frame missed its vblank output="DP-2" late_ns=12125255 budget_ns=1235169252
+2026-10-16T13:18:59.216233Z DEBUG monolith::drm: frame rate output="DP-2" presented=132 vblanks=165 budget_us=152553
+2026-10-16T13:18:59.432766Z DEBUG monolith::input: bind cmd=Spawn { argv: ["beer"] }54
+2026-10-16T13:18:59.433294Z INFO monolith::commands: spawned pid=339344 argv=["beer"]55
+2026-10-16T13:18:59.458728Z DEBUG monolith::drm: frame missed its vblank output="DP-2" late_ns=6063851 budget_ns=279677656
+2026-10-16T13:18:59.495745Z DEBUG monolith::drm: slow frame output="DP-2" took_ns=425081757
+2026-10-16T13:18:59.501210Z DEBUG monolith::drm: frame missed its vblank output="DP-2" late_ns=6080553 budget_ns=622081758
+2026-10-16T13:19:00.216526Z DEBUG monolith::drm: frame rate output="DP-2" presented=142 vblanks=165 budget_us=145759
+2026-10-16T13:19:00.835760Z DEBUG monolith::input: bind cmd=Move { dir: Left }60
+2026-10-16T13:19:00.853017Z DEBUG monolith::drm: frame missed its vblank output="DP-2" late_ns=6064851 budget_ns=345144961
+2026-10-16T13:19:01.216794Z DEBUG monolith::drm: frame rate output="DP-2" presented=164 vblanks=164 budget_us=146262
+2026-10-16T13:19:02.087739Z DEBUG monolith::input: bind cmd=InvertMove63
+2026-10-16T13:19:02.217007Z DEBUG monolith::drm: frame rate output="DP-2" presented=165 vblanks=164 budget_us=138164
+2026-10-16T13:19:02.344360Z DEBUG monolith::drm: frame missed its vblank output="DP-2" late_ns=6068851 budget_ns=178889565
+2026-10-16T13:19:02.441740Z DEBUG monolith::input: bind cmd=Move { dir: Right }66
+2026-10-16T13:19:02.497884Z DEBUG monolith::drm: slow frame output="DP-2" took_ns=423219667
+2026-10-16T13:19:02.501941Z DEBUG monolith::drm: frame missed its vblank output="DP-2" late_ns=6062553 budget_ns=601219668
+2026-10-16T13:19:02.786857Z DEBUG monolith::drm: frame missed its vblank output="DP-2" late_ns=6063851 budget_ns=465429769
+2026-10-16T13:19:03.217269Z DEBUG monolith::drm: frame rate output="DP-2" presented=159 vblanks=165 budget_us=158770
+2026-10-16T13:19:04.217526Z DEBUG monolith::drm: frame rate output="DP-2" presented=165 vblanks=165 budget_us=146771
+2026-10-16T13:19:04.781348Z DEBUG monolith::drm: frame missed its vblank output="DP-2" late_ns=6070851 budget_ns=313079372
+2026-10-16T13:19:05.217834Z DEBUG monolith::drm: frame rate output="DP-2" presented=164 vblanks=165 budget_us=144273
+2026-10-16T13:19:05.633029Z DEBUG monolith::drm: slow frame output="DP-2" took_ns=1919493974
+2026-10-16T13:19:05.636097Z DEBUG monolith::drm: frame missed its vblank output="DP-2" late_ns=42437851 budget_ns=2069493975
+2026-10-16T13:19:06.218058Z DEBUG monolith::drm: frame rate output="DP-2" presented=158 vblanks=164 budget_us=146376
+2026-10-16T13:19:07.218340Z DEBUG monolith::drm: frame rate output="DP-2" presented=165 vblanks=165 budget_us=147777
+2026-10-16T13:19:08.218585Z DEBUG monolith::drm: frame rate output="DP-2" presented=165 vblanks=164 budget_us=163678
+2026-10-16T13:19:08.370131Z DEBUG monolith::drm: frame missed its vblank output="DP-2" late_ns=6046851 budget_ns=198999079
+2026-10-16T13:19:09.008493Z DEBUG monolith::drm: slow frame output="DP-2" took_ns=324204580
+2026-10-16T13:19:09.012717Z DEBUG monolith::drm: frame missed its vblank output="DP-2" late_ns=6034851 budget_ns=474204581
+2026-10-16T13:19:09.031732Z DEBUG monolith::input: bind cmd=Quit