From f6ad736dca018a3adf3f0c548ed488ef33622a1f Mon Sep 17 00:00:00 2001
From: LGUG2Z <LGUG2Z@fastmail.com>
Date: Sat, 31 Oct 2026 18:47:49 -0700
Subject: [PATCH] feat(windows): time the steps of process_event

The event thread logs, per event, how long it waited for the window manager
lock and how long handling took (debug, or info when either is 200 ms or more:
"process_event <event>: waited for the lock N ms, handled in N ms"), and
process_event logs how long should_manage took (debug). The stall analysis of
the cand5 gate puts every remaining real hold of 1 to 4.5 s in process_event
for Show/Uncloak/FocusChange of new windows, silent before the first log line
of the handler; these lines say whether that is should_manage (Win32 and rule
matching on the new window) or the rest.

Diagnostics only, no behaviour change. Verified: tools/fast-check Windows
clippy -D warnings PASS; e2e: none needed.
---
 komorebi/src/process_event.rs | 26 +++++++++++++++++++++++++-
 1 file changed, 25 insertions(+), 1 deletion(-)

diff --git a/komorebi/src/process_event.rs b/komorebi/src/process_event.rs
index b7cf87e4..562200d4 100644
--- a/komorebi/src/process_event.rs
+++ b/komorebi/src/process_event.rs
@@ -122,8 +122,27 @@ pub fn listen_for_events(wm: Arc<Mutex<WindowManager>>) {
         tracing::info!("listening");
         loop {
             if let Ok(event) = receiver.recv() {
+                let waiting = std::time::Instant::now();
                 let mut guard = crate::lock_holder::lock(&wm, "process_event");
-                match guard.process_event(event) {
+                let handling = std::time::Instant::now();
+                let result = guard.process_event(event);
+                let (waited, handled) = (handling.duration_since(waiting), handling.elapsed());
+                if waited.max(handled) >= crate::lock_holder::SLOW {
+                    tracing::info!(
+                        "process_event {}: waited for the lock {} ms, handled in {} ms",
+                        event.title(),
+                        waited.as_millis(),
+                        handled.as_millis()
+                    );
+                } else {
+                    tracing::debug!(
+                        "process_event {}: waited for the lock {} ms, handled in {} ms",
+                        event.title(),
+                        waited.as_millis(),
+                        handled.as_millis()
+                    );
+                }
+                match result {
                     Ok(()) => {}
                     Err(error) => {
                         if cfg!(debug_assertions) {
@@ -149,7 +168,12 @@ impl WindowManager {
 
         let mut rule_debug = RuleDebug::default();
 
+        let should_manage_started = std::time::Instant::now();
         let should_manage = event.window().should_manage(Some(event), &mut rule_debug)?;
+        tracing::debug!(
+            "process_event: should_manage took {} ms",
+            should_manage_started.elapsed().as_millis()
+        );
 
         // All event handlers below this point should only be processed if the event is
         // related to a window that should be managed by the WindowManager.