atagen

monolith

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

Commit 30aece3a63ce

tarball

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

9 files changed+117-119
monolith: add a spans feature that logs every span over a millisecond

smithay is instrumented through the profiling crate, but its Tracy backend speaks an older protocol than the devshell Tracy, so the spans go through tracing instead and slow ones are printed with their ancestry.
Cargo.lock+3−71
@@ -323,21 +323,6 @@ dependencies = [
323323 ]
324324
325325 [[package]]
326-name = "generator"
327-version = "0.8.11"
328-source = "registry+https://github.com/rust-lang/crates.io-index"
329-checksum = "1be81b31c9ce4caf7f3178eeb90662bb1864d3ad363ec6bdada3201adff19c37"
330-dependencies = [
331- "cc",
332- "cfg-if",
333- "libc",
334- "log",
335- "rustversion",
336- "windows-link",
337- "windows-result",
338-]
339-
340-[[package]]
341326 name = "getrandom"
342327 version = "0.4.3"
343328 source = "registry+https://github.com/rust-lang/crates.io-index"
@@ -507,19 +492,6 @@ source = "registry+https://github.com/rust-lang/crates.io-index"
507492 checksum = "f9f8bd3e56ce4dfc153cf470fffbfa98c7620958b312ca5c3a4b8d5181fd13c6"
508493
509494 [[package]]
510-name = "loom"
511-version = "0.7.2"
512-source = "registry+https://github.com/rust-lang/crates.io-index"
513-checksum = "419e0dc8046cb947daa77eb95ae174acfbddb7673b4151f56d1eed8e93fbfaca"
514-dependencies = [
515- "cfg-if",
516- "generator",
517- "scoped-tls",
518- "tracing",
519- "tracing-subscriber",
520-]
521-
522-[[package]]
523495 name = "matchers"
524496 version = "0.2.0"
525497 source = "registry+https://github.com/rust-lang/crates.io-index"
@@ -556,13 +528,13 @@ dependencies = [
556528 "monolith-protocols",
557529 "monolith-render-vk",
558530 "pound",
531+ "profiling",
559532 "serde_json",
560533 "slotmap",
561534 "smithay",
562535 "smithay-drm-extras",
563536 "tracing",
564537 "tracing-subscriber",
565- "tracy-client",
566538 "wayland-client",
567539 "wayland-protocols",
568540 "xcursor",
@@ -624,6 +596,7 @@ dependencies = [
624596 "ash",
625597 "glam",
626598 "gpu-allocator",
599+ "profiling",
627600 "rustix 1.1.5",
628601 "smithay",
629602 "thiserror 2.0.21",
@@ -752,6 +725,7 @@ source = "registry+https://github.com/rust-lang/crates.io-index"
752725 checksum = "3d595e54a326bc53c1c197b32d295e14b169e3cfeaa8dc82b529f947fba6bcf5"
753726 dependencies = [
754727 "profiling-procmacros",
728+ "tracing",
755729 ]
756730
757731 [[package]]
@@ -908,12 +882,6 @@ dependencies = [
908882 ]
909883
910884 [[package]]
911-name = "rustversion"
912-version = "1.0.23"
913-source = "registry+https://github.com/rust-lang/crates.io-index"
914-checksum = "cf54715a573b99ac80df0bc206da022bcd442c974952c7b9720069370852e21f"
915-
916-[[package]]
917885 name = "rusty-fork"
918886 version = "0.3.1"
919887 source = "registry+https://github.com/rust-lang/crates.io-index"
@@ -926,12 +894,6 @@ dependencies = [
926894 ]
927895
928896 [[package]]
929-name = "scoped-tls"
930-version = "1.0.1"
931-source = "registry+https://github.com/rust-lang/crates.io-index"
932-checksum = "e1cf6437eb19a8f4a6cc0f7dca544973b0b78843adbfeb3683d1a94a0024a294"
933-
934-[[package]]
935897 name = "serde"
936898 version = "1.0.229"
937899 source = "registry+https://github.com/rust-lang/crates.io-index"
@@ -1266,27 +1228,6 @@ dependencies = [
12661228 ]
12671229
12681230 [[package]]
1269-name = "tracy-client"
1270-version = "0.19.0"
1271-source = "registry+https://github.com/rust-lang/crates.io-index"
1272-checksum = "d93fd676d8946eaeaff4881d26d2240a8d106fcaccbd47cb9f1389e3561ba490"
1273-dependencies = [
1274- "loom",
1275- "once_cell",
1276- "tracy-client-sys",
1277-]
1278-
1279-[[package]]
1280-name = "tracy-client-sys"
1281-version = "0.29.0"
1282-source = "registry+https://github.com/rust-lang/crates.io-index"
1283-checksum = "ab27f167b093214c68413a2e0bcd318f0591af475597405ff68138ba0a433379"
1284-dependencies = [
1285- "cc",
1286- "windows-targets 0.52.6",
1287-]
1288-
1289-[[package]]
12901231 name = "udev"
12911232 version = "0.9.3"
12921233 source = "registry+https://github.com/rust-lang/crates.io-index"
@@ -1445,15 +1386,6 @@ source = "registry+https://github.com/rust-lang/crates.io-index"
14451386 checksum = "f0805222e57f7521d6a62e36fa9163bc891acd422f971defe97d64e70d0a4fe5"
14461387
14471388 [[package]]
1448-name = "windows-result"
1449-version = "0.4.1"
1450-source = "registry+https://github.com/rust-lang/crates.io-index"
1451-checksum = "7781fa89eaf60850ac3d2da7af8e5242a5ea78d1a11c49bf2910bb5a73853eb5"
1452-dependencies = [
1453- "windows-link",
1454-]
1455-
1456-[[package]]
14571389 name = "windows-sys"
14581390 version = "0.48.0"
14591391 source = "registry+https://github.com/rust-lang/crates.io-index"
crates/monolith/Cargo.toml+3−2
@@ -9,7 +9,8 @@ publish.workspace = true
99 workspace = true
1010
1111 [features]
12-profile = ["dep:tracy-client", "tracy-client/enable"]
12+# Logs every span that runs over a millisecond, smithay's included.
13+spans = ["profiling/profile-with-tracing"]
1314
1415 [dependencies]
1516 calloop-wayland-source = "0.4"
@@ -21,6 +22,7 @@ monolith-planner.workspace = true
2122 monolith-protocols.workspace = true
2223 monolith-render-vk.workspace = true
2324 pound = "0.5"
25+profiling = "1"
2426 serde_json.workspace = true
2527 slotmap.workspace = true
2628 smithay = { workspace = true, features = [
@@ -35,6 +37,5 @@ smithay-drm-extras = { git = "https://github.com/Smithay/smithay", rev = "023b78
3537 xcursor = "0.3"
3638 tracing = "0.1"
3739 tracing-subscriber = { version = "0.3", features = ["env-filter"] }
38-tracy-client = { workspace = true, optional = true }
3940 wayland-client = "0.31"
4041 wayland-protocols = { version = "0.32", features = ["client", "unstable", "staging"] }
crates/monolith/src/drm.rs+1
@@ -531,6 +531,7 @@ pub fn render(state: &mut State) {
531531
532532 /// Draws one output for the vblank at `target`. Returns whether it still
533533 /// animates without a frame in flight, and so needs another render.
534+#[profiling::function]
534535 fn render_surface(state: &mut State, crtc: crtc::Handle, target: u64) -> bool {
535536 let State {
536537 drm: Some(drm),
crates/monolith/src/main.rs+14−5
@@ -10,6 +10,9 @@ mod nested;
1010 mod scene;
1111 mod state;
1212
13+#[cfg(feature = "spans")]
14+mod slow_spans;
15+
1316 use monolith_ipc::{Command, Query, Request};
1417 use pound::{Parse, ValueEnum};
1518 use smithay::reexports::calloop::EventLoop;
@@ -18,6 +21,9 @@ use state::State;
1821 use std::path::PathBuf;
1922 use std::process::ExitCode;
2023 use tracing_subscriber::EnvFilter;
24+use tracing_subscriber::Layer as _;
25+use tracing_subscriber::layer::SubscriberExt as _;
26+use tracing_subscriber::util::SubscriberInitExt as _;
2127
2228 /// a tiling Wayland compositor
2329 #[derive(Parse)]
@@ -91,13 +97,16 @@ fn main() -> ExitCode {
9197 }
9298 Some(Cmd::Subscribe) => return ipc::client(Request::Subscribe {}),
9399 };
94- tracing_subscriber::fmt()
95- .with_env_filter(
96- EnvFilter::try_from_default_env().unwrap_or_else(|_| EnvFilter::new("info")),
97- )
100+ let filter = EnvFilter::try_from_default_env().unwrap_or_else(|_| EnvFilter::new("info"));
101+ let fmt = tracing_subscriber::fmt::layer()
98102 .with_writer(std::io::stderr)
99103 .with_ansi(std::io::IsTerminal::is_terminal(&std::io::stderr()))
100- .init();
104+ .with_filter(filter);
105+ #[cfg(feature = "spans")]
106+ let spans = Some(slow_spans::SlowSpans);
107+ #[cfg(not(feature = "spans"))]
108+ let spans: Option<tracing_subscriber::layer::Identity> = None;
109+ tracing_subscriber::registry().with(fmt).with(spans).init();
101110 let backend = match backend {
102111 Backend::Auto if std::env::var_os("WAYLAND_DISPLAY").is_some() => Backend::Nested,
103112 Backend::Auto => Backend::Drm,
crates/monolith/src/scene.rs+1
@@ -37,6 +37,7 @@ pub struct Borders(HashMap<WindowId, [SolidColorBuffer; 4]>);
3737
3838 /// Elements for output `o` in its own coordinates, front to back.
3939 #[expect(clippy::too_many_arguments)]
40+#[profiling::function]
4041 pub fn build(
4142 layout: &Layout,
4243 o: OutputId,
crates/monolith/src/slow_spans.rs+35
@@ -0,0 +1,35 @@
1+//! Prints every span that runs for a millisecond or more, for finding what
2+//! makes a frame late. Built only with the `spans` feature.
3+
4+use std::time::Instant;
5+use tracing::span;
6+use tracing_subscriber::Layer;
7+use tracing_subscriber::layer::Context;
8+use tracing_subscriber::registry::LookupSpan;
9+
10+pub struct SlowSpans;
11+
12+struct Entered(Instant);
13+
14+impl<S> Layer<S> for SlowSpans
15+where
16+ S: tracing::Subscriber + for<'a> LookupSpan<'a>,
17+{
18+ fn on_enter(&self, id: &span::Id, ctx: Context<'_, S>) {
19+ if let Some(span) = ctx.span(id) {
20+ span.extensions_mut().replace(Entered(Instant::now()));
21+ }
22+ }
23+
24+ fn on_exit(&self, id: &span::Id, ctx: Context<'_, S>) {
25+ let Some(span) = ctx.span(id) else { return };
26+ let Some(Entered(at)) = span.extensions_mut().remove::<Entered>() else {
27+ return;
28+ };
29+ let took = at.elapsed();
30+ if took.as_micros() >= 1000 {
31+ let path: Vec<&str> = span.scope().from_root().map(|s| s.name()).collect();
32+ eprintln!("slow span {} took_us={}", path.join(">"), took.as_micros());
33+ }
34+ }
35+}
crates/render-vk/Cargo.toml+1
@@ -13,5 +13,6 @@ ash = "0.38"
1313 glam = { version = "0.33", default-features = false, features = ["std"] }
1414 rustix = { version = "1", features = ["event", "fs"] }
1515 gpu-allocator = { version = "0.27", default-features = false, features = ["vulkan"] }
16+profiling = "1"
1617 smithay.workspace = true
1718 thiserror = "2"
crates/render-vk/src/renderer.rs+5
@@ -185,6 +185,7 @@ impl VulkanRenderer {
185185 Ok(cmd)
186186 }
187187
188+ #[profiling::function]
188189 fn end_and_submit(&self, cmd: vk::CommandBuffer) -> Result<Arc<FenceInner>, Error> {
189190 let d = &self.shared.device.device;
190191 unsafe { d.end_command_buffer(cmd)? };
@@ -223,6 +224,7 @@ impl VulkanRenderer {
223224 Ok(res?)
224225 }
225226
227+ #[profiling::function]
226228 pub(crate) fn submit(
227229 &mut self,
228230 target: &mut VulkanTarget<'_>,
@@ -410,6 +412,7 @@ impl VulkanRenderer {
410412 /// Uploads `region` of `image`, taking each image row `y` in the region
411413 /// from `row(y)`. The CPU does not wait: the copy is ordered before later
412414 /// frames by its barrier, and its staging memory lives until its fence.
415+ #[profiling::function]
413416 fn upload_with<'a>(
414417 &mut self,
415418 image: &Arc<ImageInner>,
@@ -775,6 +778,7 @@ impl Bind<VulkanImage> for VulkanRenderer {
775778 }
776779
777780 impl Bind<Dmabuf> for VulkanRenderer {
781+ #[profiling::function]
778782 fn bind<'a>(&mut self, target: &'a mut Dmabuf) -> Result<VulkanTarget<'a>, Error> {
779783 let key = target.weak();
780784 let image = match self.dmabuf_targets.get(&key) {
@@ -858,6 +862,7 @@ impl ImportDma for VulkanRenderer {
858862 self.caps.sample.clone()
859863 }
860864
865+ #[profiling::function]
861866 fn import_dmabuf(
862867 &mut self,
863868 buffer: &Dmabuf,
monolith.log+54−41
@@ -1,45 +1,58 @@
11 Finished `release` profile [optimized] target(s) in 0.07s
22 Running `target/release/monolith run --backend drm , vkcube`
3-2026-10-16T13:39:52.271005Z INFO monolith::drm: primary GPU path=/dev/dri/card1
4-2026-10-16T13:39:52.553698Z INFO monolith::drm: output connected name="DP-2" w=2560 h=1440 refresh=165
5-2026-10-16T13:39:52.553800Z INFO monolith::ipc: control socket path=/run/user/1000/monolith-wayland-2.sock
6-2026-10-16T13:39:52.553815Z INFO monolith: monolith running socket="wayland-2" device="NVIDIA GeForce RTX 3060"
7-2026-10-16T13:39:52.554264Z INFO monolith::commands: spawned pid=350740 argv=[",", "vkcube"]
8-2026-10-16T13:39:52.593357Z DEBUG monolith::drm: slow frame output="DP-2" took_ns=38986278 scene_ns=4530 render_ns=23032820 render_cpu_ns=8313475 queue_ns=99091
9-2026-10-16T13:39:52.597275Z DEBUG monolith::drm: frame rate output="DP-2" presented=1 vblanks=8564428 budget_us=40986
3+2026-10-16T13:41:51.631819Z INFO monolith::drm: primary GPU path=/dev/dri/card1
4+2026-10-16T13:41:51.960157Z INFO monolith::drm: output connected name="DP-2" w=2560 h=1440 refresh=165
5+2026-10-16T13:41:51.960243Z INFO monolith::ipc: control socket path=/run/user/1000/monolith-wayland-2.sock
6+2026-10-16T13:41:51.960257Z INFO monolith: monolith running socket="wayland-2" device="NVIDIA GeForce RTX 3060"
7+2026-10-16T13:41:51.960639Z INFO monolith::commands: spawned pid=351673 argv=[",", "vkcube"]
8+2026-10-16T13:41:51.987220Z DEBUG monolith::drm: slow frame output="DP-2" took_ns=26496547 scene_ns=4840 render_ns=13370622 render_cpu_ns=3089012 queue_ns=107051
9+2026-10-16T13:41:51.990179Z DEBUG monolith::drm: frame rate output="DP-2" presented=1 vblanks=8584123 budget_us=28496
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:39:53.633937Z DEBUG monolith::drm: frame rate output="DP-2" presented=53 vblanks=171 budget_us=2250
13-2026-10-16T13:39:54.379572Z DEBUG monolith::drm: frame missed its vblank output="DP-2" late_ns=6071851 budget_ns=2537563
14-2026-10-16T13:39:54.634161Z DEBUG monolith::drm: frame rate output="DP-2" presented=163 vblanks=164 budget_us=2727
15-2026-10-16T13:39:55.030351Z DEBUG monolith::drm: slow frame output="DP-2" took_ns=4831411 scene_ns=5370 render_ns=4754940 render_cpu_ns=1894492 queue_ns=69361
16-2026-10-16T13:39:55.034256Z DEBUG monolith::drm: frame missed its vblank output="DP-2" late_ns=6064851 budget_ns=3179425
17-2026-10-16T13:39:55.634419Z DEBUG monolith::drm: frame rate output="DP-2" presented=164 vblanks=165 budget_us=3122
18-2026-10-16T13:39:56.634675Z DEBUG monolith::drm: frame rate output="DP-2" presented=165 vblanks=164 budget_us=3157
19-2026-10-16T13:39:56.780418Z DEBUG monolith::drm: slow frame output="DP-2" took_ns=3376287 scene_ns=6120 render_ns=3275165 render_cpu_ns=768540 queue_ns=92432
20-2026-10-16T13:39:56.786224Z DEBUG monolith::drm: frame missed its vblank output="DP-2" late_ns=6065851 budget_ns=3413131
21-2026-10-16T13:39:57.634966Z DEBUG monolith::drm: frame rate output="DP-2" presented=164 vblanks=165 budget_us=3274
22-2026-10-16T13:39:58.635224Z DEBUG monolith::drm: frame rate output="DP-2" presented=165 vblanks=165 budget_us=3324
23-2026-10-16T13:39:59.635443Z DEBUG monolith::drm: frame rate output="DP-2" presented=165 vblanks=164 budget_us=3247
24-2026-10-16T13:40:00.499837Z DEBUG monolith::input: bind cmd=Fullscreen
25-2026-10-16T13:40:00.642257Z DEBUG monolith::drm: slow frame output="DP-2" took_ns=14485644 scene_ns=7720 render_ns=14191029 render_cpu_ns=7160684 queue_ns=283285
26-2026-10-16T13:40:00.647835Z DEBUG monolith::drm: frame missed its vblank output="DP-2" late_ns=54532212 budget_ns=3203097
27-2026-10-16T13:40:00.647849Z DEBUG monolith::drm: frame rate output="DP-2" presented=147 vblanks=167 budget_us=3203
28-2026-10-16T13:40:01.648077Z DEBUG monolith::drm: frame rate output="DP-2" presented=165 vblanks=164 budget_us=3221
29-2026-10-16T13:40:02.648330Z DEBUG monolith::drm: frame rate output="DP-2" presented=165 vblanks=164 budget_us=3207
30-2026-10-16T13:40:03.648591Z DEBUG monolith::drm: frame rate output="DP-2" presented=165 vblanks=165 budget_us=3432
31-2026-10-16T13:40:04.648848Z DEBUG monolith::drm: frame rate output="DP-2" presented=165 vblanks=165 budget_us=3463
32-2026-10-16T13:40:05.649107Z DEBUG monolith::drm: frame rate output="DP-2" presented=165 vblanks=165 budget_us=3281
33-2026-10-16T13:40:05.776430Z DEBUG monolith::drm: slow frame output="DP-2" took_ns=3303456 scene_ns=5290 render_ns=3215134 render_cpu_ns=3281472 queue_ns=79822
34-2026-10-16T13:40:05.782490Z DEBUG monolith::drm: frame missed its vblank output="DP-2" late_ns=6064851 budget_ns=3304089
35-2026-10-16T13:40:06.649365Z DEBUG monolith::drm: frame rate output="DP-2" presented=164 vblanks=165 budget_us=3245
36-2026-10-16T13:40:07.649665Z DEBUG monolith::drm: frame rate output="DP-2" presented=165 vblanks=165 budget_us=3276
37-2026-10-16T13:40:08.649903Z DEBUG monolith::drm: frame rate output="DP-2" presented=165 vblanks=165 budget_us=3333
38-2026-10-16T13:40:09.650131Z DEBUG monolith::drm: frame rate output="DP-2" presented=165 vblanks=164 budget_us=3335
39-2026-10-16T13:40:10.650389Z DEBUG monolith::drm: frame rate output="DP-2" presented=165 vblanks=165 budget_us=3271
40-2026-10-16T13:40:11.650648Z DEBUG monolith::drm: frame rate output="DP-2" presented=165 vblanks=165 budget_us=3392
41-2026-10-16T13:40:12.650906Z DEBUG monolith::drm: frame rate output="DP-2" presented=165 vblanks=165 budget_us=3252
42-2026-10-16T13:40:13.651161Z DEBUG monolith::drm: frame rate output="DP-2" presented=165 vblanks=165 budget_us=3345
43-2026-10-16T13:40:14.651463Z DEBUG monolith::drm: frame rate output="DP-2" presented=165 vblanks=165 budget_us=3307
44-2026-10-16T13:40:15.651701Z DEBUG monolith::drm: frame rate output="DP-2" presented=165 vblanks=165 budget_us=3265
45-2026-10-16T13:40:15.691710Z DEBUG monolith::input: bind cmd=Quit
12+2026-10-16T13:41:52.990409Z DEBUG monolith::drm: frame rate output="DP-2" presented=45 vblanks=164 budget_us=2209
13+2026-10-16T13:41:53.166218Z DEBUG monolith::drm: frame missed its vblank output="DP-2" late_ns=6103871 budget_ns=2732345
14+2026-10-16T13:41:53.990625Z DEBUG monolith::drm: frame rate output="DP-2" presented=143 vblanks=164 budget_us=2788
15+2026-10-16T13:41:54.557117Z DEBUG monolith::drm: slow frame output="DP-2" took_ns=5466464 scene_ns=4740 render_ns=5383123 render_cpu_ns=1768941 queue_ns=77001
16+2026-10-16T13:41:54.560470Z DEBUG monolith::drm: frame missed its vblank output="DP-2" late_ns=6065851 budget_ns=3271506
17+2026-10-16T13:41:54.990887Z DEBUG monolith::drm: frame rate output="DP-2" presented=164 vblanks=165 budget_us=3224
18+2026-10-16T13:41:55.991138Z DEBUG monolith::drm: frame rate output="DP-2" presented=165 vblanks=165 budget_us=3114
19+2026-10-16T13:41:56.312454Z DEBUG monolith::drm: frame missed its vblank output="DP-2" late_ns=6067851 budget_ns=3289218
20+2026-10-16T13:41:56.991399Z DEBUG monolith::drm: frame rate output="DP-2" presented=164 vblanks=165 budget_us=3323
21+2026-10-16T13:41:57.991651Z DEBUG monolith::drm: frame rate output="DP-2" presented=165 vblanks=165 budget_us=3245
22+2026-10-16T13:41:58.979875Z DEBUG monolith::drm: slow frame output="DP-2" took_ns=3492910 scene_ns=5180 render_ns=3414248 render_cpu_ns=3479602 queue_ns=71322
23+2026-10-16T13:41:58.985892Z DEBUG monolith::drm: frame missed its vblank output="DP-2" late_ns=6097851 budget_ns=3408461
24+2026-10-16T13:41:58.991938Z DEBUG monolith::drm: frame rate output="DP-2" presented=164 vblanks=165 budget_us=3415
25+2026-10-16T13:41:59.559690Z DEBUG monolith::input: bind cmd=Fullscreen
26+2026-10-16T13:41:59.729017Z DEBUG monolith::drm: slow frame output="DP-2" took_ns=10899698 scene_ns=7750 render_ns=10721335 render_cpu_ns=5547754 queue_ns=166883
27+2026-10-16T13:41:59.737603Z DEBUG monolith::drm: frame missed its vblank output="DP-2" late_ns=78815063 budget_ns=3177867
28+2026-10-16T13:41:59.992172Z DEBUG monolith::drm: frame rate output="DP-2" presented=140 vblanks=164 budget_us=3326
29+2026-10-16T13:42:00.992420Z DEBUG monolith::drm: frame rate output="DP-2" presented=165 vblanks=165 budget_us=3359
30+2026-10-16T13:42:01.992690Z DEBUG monolith::drm: frame rate output="DP-2" presented=165 vblanks=165 budget_us=3402
31+2026-10-16T13:42:02.992934Z DEBUG monolith::drm: frame rate output="DP-2" presented=165 vblanks=165 budget_us=3237
32+2026-10-16T13:42:03.993200Z DEBUG monolith::drm: frame rate output="DP-2" presented=165 vblanks=165 budget_us=3261
33+2026-10-16T13:42:04.993449Z DEBUG monolith::drm: frame rate output="DP-2" presented=165 vblanks=165 budget_us=3279
34+2026-10-16T13:42:05.339249Z DEBUG monolith::drm: slow frame output="DP-2" took_ns=3550112 scene_ns=6330 render_ns=3435140 render_cpu_ns=3521092 queue_ns=106462
35+2026-10-16T13:42:05.345073Z DEBUG monolith::drm: frame missed its vblank output="DP-2" late_ns=6066851 budget_ns=3292298
36+2026-10-16T13:42:05.993707Z DEBUG monolith::drm: frame rate output="DP-2" presented=164 vblanks=165 budget_us=3270
37+2026-10-16T13:42:06.993984Z DEBUG monolith::drm: frame rate output="DP-2" presented=165 vblanks=165 budget_us=3316
38+2026-10-16T13:42:07.994216Z DEBUG monolith::drm: frame rate output="DP-2" presented=165 vblanks=165 budget_us=3318
39+2026-10-16T13:42:08.994516Z DEBUG monolith::drm: frame rate output="DP-2" presented=165 vblanks=165 budget_us=3398
40+2026-10-16T13:42:09.994731Z DEBUG monolith::drm: frame rate output="DP-2" presented=165 vblanks=164 budget_us=3291
41+2026-10-16T13:42:10.994991Z DEBUG monolith::drm: frame rate output="DP-2" presented=165 vblanks=165 budget_us=3336
42+2026-10-16T13:42:11.995247Z DEBUG monolith::drm: frame rate output="DP-2" presented=165 vblanks=165 budget_us=3403
43+2026-10-16T13:42:12.995506Z DEBUG monolith::drm: frame rate output="DP-2" presented=165 vblanks=165 budget_us=3213
44+2026-10-16T13:42:13.995760Z DEBUG monolith::drm: frame rate output="DP-2" presented=165 vblanks=164 budget_us=3225
45+2026-10-16T13:42:14.996038Z DEBUG monolith::drm: frame rate output="DP-2" presented=165 vblanks=165 budget_us=3269
46+2026-10-16T13:42:15.996279Z DEBUG monolith::drm: frame rate output="DP-2" presented=165 vblanks=164 budget_us=3212
47+2026-10-16T13:42:16.996535Z DEBUG monolith::drm: frame rate output="DP-2" presented=165 vblanks=165 budget_us=3186
48+2026-10-16T13:42:17.760357Z DEBUG monolith::drm: slow frame output="DP-2" took_ns=3380019 scene_ns=8680 render_ns=3228576 render_cpu_ns=3350232 queue_ns=138973
49+2026-10-16T13:42:17.766453Z DEBUG monolith::drm: frame missed its vblank output="DP-2" late_ns=6068851 budget_ns=3386040
50+2026-10-16T13:42:17.996794Z DEBUG monolith::drm: frame rate output="DP-2" presented=164 vblanks=165 budget_us=3266
51+2026-10-16T13:42:18.997113Z DEBUG monolith::drm: frame rate output="DP-2" presented=165 vblanks=165 budget_us=3323
52+2026-10-16T13:42:19.997305Z DEBUG monolith::drm: frame rate output="DP-2" presented=165 vblanks=164 budget_us=3180
53+2026-10-16T13:42:20.997589Z DEBUG monolith::drm: frame rate output="DP-2" presented=165 vblanks=165 budget_us=3305
54+2026-10-16T13:42:21.997830Z DEBUG monolith::drm: frame rate output="DP-2" presented=165 vblanks=164 budget_us=3357
55+2026-10-16T13:42:22.998079Z DEBUG monolith::drm: frame rate output="DP-2" presented=165 vblanks=165 budget_us=3373
56+2026-10-16T13:42:23.973895Z DEBUG monolith::drm: slow frame output="DP-2" took_ns=3117544 scene_ns=5260 render_ns=3023242 render_cpu_ns=3094742 queue_ns=86642
57+2026-10-16T13:42:23.998335Z DEBUG monolith::drm: frame rate output="DP-2" presented=165 vblanks=165 budget_us=3277
58+2026-10-16T13:42:24.122439Z DEBUG monolith::input: bind cmd=Quit