atagen

monolith

public
Star0
Watch0

Commit f729188530f0

tarball

atagen <boss@atagen.co>2026-10-17 05:56 UTC

1 file changed+34-1
monolith: log direct scanout and per-frame compositor CPU

The M7 targets need numbers, and only slow frames were logged. The frame rate line now carries the p99 compositor CPU per frame and how many frames went straight to the primary plane. Scanout switching on or off is logged with the element and plane counts, which narrows down what kept a fullscreen window from scanning out.
Modified file: crates/monolith/src/drm.rs+34 additions−1 deletions
@@ -12,7 +12,7 @@ use monolith_layout::{OutputId, Rect};
1212 use smithay::backend::allocator::Fourcc;
1313 use smithay::backend::allocator::gbm::{GbmAllocator, GbmBufferFlags, GbmDevice};
1414 use smithay::backend::drm::VrrSupport;
15-use smithay::backend::drm::compositor::FrameFlags;
15+use smithay::backend::drm::compositor::{FrameFlags, PrimaryPlaneElement};
1616 use smithay::backend::drm::exporter::gbm::GbmFramebufferExporter;
1717 use smithay::backend::drm::output::{DrmOutput, DrmOutputManager, DrmOutputRenderElements};
1818 use smithay::backend::drm::{
@@ -86,6 +86,12 @@ struct Surface {
8686 vrr_on: bool,
8787 /// Only the cursor moved, which under VRR is drawn at a capped rate.
8888 cursor_redraw: bool,
89+ /// The last frame went straight to the primary plane without compositing.
90+ scanout: bool,
91+ /// Frames scanned out and per-frame compositor CPU times since
92+ /// `stats_since`, for the targets in decisions.md.
93+ scanned_out: u32,
94+ frame_cpu_ns: Vec<u64>,
8995 }
9096
9197 impl Surface {
@@ -358,6 +364,9 @@ fn connect(state: &mut State, connector: connector::Info, crtc: crtc::Handle) {
358364 vrr_capable,
359365 vrr_on: false,
360366 cursor_redraw: false,
367+ scanout: false,
368+ scanned_out: 0,
369+ frame_cpu_ns: Vec::new(),
361370 refresh_ns: 1_000_000_000_000 / u64::from(wl_mode.refresh.max(1) as u32),
362371 },
363372 );
@@ -431,14 +440,21 @@ fn on_vblank(state: &mut State, crtc: crtc::Handle, meta: &mut Option<DrmEventMe
431440 // Under VRR the panel waits for each flip, so the nominal refresh
432441 // says nothing about how many vblanks there were.
433442 let vblanks = (!surface.vrr_on).then(|| window / surface.refresh_ns.max(1));
443+ let cpu = &mut surface.frame_cpu_ns;
444+ cpu.sort_unstable();
445+ let p99 = cpu.get(cpu.len().saturating_sub(1) * 99 / 100).copied();
434446 tracing::debug!(
435447 output = surface.output.name(),
436448 presented = surface.presented,
437449 vblanks,
438450 vrr = surface.vrr_on,
451+ scanned_out = surface.scanned_out,
452+ cpu_p99_us = p99.map(|ns| ns / 1000),
439453 budget_us = surface.budget.ns() / 1000,
440454 "frame rate"
441455 );
456+ cpu.clear();
457+ surface.scanned_out = 0;
442458 surface.presented = 0;
443459 surface.stats_since = t;
444460 }
@@ -588,6 +604,7 @@ fn render_surface(state: &mut State, crtc: crtc::Handle, target: u64) -> bool {
588604 }
589605 }
590606 let began = std::time::Instant::now();
607+ let frame_cpu_began = thread_cpu_ns();
591608 let now = target;
592609 if wm.layout.output(surface.id).is_none() {
593610 return false;
@@ -612,6 +629,21 @@ fn render_surface(state: &mut State, crtc: crtc::Handle, target: u64) -> bool {
612629 .render_frame(renderer, &elements, CLEAR, drm.frame_flags)
613630 {
614631 Ok(result) if !result.is_empty => {
632+ let direct = matches!(result.primary_element, PrimaryPlaneElement::Element(_));
633+ if direct {
634+ surface.scanned_out += 1;
635+ }
636+ if direct != surface.scanout {
637+ surface.scanout = direct;
638+ tracing::info!(
639+ output = surface.output.name(),
640+ scanout = direct,
641+ elements = elements.len(),
642+ overlay_planes = result.overlay_elements.len(),
643+ cursor_plane = result.cursor_element.is_some(),
644+ "direct scanout"
645+ );
646+ }
615647 let queue_began = std::time::Instant::now();
616648 match surface.drm.queue_frame(()) {
617649 Ok(()) => {
@@ -630,6 +662,7 @@ fn render_surface(state: &mut State, crtc: crtc::Handle, target: u64) -> bool {
630662 let render_ns = render_began.elapsed().as_nanos() as u64 - queue_ns;
631663 let took = began.elapsed().as_nanos() as u64;
632664 surface.budget.record(took);
665+ surface.frame_cpu_ns.push(thread_cpu_ns() - frame_cpu_began);
633666 if took > surface.refresh_ns / 2 {
634667 tracing::debug!(
635668 output = surface.output.name(),