AppKit/UIKit: Improve tracing

clippy.toml

@@ -1,4 +1,11 @@
 # Using allow-invalid because this is platform-specific code
+disallowed-macros = [
+    { path = "std::print", reason = "works badly on web", replacement = "tracing::info" },
+    { path = "std::println", reason = "works badly on web", replacement = "tracing::info" },
+    { path = "std::eprint", reason = "works badly on web", replacement = "tracing::error" },
+    { path = "std::eprintln", reason = "works badly on web", replacement = "tracing::error" },
+    { path = "std::dbg", reason = "leftover debugging aid, remove it or use tracing" },
+]
 disallowed-methods = [
     { allow-invalid = true, path = "objc2_app_kit::NSView::visibleRect", reason = "We expose a render target to the user, and visibility is not really relevant to that (and can break if you don't use the rectangle position as well). Use `frame` instead." },
     { allow-invalid = true, path = "objc2_app_kit::NSWindow::setFrameTopLeftPoint", reason = "Not sufficient when working with Winit's coordinate system, use `flip_window_screen_coordinates` instead" },

winit-appkit/src/app.rs

@@ -1,14 +1,15 @@
 #![allow(clippy::unnecessary_cast)]
 
 use std::cell::Cell;
-use std::mem;
 use std::rc::Rc;
+use std::{mem, ptr};
 
 use dispatch2::MainThreadBound;
 use objc2::runtime::{Imp, Sel};
 use objc2::sel;
 use objc2_app_kit::{NSApplication, NSEvent, NSEventModifierFlags, NSEventType};
 use objc2_foundation::MainThreadMarker;
+use tracing::trace_span;
 use winit_core::event::{DeviceEvent, ElementState};
 
 use super::app_state::AppState;
@@ -21,6 +22,8 @@ static ORIGINAL: MainThreadBound<Cell<Option<SendEvent>>> = {
 };
 
 extern "C-unwind" fn send_event(app: &NSApplication, sel: Sel, event: &NSEvent) {
+    // Pass `RUST_LOG='trace,winit_appkit::app=warn'` if you want TRACE logs but not this.
+    let _entered = trace_span!("sendEvent:", ?event).entered();
     let mtm = MainThreadMarker::from(app);
 
     // Normally, holding Cmd + any key never sends us a `keyUp` event for that key.
@@ -48,7 +51,7 @@ extern "C-unwind" fn send_event(app: &NSApplication, sel: Sel, event: &NSEvent)
     original(app, sel, event)
 }
 
-/// Override the [`sendEvent:`][NSApplication::sendEvent] method on the given application class.
+/// Intercept the [`sendEvent:`][NSApplication::sendEvent] method on the given application class.
 ///
 /// The previous implementation created a subclass of [`NSApplication`], however we would like to
 /// give the user full control over their `NSApplication`, so we override the method here using
@@ -75,9 +78,7 @@ pub(crate) fn override_send_event(global_app: &NSApplication) {
     let overridden = unsafe { mem::transmute::<SendEvent, Imp>(send_event) };
 
     // If we've already overridden the method, don't do anything.
-    // FIXME(madsmtm): Use `std::ptr::fn_addr_eq` (Rust 1.85) once available in MSRV.
-    #[allow(unknown_lints, unpredictable_function_pointer_comparisons)]
-    if overridden == method.implementation() {
+    if ptr::fn_addr_eq(overridden, method.implementation()) {
         return;
     }
 

winit-appkit/src/app_state.rs

@@ -99,7 +99,6 @@ impl AppState {
     // NOTE: This notification will, globally, only be emitted once,
     // no matter how many `EventLoop`s the user creates.
     pub fn did_finish_launching(self: &Rc<Self>, _notification: &NSNotification) {
-        trace_scope!("NSApplicationDidFinishLaunchingNotification");
         self.is_launched.set(true);
 
         let app = NSApplication::sharedApplication(self.mtm);
@@ -154,7 +153,6 @@ impl AppState {
     }
 
     pub fn will_terminate(self: &Rc<Self>, _notification: &NSNotification) {
-        trace_scope!("NSApplicationWillTerminateNotification");
         let app = NSApplication::sharedApplication(self.mtm);
         notify_windows_of_exit(&app);
         self.event_handler.terminate();

winit-appkit/src/event_loop.rs

@@ -12,7 +12,8 @@ use objc2_app_kit::{
 use objc2_core_foundation::{CFIndex, CFRunLoopActivity, kCFRunLoopCommonModes};
 use objc2_foundation::{NSNotificationCenter, NSObjectProtocol};
 use rwh_06::HasDisplayHandle;
-use winit_common::core_foundation::{MainRunLoop, MainRunLoopObserver};
+use tracing::debug_span;
+use winit_common::core_foundation::{MainRunLoop, MainRunLoopObserver, tracing_observers};
 use winit_core::application::ApplicationHandler;
 use winit_core::cursor::{CustomCursor as CoreCustomCursor, CustomCursorSource};
 use winit_core::error::{EventLoopError, RequestError};
@@ -152,6 +153,7 @@ pub struct EventLoop {
     _did_finish_launching_observer: Retained<ProtocolObject<dyn NSObjectProtocol>>,
     _will_terminate_observer: Retained<ProtocolObject<dyn NSObjectProtocol>>,
 
+    _tracing_observers: Option<(MainRunLoopObserver, MainRunLoopObserver)>,
     _before_waiting_observer: MainRunLoopObserver,
     _after_waiting_observer: MainRunLoopObserver,
 }
@@ -203,6 +205,7 @@ impl EventLoop {
             // `applicationDidFinishLaunching:`
             unsafe { NSApplicationDidFinishLaunchingNotification },
             move |notification| {
+                let _entered = debug_span!("NSApplicationDidFinishLaunchingNotification").entered();
                 if let Some(app_state) = weak_app_state.upgrade() {
                     app_state.did_finish_launching(notification);
                 }
@@ -215,6 +218,7 @@ impl EventLoop {
             // `applicationWillTerminate:`
             unsafe { NSApplicationWillTerminateNotification },
             move |notification| {
+                let _entered = debug_span!("NSApplicationWillTerminateNotification").entered();
                 if let Some(app_state) = weak_app_state.upgrade() {
                     app_state.will_terminate(notification);
                 }
@@ -224,14 +228,20 @@ impl EventLoop {
         let main_loop = MainRunLoop::get(mtm);
         let mode = unsafe { kCFRunLoopCommonModes }.unwrap();
 
+        // Tracing observers have the lowest and highest orderings.
+        let _tracing_observers = tracing_observers(mtm).inspect(|(start, end)| {
+            main_loop.add_observer(start, mode);
+            main_loop.add_observer(end, mode);
+        });
+
         let app_state_clone = Rc::clone(&app_state);
         let _before_waiting_observer = MainRunLoopObserver::new(
             mtm,
             CFRunLoopActivity::BeforeWaiting,
             true,
-            // Queued with the lowest priority to ensure it is processed after other observers.
-            // Without that, we'd get a `LoopExiting` after `AboutToWait`.
-            CFIndex::MAX,
+            // Queued with the second-lowest priority (tracing observers use the lowest) to ensure
+            // it is processed after other observers.
+            CFIndex::MAX - 1,
             move |_| app_state_clone.cleared(),
         );
         main_loop.add_observer(&_before_waiting_observer, mode);
@@ -241,8 +251,9 @@ impl EventLoop {
             mtm,
             CFRunLoopActivity::AfterWaiting,
             true,
-            // Queued with the highest priority to ensure it is processed before other observers.
-            CFIndex::MIN,
+            // Queued with the second-highest priority (tracing observers use the highest) to
+            // ensure it is processed before other observers.
+            CFIndex::MIN + 1,
             move |_| app_state_clone.wakeup(),
         );
         main_loop.add_observer(&_after_waiting_observer, mode);
@@ -253,6 +264,7 @@ impl EventLoop {
             window_target: ActiveEventLoop { app_state, mtm },
             _did_finish_launching_observer,
             _will_terminate_observer,
+            _tracing_observers,
             _before_waiting_observer,
             _after_waiting_observer,
         })

winit-appkit/src/util.rs

@@ -1,37 +1,10 @@
 use objc2_core_graphics::CGError;
-use tracing::trace;
 use winit_core::error::OsError;
 
 macro_rules! os_error {
     ($error:expr) => {{ winit_core::error::OsError::new(line!(), file!(), $error) }};
 }
 
-macro_rules! trace_scope {
-    ($s:literal) => {
-        let _crate = $crate::util::TraceGuard::new(module_path!(), $s);
-    };
-}
-
-pub(crate) struct TraceGuard {
-    module_path: &'static str,
-    called_from_fn: &'static str,
-}
-
-impl TraceGuard {
-    #[inline]
-    pub(crate) fn new(module_path: &'static str, called_from_fn: &'static str) -> Self {
-        trace!(target = module_path, "Triggered `{}`", called_from_fn);
-        Self { module_path, called_from_fn }
-    }
-}
-
-impl Drop for TraceGuard {
-    #[inline]
-    fn drop(&mut self) {
-        trace!(target = self.module_path, "Completed `{}`", self.called_from_fn);
-    }
-}
-
 #[track_caller]
 pub(crate) fn cgerr(err: CGError) -> Result<(), OsError> {
     if err == CGError::Success { Ok(()) } else { Err(os_error!(format!("CGError {err:?}"))) }