atagen

monolith

public
Star0
Fork0
Watch0
38 commits1 branch0 tags0 releases1.5 MiB

Commit d96bfa1d0892

tarball

atagen <boss@atagen.co>2026-10-16 13:39 UTC

2 files changed+60-40
monolith: log render thread CPU time on slow frames
crates/monolith/src/drm.rs+12
@@ -578,6 +578,7 @@ fn render_surface(state: &mut State, crtc: crtc::Handle, target: u64) -> bool {
578578 let animating = anim.active(now);
579579 anim.prune(now);
580580 let render_began = std::time::Instant::now();
581+ let cpu_began = thread_cpu_ns();
581582 let mut queue_ns = 0;
582583 match surface
583584 .drm
@@ -594,6 +595,7 @@ fn render_surface(state: &mut State, crtc: crtc::Handle, target: u64) -> bool {
594595 Ok(_) => {}
595596 Err(e) => tracing::warn!("rendering failed: {e}"),
596597 }
598+ let render_cpu_ns = thread_cpu_ns() - cpu_began;
597599 let render_ns = render_began.elapsed().as_nanos() as u64 - queue_ns;
598600 let took = began.elapsed().as_nanos() as u64;
599601 surface.budget.record(took);
@@ -603,6 +605,7 @@ fn render_surface(state: &mut State, crtc: crtc::Handle, target: u64) -> bool {
603605 took_ns = took,
604606 scene_ns,
605607 render_ns,
608+ render_cpu_ns,
606609 queue_ns,
607610 "slow frame"
608611 );
@@ -621,6 +624,15 @@ fn render_surface(state: &mut State, crtc: crtc::Handle, target: u64) -> bool {
621624 animating && !surface.queued
622625 }
623626
627+/// CPU time this thread has used, to tell a render that works from one that
628+/// waits or is descheduled.
629+fn thread_cpu_ns() -> u64 {
630+ let t = smithay::reexports::rustix::time::clock_gettime(
631+ smithay::reexports::rustix::time::ClockId::ThreadCPUTime,
632+ );
633+ t.tv_sec as u64 * 1_000_000_000 + t.tv_nsec as u64
634+}
635+
624636 fn on_input(state: &mut State, event: InputEvent<LibinputInputBackend>) {
625637 match event {
626638 InputEvent::Keyboard { event } => {
monolith.log+48−40
@@ -1,43 +1,51 @@
1- Finished `release` profile [optimized] target(s) in 0.06s
1+ Finished `release` profile [optimized] target(s) in 0.09s
22 Running `target/release/monolith run --backend drm , vkcube`
3-2026-10-16T13:35:15.490106Z INFO monolith::drm: primary GPU path=/dev/dri/card1
4-2026-10-16T13:35:15.730968Z INFO monolith::drm: output connected name="DP-2" w=2560 h=1440 refresh=165
5-2026-10-16T13:35:15.731044Z INFO monolith::ipc: control socket path=/run/user/1000/monolith-wayland-2.sock
6-2026-10-16T13:35:15.731056Z INFO monolith: monolith running socket="wayland-2" device="NVIDIA GeForce RTX 3060"
7-2026-10-16T13:35:15.731475Z INFO monolith::commands: spawned pid=349343 argv=[",", "vkcube"]
8-2026-10-16T13:35:15.752875Z DEBUG monolith::drm: slow frame output="DP-2" took_ns=21319632 scene_ns=1670 render_ns=9734952 queue_ns=96181
9-2026-10-16T13:35:15.753292Z DEBUG monolith::drm: frame rate output="DP-2" presented=1 vblanks=8518760 budget_us=23319
3+2026-10-16T13:37:26.021991Z INFO monolith::drm: primary GPU path=/dev/dri/card1
4+2026-10-16T13:37:26.301101Z INFO monolith::drm: output connected name="DP-2" w=2560 h=1440 refresh=165
5+2026-10-16T13:37:26.301182Z INFO monolith::ipc: control socket path=/run/user/1000/monolith-wayland-2.sock
6+2026-10-16T13:37:26.301196Z INFO monolith: monolith running socket="wayland-2" device="NVIDIA GeForce RTX 3060"
7+2026-10-16T13:37:26.301621Z INFO monolith::commands: spawned pid=350032 argv=[",", "vkcube"]
8+2026-10-16T13:37:26.329975Z DEBUG monolith::drm: slow frame output="DP-2" took_ns=28292811 scene_ns=1680 render_ns=15822467 queue_ns=143422
9+2026-10-16T13:37:26.336024Z DEBUG monolith::drm: frame rate output="DP-2" presented=1 vblanks=8540301 budget_us=30292
1010 Selected WSI platform: wayland
1111 Selected GPU 0: NVIDIA GeForce RTX 3060, type: DiscreteGpu, apiVersion: 4211017 (1.4.329), driverVersion: -1797652352 (83.416.128)
12-2026-10-16T13:35:16.450434Z DEBUG monolith::drm: frame missed its vblank output="DP-2" late_ns=24230851 budget_ns=2803045
13-2026-10-16T13:35:16.753596Z DEBUG monolith::drm: frame rate output="DP-2" presented=69 vblanks=165 budget_us=2738
14-2026-10-16T13:35:17.753796Z DEBUG monolith::drm: frame rate output="DP-2" presented=165 vblanks=164 budget_us=2632
15-2026-10-16T13:35:18.754050Z DEBUG monolith::drm: frame rate output="DP-2" presented=165 vblanks=164 budget_us=2449
16-2026-10-16T13:35:19.754328Z DEBUG monolith::drm: frame rate output="DP-2" presented=165 vblanks=165 budget_us=2236
17-2026-10-16T13:35:19.790784Z DEBUG monolith::drm: frame missed its vblank output="DP-2" late_ns=6078851 budget_ns=2755525
18-2026-10-16T13:35:20.754562Z DEBUG monolith::drm: frame rate output="DP-2" presented=164 vblanks=164 budget_us=2552
19-2026-10-16T13:35:21.754869Z DEBUG monolith::drm: frame rate output="DP-2" presented=165 vblanks=165 budget_us=2615
20-2026-10-16T13:35:22.372840Z DEBUG monolith::input: bind cmd=Fullscreen
21-2026-10-16T13:35:22.449190Z DEBUG monolith::drm: slow frame output="DP-2" took_ns=6973660 scene_ns=4561 render_ns=6779016 queue_ns=188123
22-2026-10-16T13:35:22.452000Z DEBUG monolith::drm: frame missed its vblank output="DP-2" late_ns=30322255 budget_ns=2938557
23-2026-10-16T13:35:22.470172Z DEBUG monolith::drm: frame missed its vblank output="DP-2" late_ns=6065851 budget_ns=3437557
24-2026-10-16T13:35:22.506619Z DEBUG monolith::drm: slow frame output="DP-2" took_ns=3565205 scene_ns=4030 render_ns=3479754 queue_ns=78911
25-2026-10-16T13:35:22.512598Z DEBUG monolith::drm: frame missed its vblank output="DP-2" late_ns=6056851 budget_ns=3538122
26-2026-10-16T13:35:22.755071Z DEBUG monolith::drm: frame rate output="DP-2" presented=154 vblanks=164 budget_us=3382
27-2026-10-16T13:35:23.755325Z DEBUG monolith::drm: frame rate output="DP-2" presented=165 vblanks=165 budget_us=3137
28-2026-10-16T13:35:24.755593Z DEBUG monolith::drm: frame rate output="DP-2" presented=165 vblanks=165 budget_us=2998
29-2026-10-16T13:35:25.755884Z DEBUG monolith::drm: frame rate output="DP-2" presented=165 vblanks=165 budget_us=2771
30-2026-10-16T13:35:26.756094Z DEBUG monolith::drm: frame rate output="DP-2" presented=165 vblanks=164 budget_us=2601
31-2026-10-16T13:35:27.756410Z DEBUG monolith::drm: frame rate output="DP-2" presented=165 vblanks=165 budget_us=2467
32-2026-10-16T13:35:28.726318Z DEBUG monolith::drm: frame missed its vblank output="DP-2" late_ns=6060851 budget_ns=2822079
33-2026-10-16T13:35:28.756635Z DEBUG monolith::drm: frame rate output="DP-2" presented=164 vblanks=164 budget_us=2896
34-2026-10-16T13:35:29.756859Z DEBUG monolith::drm: frame rate output="DP-2" presented=165 vblanks=164 budget_us=2563
35-2026-10-16T13:35:30.757118Z DEBUG monolith::drm: frame rate output="DP-2" presented=165 vblanks=165 budget_us=2401
36-2026-10-16T13:35:31.757402Z DEBUG monolith::drm: frame rate output="DP-2" presented=165 vblanks=165 budget_us=2363
37-2026-10-16T13:35:32.757640Z DEBUG monolith::drm: frame rate output="DP-2" presented=165 vblanks=164 budget_us=2124
38-2026-10-16T13:35:33.757961Z DEBUG monolith::drm: frame rate output="DP-2" presented=165 vblanks=165 budget_us=1931
39-2026-10-16T13:35:34.758162Z DEBUG monolith::drm: frame rate output="DP-2" presented=165 vblanks=164 budget_us=1773
40-2026-10-16T13:35:34.940003Z DEBUG monolith::drm: frame missed its vblank output="DP-2" late_ns=6042851 budget_ns=2282459
41-2026-10-16T13:35:35.758521Z DEBUG monolith::drm: frame rate output="DP-2" presented=164 vblanks=165 budget_us=2348
42-2026-10-16T13:35:36.758685Z DEBUG monolith::drm: frame rate output="DP-2" presented=165 vblanks=164 budget_us=1960
43-2026-10-16T13:35:37.231640Z DEBUG monolith::input: bind cmd=Quit
12+2026-10-16T13:37:27.148355Z DEBUG monolith::drm: frame missed its vblank output="DP-2" late_ns=6065404 budget_ns=2855707
13+2026-10-16T13:37:27.336255Z DEBUG monolith::drm: frame rate output="DP-2" presented=62 vblanks=164 budget_us=2871
14+2026-10-16T13:37:28.088426Z DEBUG monolith::input: bind cmd=Fullscreen
15+2026-10-16T13:37:28.190690Z DEBUG monolith::drm: slow frame output="DP-2" took_ns=12164788 scene_ns=9340 render_ns=11917384 queue_ns=233254
16+2026-10-16T13:37:28.197103Z DEBUG monolith::drm: frame missed its vblank output="DP-2" late_ns=42442808 budget_ns=3252354
17+2026-10-16T13:37:28.336509Z DEBUG monolith::drm: frame rate output="DP-2" presented=151 vblanks=165 budget_us=3313
18+2026-10-16T13:37:29.336770Z DEBUG monolith::drm: frame rate output="DP-2" presented=165 vblanks=165 budget_us=3169
19+2026-10-16T13:37:30.337026Z DEBUG monolith::drm: frame rate output="DP-2" presented=165 vblanks=165 budget_us=3371
20+2026-10-16T13:37:30.494826Z DEBUG monolith::drm: slow frame output="DP-2" took_ns=3517847 scene_ns=7420 render_ns=3449676 queue_ns=57191
21+2026-10-16T13:37:30.500748Z DEBUG monolith::drm: frame missed its vblank output="DP-2" late_ns=6094851 budget_ns=3430980
22+2026-10-16T13:37:31.337282Z DEBUG monolith::drm: frame rate output="DP-2" presented=164 vblanks=165 budget_us=3314
23+2026-10-16T13:37:32.337537Z DEBUG monolith::drm: frame rate output="DP-2" presented=165 vblanks=164 budget_us=3197
24+2026-10-16T13:37:33.156161Z DEBUG monolith::drm: slow frame output="DP-2" took_ns=3500447 scene_ns=4140 render_ns=3330464 queue_ns=164403
25+2026-10-16T13:37:33.161992Z DEBUG monolith::drm: frame missed its vblank output="DP-2" late_ns=6064851 budget_ns=3349589
26+2026-10-16T13:37:33.337799Z DEBUG monolith::drm: frame rate output="DP-2" presented=164 vblanks=165 budget_us=3295
27+2026-10-16T13:37:34.338051Z DEBUG monolith::drm: frame rate output="DP-2" presented=165 vblanks=165 budget_us=3441
28+2026-10-16T13:37:35.338354Z DEBUG monolith::drm: frame rate output="DP-2" presented=165 vblanks=165 budget_us=3432
29+2026-10-16T13:37:36.338593Z DEBUG monolith::drm: frame rate output="DP-2" presented=165 vblanks=165 budget_us=3367
30+2026-10-16T13:37:37.338902Z DEBUG monolith::drm: frame rate output="DP-2" presented=165 vblanks=165 budget_us=3194
31+2026-10-16T13:37:38.339072Z DEBUG monolith::drm: frame rate output="DP-2" presented=165 vblanks=164 budget_us=3374
32+2026-10-16T13:37:39.339326Z DEBUG monolith::drm: frame rate output="DP-2" presented=165 vblanks=165 budget_us=3291
33+2026-10-16T13:37:39.369816Z DEBUG monolith::drm: slow frame output="DP-2" took_ns=3477627 scene_ns=3430 render_ns=3351345 queue_ns=121312
34+2026-10-16T13:37:39.375734Z DEBUG monolith::drm: frame missed its vblank output="DP-2" late_ns=6081851 budget_ns=3291628
35+2026-10-16T13:37:40.339587Z DEBUG monolith::drm: frame rate output="DP-2" presented=164 vblanks=165 budget_us=3336
36+2026-10-16T13:37:41.339871Z DEBUG monolith::drm: frame rate output="DP-2" presented=165 vblanks=165 budget_us=3236
37+2026-10-16T13:37:42.340096Z DEBUG monolith::drm: frame rate output="DP-2" presented=165 vblanks=164 budget_us=3335
38+2026-10-16T13:37:43.340353Z DEBUG monolith::drm: frame rate output="DP-2" presented=165 vblanks=165 budget_us=3406
39+2026-10-16T13:37:44.340610Z DEBUG monolith::drm: frame rate output="DP-2" presented=165 vblanks=165 budget_us=3440
40+2026-10-16T13:37:45.340866Z DEBUG monolith::drm: frame rate output="DP-2" presented=165 vblanks=165 budget_us=3415
41+2026-10-16T13:37:45.583154Z DEBUG monolith::drm: slow frame output="DP-2" took_ns=3209653 scene_ns=4340 render_ns=3055520 queue_ns=148143
42+2026-10-16T13:37:46.341122Z DEBUG monolith::drm: frame rate output="DP-2" presented=165 vblanks=165 budget_us=3401
43+2026-10-16T13:37:47.341427Z DEBUG monolith::drm: frame rate output="DP-2" presented=165 vblanks=165 budget_us=3328
44+2026-10-16T13:37:48.341697Z DEBUG monolith::drm: frame rate output="DP-2" presented=165 vblanks=165 budget_us=3358
45+2026-10-16T13:37:49.341925Z DEBUG monolith::drm: frame rate output="DP-2" presented=165 vblanks=165 budget_us=3421
46+2026-10-16T13:37:50.342193Z DEBUG monolith::drm: frame rate output="DP-2" presented=165 vblanks=164 budget_us=3332
47+2026-10-16T13:37:51.342403Z DEBUG monolith::drm: frame rate output="DP-2" presented=165 vblanks=164 budget_us=3263
48+2026-10-16T13:37:51.791450Z DEBUG monolith::drm: slow frame output="DP-2" took_ns=3722772 scene_ns=4890 render_ns=3438177 queue_ns=277855
49+2026-10-16T13:37:51.797115Z DEBUG monolith::drm: frame missed its vblank output="DP-2" late_ns=6074851 budget_ns=3283108
50+2026-10-16T13:37:52.342659Z DEBUG monolith::drm: frame rate output="DP-2" presented=164 vblanks=165 budget_us=3325
51+2026-10-16T13:37:53.185148Z DEBUG monolith::input: bind cmd=Quit