app: instrument entire draw tree

bin/app/src/logger.rs

@@ -114,7 +114,7 @@ pub fn setup_logging() -> Option<WorkerGuard> {
 
     #[cfg(not(target_os = "android"))]
     {
-        let mut terminal_layer = tracing_subscriber::fmt::Layer::new()
+        let terminal_layer = tracing_subscriber::fmt::Layer::new()
             .with_span_events(FmtSpan::ENTER | FmtSpan::CLOSE)
             .event_format(EventFormatter::new(true, true))
             .fmt_fields(tracing_subscriber::fmt::format::debug_fn(

bin/app/src/prop/guard.rs

@@ -85,6 +85,12 @@ impl Drop for PropertyAtomicGuard {
     }
 }
 
+impl std::fmt::Debug for PropertyAtomicGuard {
+    fn fmt(&self, f: &mut std::fmt::Formatter) -> std::fmt::Result {
+        f.debug_struct("PropertyAtomicGuard").field("batch_id", &self.batch_id).finish()
+    }
+}
+
 pub type BatchGuardId = u32;
 type BatchGuardCb = Box<dyn FnOnce(BatchGuardId) + Send + Sync>;
 pub type BatchGuardPtr = Arc<BatchGuard>;
@@ -112,3 +118,9 @@ impl Drop for BatchGuard {
         end_batch(self.id);
     }
 }
+
+impl std::fmt::Debug for BatchGuard {
+    fn fmt(&self, f: &mut std::fmt::Formatter) -> std::fmt::Result {
+        f.debug_struct("BatchGuard").field("id", &self.id).finish()
+    }
+}

bin/app/src/ui/button.rs

@@ -22,6 +22,7 @@ use std::sync::{
     atomic::{AtomicBool, Ordering},
     Arc,
 };
+use tracing::instrument;
 
 use crate::{
     gfx::{Point, Rectangle},
@@ -31,8 +32,8 @@ use crate::{
 
 use super::{DrawUpdate, UIObject};
 
-macro_rules! d { ($($arg:tt)*) => { debug!(target: "app", $($arg)*); } }
-macro_rules! t { ($($arg:tt)*) => { trace!(target: "app", $($arg)*); } }
+macro_rules! d { ($($arg:tt)*) => { debug!(target: "ui::button", $($arg)*); } }
+macro_rules! t { ($($arg:tt)*) => { trace!(target: "ui::button", $($arg)*); } }
 
 pub type ButtonPtr = Arc<Button>;
 
@@ -73,10 +74,10 @@ impl UIObject for Button {
         self.priority.get()
     }
 
+    #[instrument(target = "ui::button")]
     async fn draw(
         &self,
         parent_rect: Rectangle,
-        _trace_id: u32,
         atom: &mut PropertyAtomicGuard,
     ) -> Option<DrawUpdate> {
         let _ = self.rect.eval(atom, &parent_rect);
@@ -156,3 +157,9 @@ impl UIObject for Button {
         }
     }
 }
+
+impl std::fmt::Debug for Button {
+    fn fmt(&self, f: &mut std::fmt::Formatter) -> std::fmt::Result {
+        write!(f, "{:?}", self.node.upgrade().unwrap())
+    }
+}

bin/app/src/ui/chatview/mod.rs

@@ -33,6 +33,7 @@ use std::{
         Arc, Weak,
     },
 };
+use tracing::instrument;
 
 mod page;
 use page::MessageBuffer;
@@ -81,7 +82,7 @@ pub struct ChatMsg {
 
 pub type Timestamp = u64;
 
-#[derive(Clone, SerialEncodable, SerialDecodable, PartialEq)]
+#[derive(Debug, Clone, SerialEncodable, SerialDecodable, PartialEq)]
 pub struct MessageId(pub [u8; 32]);
 
 impl std::fmt::Display for MessageId {
@@ -340,9 +341,8 @@ impl ChatView {
     }
 
     /// Mark line as selected
+    #[instrument(target = "ui::chatview")]
     async fn select_line(&self, batch_id: BatchGuardId, mut y: f32) {
-        let trace_id = rand::random();
-        t!("select_line({y}) [trace_id={trace_id}]");
         // The cursor is inside the rect. We just have to find which line it clicked.
         let rect = self.rect.get();
 
@@ -356,7 +356,7 @@ impl ChatView {
         let mut msgbuf = self.msgbuf.lock().await;
         msgbuf.select_line(y).await;
 
-        self.redraw_cached(batch_id, &mut msgbuf, trace_id).await;
+        self.redraw_cached(batch_id, &mut msgbuf).await;
     }
 
     fn end_touch_phase(&self, touch_y: f32) {
@@ -420,6 +420,7 @@ impl ChatView {
         let _ = self.tree.flush_async().await;
         true
     }
+    #[instrument(target = "ui::chatview")]
     pub async fn handle_insert_line(
         &self,
         timest: Timestamp,
@@ -427,9 +428,6 @@ impl ChatView {
         nick: String,
         text: String,
     ) {
-        let trace_id = rand::random();
-        t!("handle_insert_line({timest}, {msg_id}, {nick}, {text}) [trace_id={trace_id}]");
-
         // Lock message buffer so background loader doesn't load the message as soon as it's
         // inserted into the DB.
         let mut msgbuf = self.msgbuf.lock().await;
@@ -455,9 +453,10 @@ impl ChatView {
         }
 
         let atom = self.render_api.make_guard(gfxtag!("ChatView::handle_insert_line"));
-        self.redraw_cached(atom.batch_id, &mut msgbuf, trace_id).await;
+        self.redraw_cached(atom.batch_id, &mut msgbuf).await;
         self.bgload_cv.notify();
     }
+    #[instrument(target = "ui::chatview")]
     async fn handle_insert_unconf_line(
         &self,
         timest: Timestamp,
@@ -465,9 +464,6 @@ impl ChatView {
         nick: String,
         text: String,
     ) {
-        let trace_id = rand::random();
-        t!("handle_insert_unconf_line({timest}, {msg_id}, {nick}, {text}) [trace_id={trace_id}]");
-
         // We don't add unconfirmed lines to the db. Maybe we should?
 
         // Add message to page
@@ -475,7 +471,7 @@ impl ChatView {
         let Some(privmsg) = msgbuf.insert_privmsg(timest, msg_id, nick, text) else { return };
         privmsg.confirmed = false;
         let atom = self.render_api.make_guard(gfxtag!("ChatView::handle_insert_unconf_line"));
-        self.redraw_cached(atom.batch_id, &mut msgbuf, trace_id).await;
+        self.redraw_cached(atom.batch_id, &mut msgbuf).await;
         self.bgload_cv.notify();
     }
 
@@ -525,8 +521,6 @@ impl ChatView {
     }
 
     async fn handle_bgload(&self) {
-        let trace_id = rand::random();
-        //t!("ChatView::handle_bgload() [trace_id={trace_id}]");
         // Do we need to load some more?
         let scroll = self.scroll.get();
         let rect = self.rect.get();
@@ -592,13 +586,11 @@ impl ChatView {
         //t!("do_redraw = {do_redraw} [trace_id={trace_id}]");
         if do_redraw {
             let atom = self.render_api.make_guard(gfxtag!("ChatView::handle_bgload"));
-            self.redraw_cached(atom.batch_id, &mut msgbuf, trace_id).await;
+            self.redraw_cached(atom.batch_id, &mut msgbuf).await;
         }
     }
 
     async fn scrollview(&self, mut scroll: f32, atom: &mut PropertyAtomicGuard) -> f32 {
-        let trace_id = rand::random();
-        //t!("scrollview({scroll}) [trace_id={trace_id}]");
         let old_scroll = self.scroll.get();
 
         let rect = self.rect.get();
@@ -611,7 +603,7 @@ impl ChatView {
         }
 
         // 2/3 of time spent here  ~3.3ms
-        self.redraw_cached(atom.batch_id, &mut msgbuf, trace_id).await;
+        self.redraw_cached(atom.batch_id, &mut msgbuf).await;
 
         self.scroll.set(atom, scroll);
         self.bgload_cv.notify();
@@ -683,13 +675,8 @@ impl ChatView {
         instrs
     }
 
-    async fn redraw_cached(
-        &self,
-        batch_id: BatchGuardId,
-        msgbuf: &mut MessageBuffer,
-        _trace_id: u32,
-    ) {
-        //t!("ChatView::redraw_cached() [trace_id={trace_id}]");
+    #[instrument(skip(msgbuf), target = "ui::chatview")]
+    async fn redraw_cached(&self, batch_id: BatchGuardId, msgbuf: &mut MessageBuffer) {
         let timest = unixtime();
         let rect = self.rect.get();
 
@@ -702,21 +689,18 @@ impl ChatView {
             vec![(self.dc_key, DrawCall::new(instrs, vec![], self.z_index.get(), "chatview"))];
 
         self.render_api.replace_draw_calls(batch_id, timest, draw_calls);
-        //t!("ChatView::redraw_cached() DONE [trace_id={trace_id}]");
     }
 
     /// Invalidates cache and redraws everything
+    #[instrument(target = "ui::chatview")]
     async fn redraw_all(&self, atom: &mut PropertyAtomicGuard) {
-        let trace_id = rand::random();
-        t!("ChatView::redraw_all() [trace_id={trace_id}]");
         let parent_rect = self.parent_rect.lock().unwrap().clone();
         self.rect.eval(atom, &parent_rect).expect("unable to eval rect");
 
         let mut msgbuf = self.msgbuf.lock().await;
         msgbuf.adjust_params();
         msgbuf.clear_meshes();
-        self.redraw_cached(atom.batch_id, &mut msgbuf, trace_id).await;
-        t!("ChatView::redraw_all() DONE [trace_id={trace_id}]");
+        self.redraw_cached(atom.batch_id, &mut msgbuf).await;
     }
 }
 
@@ -815,14 +799,12 @@ impl UIObject for ChatView {
         self.msgbuf.lock_blocking().clear();
     }
 
+    #[instrument(target = "ui::chatview")]
     async fn draw(
         &self,
         parent_rect: Rectangle,
-        trace_id: u32,
         atom: &mut PropertyAtomicGuard,
     ) -> Option<DrawUpdate> {
-        t!("ChatView::draw({:?}, {trace_id})", self.node.upgrade().unwrap());
-
         *self.parent_rect.lock() = Some(parent_rect.clone());
         self.rect.eval(atom, &parent_rect).ok()?;
         let rect = self.rect.get();
@@ -1056,3 +1038,9 @@ impl Drop for ChatView {
         );
     }
 }
+
+impl std::fmt::Debug for ChatView {
+    fn fmt(&self, f: &mut std::fmt::Formatter) -> std::fmt::Result {
+        write!(f, "{:?}", self.node.upgrade().unwrap())
+    }
+}

bin/app/src/ui/edit/mod.rs

@@ -34,6 +34,7 @@ use std::{
         Arc, Weak,
     },
 };
+use tracing::instrument;
 
 #[cfg(target_os = "android")]
 use crate::AndroidSuggestEvent;
@@ -407,6 +408,7 @@ impl BaseEdit {
         Pimpl::Edit(self_)
     }
 
+    #[inline]
     fn node(&self) -> SceneNodePtr {
         self.node.upgrade().unwrap()
     }
@@ -1009,10 +1011,10 @@ impl BaseEdit {
         self.cursor_is_visible.store(true, Ordering::Relaxed);
     }
 
+    #[instrument(target = "ui::edit")]
     async fn redraw(&self, atom: &mut PropertyAtomicGuard) {
-        let trace_id = rand::random();
         let timest = unixtime();
-        let draw_update = self.make_draw_calls(trace_id).await;
+        let draw_update = self.make_draw_calls().await;
         self.render_api.replace_draw_calls(atom.batch_id, timest, draw_update.draw_calls);
     }
 
@@ -1161,7 +1163,7 @@ impl BaseEdit {
         self.behave.eval_rect(atom).await;
     }
 
-    async fn make_draw_calls(&self, _trace_id: u32) -> DrawUpdate {
+    async fn make_draw_calls(&self) -> DrawUpdate {
         let rect = self.rect.get();
 
         let cursor_instrs = self.get_cursor_instrs().await;
@@ -1559,16 +1561,15 @@ impl UIObject for BaseEdit {
         *self.editor.lock_blocking() = None;
     }
 
+    #[instrument(target = "ui::edit")]
     async fn draw(
         &self,
         parent_rect: Rectangle,
-        trace_id: u32,
         _atom: &mut PropertyAtomicGuard,
     ) -> Option<DrawUpdate> {
-        t!("BaseEdit::draw({:?}, {trace_id})", self.node());
         *self.parent_rect.lock() = Some(parent_rect);
         self.eval_rect().await;
-        Some(self.make_draw_calls(trace_id).await)
+        Some(self.make_draw_calls().await)
     }
 
     async fn handle_char(&self, key: char, mods: KeyMods, repeat: bool) -> bool {
@@ -1781,3 +1782,11 @@ impl UIObject for BaseEdit {
         }
     }
 }
+
+// TODO: impl Drop
+
+impl std::fmt::Debug for BaseEdit {
+    fn fmt(&self, f: &mut std::fmt::Formatter) -> std::fmt::Result {
+        write!(f, "{:?}", self.node.upgrade().unwrap())
+    }
+}

bin/app/src/ui/emoji_picker/mod.rs

@@ -184,24 +184,21 @@ impl EmojiPicker {
         }
     }
 
+    #[instrument(target = "ui::emoji_picker")]
     fn redraw(&self, atom: &mut PropertyAtomicGuard) {
-        let trace_id = rand::random();
         let timest = unixtime();
-        t!("redraw({:?}) [timest={timest}, trace_id={trace_id}]", self.node.upgrade().unwrap());
         let Some(parent_rect) = self.parent_rect.lock().clone() else { return };
 
-        let Some(draw_update) = self.get_draw_calls(parent_rect, trace_id, atom) else {
-            error!(target: "ui::emoji_picker", "Emoji picker failed to draw");
+        let Some(draw_update) = self.get_draw_calls(parent_rect, atom) else {
+            error!(target: "ui:emoji_picker", "Emoji picker failed to draw");
             return
         };
         self.render_api.replace_draw_calls(atom.batch_id, timest, draw_update.draw_calls);
-        t!("redraw DONE [trace_id={trace_id}]");
     }
 
     fn get_draw_calls(
         &self,
         parent_rect: Rectangle,
-        _trace_id: u32,
         atom: &mut PropertyAtomicGuard,
     ) -> Option<DrawUpdate> {
         if let Err(e) = self.rect.eval(atom, &parent_rect) {
@@ -279,15 +276,14 @@ impl UIObject for EmojiPicker {
         self.emoji_meshes.lock().clear();
     }
 
+    #[instrument(target = "ui::emoji_picker")]
     async fn draw(
         &self,
         parent_rect: Rectangle,
-        trace_id: u32,
         atom: &mut PropertyAtomicGuard,
     ) -> Option<DrawUpdate> {
-        t!("EmojiPicker::draw({parent_rect:?}, {trace_id})");
         *self.parent_rect.lock() = Some(parent_rect);
-        self.get_draw_calls(parent_rect, trace_id, atom)
+        self.get_draw_calls(parent_rect, atom)
     }
 
     async fn handle_mouse_move(&self, mouse_pos: Point) -> bool {
@@ -400,3 +396,9 @@ impl Drop for EmojiPicker {
         );
     }
 }
+
+impl std::fmt::Debug for EmojiPicker {
+    fn fmt(&self, f: &mut std::fmt::Formatter) -> std::fmt::Result {
+        write!(f, "{:?}", self.node.upgrade().unwrap())
+    }
+}

bin/app/src/ui/image.rs

@@ -21,6 +21,7 @@ use image::ImageReader;
 use parking_lot::Mutex as SyncMutex;
 use rand::{rngs::OsRng, Rng};
 use std::{io::Cursor, sync::Arc};
+use tracing::instrument;
 
 use crate::{
     gfx::{gfxtag, DrawCall, DrawInstruction, DrawMesh, ManagedTexturePtr, Rectangle, RenderApi},
@@ -31,7 +32,7 @@ use crate::{
     ExecutorPtr,
 };
 
-use super::{DrawTrace, DrawUpdate, OnModify, UIObject};
+use super::{DrawUpdate, OnModify, UIObject};
 
 macro_rules! t { ($($arg:tt)*) => { trace!(target: "ui::image", $($arg)*); } }
 
@@ -119,10 +120,9 @@ impl Image {
         self.render_api.new_texture(width, height, bmp, gfxtag!("img"))
     }
 
+    #[instrument(target = "ui::button")]
     async fn redraw(self: Arc<Self>, batch: BatchGuardPtr) {
-        let trace: DrawTrace = rand::random();
         let timest = unixtime();
-        t!("redraw({:?}) [trace={trace}]", self.node.upgrade().unwrap());
         let Some(parent_rect) = self.parent_rect.lock().clone() else { return };
 
         let atom = &mut batch.spawn();
@@ -131,7 +131,6 @@ impl Image {
             return
         };
         self.render_api.replace_draw_calls(batch.id, timest, draw_update.draw_calls);
-        t!("redraw() DONE [trace={trace}]");
     }
 
     /// Called whenever any property changes.
@@ -206,13 +205,12 @@ impl UIObject for Image {
         *self.texture.lock() = None;
     }
 
+    #[instrument(target = "ui::button")]
     async fn draw(
         &self,
         parent_rect: Rectangle,
-        trace: DrawTrace,
         atom: &mut PropertyAtomicGuard,
     ) -> Option<DrawUpdate> {
-        t!("Image::draw() [trace={trace}]");
         *self.parent_rect.lock() = Some(parent_rect);
         self.get_draw_calls(atom, parent_rect).await
     }
@@ -228,3 +226,9 @@ impl Drop for Image {
         );
     }
 }
+
+impl std::fmt::Debug for Image {
+    fn fmt(&self, f: &mut std::fmt::Formatter) -> std::fmt::Result {
+        write!(f, "{:?}", self.node.upgrade().unwrap())
+    }
+}

bin/app/src/ui/layer.rs

@@ -21,6 +21,7 @@ use miniquad::{KeyCode, KeyMods, MouseButton, TouchPhase};
 use parking_lot::Mutex as SyncMutex;
 use rand::{rngs::OsRng, Rng};
 use std::sync::Arc;
+use tracing::instrument;
 
 use crate::{
     gfx::{DrawCall, DrawInstruction, Point, Rectangle, RenderApi},
@@ -34,7 +35,7 @@ use super::{
     get_children_ordered, get_ui_object3, get_ui_object_ptr, DrawUpdate, OnModify, UIObject,
 };
 
-macro_rules! t { ($($arg:tt)*) => { trace!(target: "ui::layer", $($arg)*); } }
+macro_rules! t { ($($arg:tt)*) => { trace!(target: "ui:layer", $($arg)*); } }
 
 pub type LayerPtr = Arc<Layer>;
 
@@ -83,33 +84,26 @@ impl Layer {
         get_children_ordered(&node)
     }
 
+    #[instrument(target = "ui::layer")]
     async fn redraw(self: Arc<Self>, batch: BatchGuardPtr) {
-        let trace_id = rand::random();
         let timest = unixtime();
-        t!("Layer::redraw({:?}) [trace_id={trace_id}]", self.node.upgrade().unwrap());
         let Some(parent_rect) = self.parent_rect.lock().clone() else { return };
 
         let atom = &mut batch.spawn();
-        let Some(draw_update) = self.get_draw_calls(parent_rect, trace_id, atom).await else {
-            error!(target: "ui::layer", "Layer failed to draw [trace_id={trace_id}]");
+        let Some(draw_update) = self.get_draw_calls(parent_rect, atom).await else {
+            error!(target: "ui:layer", "Layer failed to draw");
             return
         };
         self.render_api.replace_draw_calls(batch.id, timest, draw_update.draw_calls);
-        t!(
-            "Layer::redraw({:?}) DONE [timest={timest}, trace_id={trace_id}]",
-            self.node.upgrade().unwrap()
-        );
     }
 
     async fn get_draw_calls(
         &self,
         parent_rect: Rectangle,
-        trace_id: u32,
         atom: &mut PropertyAtomicGuard,
     ) -> Option<DrawUpdate> {
         self.rect.eval(atom, &parent_rect).ok()?;
         let rect = self.rect.get();
-        t!("Layer::get_draw_calls() [rect={rect:?}, dc={}, trace_id={trace_id}]", self.dc_key);
 
         // Apply viewport
 
@@ -121,8 +115,8 @@ impl Layer {
         if self.is_visible.get() {
             for child in self.get_children() {
                 let obj = get_ui_object3(&child);
-                let Some(mut draw_update) = obj.draw(rect, trace_id, atom).await else {
-                    t!("{child:?} draw returned none [trace_id={trace_id}]");
+                let Some(mut draw_update) = obj.draw(rect, atom).await else {
+                    t!("{child:?} draw returned none");
                     continue
                 };
 
@@ -180,13 +174,12 @@ impl UIObject for Layer {
         }
     }
 
+    #[instrument(target = "ui::layer")]
     async fn draw(
         &self,
         parent_rect: Rectangle,
-        trace_id: u32,
         atom: &mut PropertyAtomicGuard,
     ) -> Option<DrawUpdate> {
-        t!("Layer::draw({:?}) [trace_id={trace_id}]", self.node.upgrade().unwrap());
         *self.parent_rect.lock() = Some(parent_rect);
 
         /*
@@ -200,9 +193,7 @@ impl UIObject for Layer {
         }
         */
 
-        let update = self.get_draw_calls(parent_rect, trace_id, atom).await;
-        t!("Layer::draw({:?}) DONE [trace_id={trace_id}]", self.node.upgrade().unwrap());
-        update
+        self.get_draw_calls(parent_rect, atom).await
     }
 
     async fn handle_char(&self, key: char, mods: KeyMods, repeat: bool) -> bool {
@@ -322,3 +313,11 @@ impl UIObject for Layer {
         }
     }
 }
+
+// TODO: Drop
+
+impl std::fmt::Debug for Layer {
+    fn fmt(&self, f: &mut std::fmt::Formatter) -> std::fmt::Result {
+        write!(f, "{:?}", self.node.upgrade().unwrap())
+    }
+}

bin/app/src/ui/mod.rs

@@ -61,8 +61,6 @@ pub use win::{Window, WindowPtr};
 macro_rules! e { ($($arg:tt)*) => { error!(target: "scene::on_modify", $($arg)*); } }
 macro_rules! t { ($($arg:tt)*) => { trace!(target: "scene::on_modify", $($arg)*); } }
 
-type DrawTrace = u32;
-
 #[async_trait]
 pub trait UIObject: Sync {
     fn priority(&self) -> u32;
@@ -77,7 +75,6 @@ pub trait UIObject: Sync {
     async fn draw(
         &self,
         _parent_rect: Rectangle,
-        _trace: DrawTrace,
         _atom: &mut PropertyAtomicGuard,
     ) -> Option<DrawUpdate> {
         None

bin/app/src/ui/text.rs

@@ -20,6 +20,7 @@ use async_trait::async_trait;
 use parking_lot::Mutex as SyncMutex;
 use rand::{rngs::OsRng, Rng};
 use std::sync::Arc;
+use tracing::instrument;
 
 use crate::{
     gfx::{gfxtag, DrawCall, DrawInstruction, Rectangle, RenderApi},
@@ -33,7 +34,7 @@ use crate::{
     ExecutorPtr,
 };
 
-use super::{DrawTrace, DrawUpdate, OnModify, UIObject};
+use super::{DrawUpdate, OnModify, UIObject};
 
 macro_rules! t { ($($arg:tt)*) => { trace!(target: "ui::text", $($arg)*); } }
 
@@ -136,19 +137,17 @@ impl Text {
         text2::render_layout_with_opts(&layout, debug_opts, &self.render_api, gfxtag!("text"))
     }
 
+    #[instrument(target = "ui::text")]
     async fn redraw(self: Arc<Self>, batch: BatchGuardPtr) {
-        let trace: DrawTrace = rand::random();
         let timest = unixtime();
-        t!("Text::redraw({:?}) [trace={trace}]", self.node.upgrade().unwrap());
         let Some(parent_rect) = self.parent_rect.lock().clone() else { return };
 
         let atom = &mut batch.spawn();
         let Some(draw_update) = self.get_draw_calls(atom, parent_rect).await else {
-            error!(target: "ui::text", "Text failed to draw [trace={trace}]");
+            error!(target: "ui::text", "Text failed to draw");
             return
         };
         self.render_api.replace_draw_calls(batch.id, timest, draw_update.draw_calls);
-        t!("Text::redraw() DONE [trace={trace}]");
     }
 
     async fn get_draw_calls(
@@ -197,13 +196,12 @@ impl UIObject for Text {
         *self.parent_rect.lock() = None;
     }
 
+    #[instrument(target = "ui::text")]
     async fn draw(
         &self,
         parent_rect: Rectangle,
-        trace: DrawTrace,
         atom: &mut PropertyAtomicGuard,
     ) -> Option<DrawUpdate> {
-        t!("Text::draw({:?}) [trace={trace}]", self.node.upgrade().unwrap());
         *self.parent_rect.lock() = Some(parent_rect);
         self.get_draw_calls(atom, parent_rect).await
     }
@@ -223,3 +221,9 @@ impl Drop for Text {
         );
     }
 }
+
+impl std::fmt::Debug for Text {
+    fn fmt(&self, f: &mut std::fmt::Formatter) -> std::fmt::Result {
+        write!(f, "{:?}", self.node.upgrade().unwrap())
+    }
+}

bin/app/src/ui/vector_art/mod.rs

@@ -30,12 +30,12 @@ use crate::{
     ExecutorPtr,
 };
 
-use super::{DrawTrace, DrawUpdate, OnModify, UIObject};
+use super::{DrawUpdate, OnModify, UIObject};
 
 pub mod shape;
 use shape::VectorShape;
 
-macro_rules! t { ($($arg:tt)*) => { trace!(target: "ui::vector_art", $($arg)*); } }
+macro_rules! t { ($($arg:tt)*) => { trace!(target: "ui:vector_art", $($arg)*); } }
 
 pub type VectorArtPtr = Arc<VectorArt>;
 
@@ -84,19 +84,14 @@ impl VectorArt {
         Pimpl::VectorArt(self_)
     }
 
-    fn node_path(&self) -> String {
-        format!("{:?}", self.node.upgrade().unwrap())
-    }
-
+    #[instrument(target = "ui::vector_art")]
     async fn redraw(self: Arc<Self>, batch: BatchGuardPtr) {
-        let trace = rand::random();
         let timest = unixtime();
-        trace!(target: "ui::vector_art", "VectorArt::redraw({}) [trace={trace}]", self.node_path());
         let Some(parent_rect) = self.parent_rect.lock().clone() else { return };
 
         let atom = &mut batch.spawn();
-        let Some(draw_update) = self.get_draw_calls(atom, parent_rect, trace).await else {
-            error!(target: "ui::vector_art", "Mesh failed to draw [trace={trace}]");
+        let Some(draw_update) = self.get_draw_calls(atom, parent_rect).await else {
+            error!(target: "ui:vector_art", "Mesh failed to draw");
             return
         };
         self.render_api.replace_draw_calls(batch.id, timest, draw_update.draw_calls);
@@ -104,7 +99,7 @@ impl VectorArt {
 
     fn get_draw_instrs(&self) -> Vec<DrawInstruction> {
         if !self.is_visible.get() {
-            t!("Skipping draw for invisible {}", self.node_path());
+            t!("Skipping draw for invisible node");
             return vec![]
         }
 
@@ -121,15 +116,13 @@ impl VectorArt {
         vec![DrawInstruction::Move(rect.pos()), DrawInstruction::Draw(mesh)]
     }
 
-    #[instrument(skip_all)]
     async fn get_draw_calls(
         &self,
         atom: &mut PropertyAtomicGuard,
         parent_rect: Rectangle,
-        trace: DrawTrace,
     ) -> Option<DrawUpdate> {
         if let Err(e) = self.rect.eval(atom, &parent_rect) {
-            warn!(target: "ui::vector_art", "Rect eval failure: {e} [trace={trace}]");
+            warn!(target: "ui::vector_art", "Rect eval failure: {e}");
             return None
         }
         let instrs = self.get_draw_instrs();
@@ -165,15 +158,14 @@ impl UIObject for VectorArt {
         *self.parent_rect.lock() = None;
     }
 
+    #[instrument(target = "ui::vector_art")]
     async fn draw(
         &self,
         parent_rect: Rectangle,
-        trace: DrawTrace,
         atom: &mut PropertyAtomicGuard,
     ) -> Option<DrawUpdate> {
-        t!("VectorArt::draw({}) [trace={trace}]", self.node_path());
         *self.parent_rect.lock() = Some(parent_rect);
-        self.get_draw_calls(atom, parent_rect, trace).await
+        self.get_draw_calls(atom, parent_rect).await
     }
 }
 
@@ -187,3 +179,9 @@ impl Drop for VectorArt {
         );
     }
 }
+
+impl std::fmt::Debug for VectorArt {
+    fn fmt(&self, f: &mut std::fmt::Formatter) -> std::fmt::Result {
+        write!(f, "{:?}", self.node.upgrade().unwrap())
+    }
+}

bin/app/src/ui/video.rs

@@ -37,12 +37,12 @@ use crate::{
     ExecutorPtr,
 };
 
-use super::{DrawTrace, DrawUpdate, OnModify, UIObject};
+use super::{DrawUpdate, OnModify, UIObject};
 
 pub const N_LOADERS: usize = 6;
 
-macro_rules! t { ($($arg:tt)*) => { trace!(target: "ui::video", $($arg)*); } }
-macro_rules! d { ($($arg:tt)*) => { debug!(target: "ui::video", $($arg)*); } }
+macro_rules! t { ($($arg:tt)*) => { trace!(target: "ui:video", $($arg)*); } }
+macro_rules! d { ($($arg:tt)*) => { debug!(target: "ui:video", $($arg)*); } }
 
 pub type VideoPtr = Arc<Video>;
 
@@ -218,19 +218,17 @@ impl Video {
         render_api.new_texture(width, height, bmp, gfxtag!("img"))
     }
 
+    #[instrument(target = "ui::video")]
     async fn redraw(self: Arc<Self>, batch: BatchGuardPtr) {
-        let trace: DrawTrace = rand::random();
         let timest = unixtime();
-        t!("redraw({:?}) [trace={trace}]", self.node.upgrade().unwrap());
         let Some(parent_rect) = self.parent_rect.lock().clone() else { return };
 
         let atom = &mut batch.spawn();
         let Some(draw_update) = self.get_draw_calls(atom, parent_rect).await else {
-            error!(target: "ui::video", "Video failed to draw");
+            error!(target: "ui:video", "Video failed to draw");
             return
         };
         self.render_api.replace_draw_calls(batch.id, timest, draw_update.draw_calls);
-        t!("redraw() DONE [trace={trace}]");
     }
 
     /// Called whenever any property changes.
@@ -243,7 +241,6 @@ impl Video {
         mesh.alloc(&self.render_api)
     }
 
-    #[instrument(skip_all)]
     async fn get_draw_calls(
         &self,
         atom: &mut PropertyAtomicGuard,
@@ -375,13 +372,12 @@ impl UIObject for Video {
         *self.vid_data.lock() = None;
     }
 
+    #[instrument(target = "ui::video")]
     async fn draw(
         &self,
         parent_rect: Rectangle,
-        trace: DrawTrace,
         atom: &mut PropertyAtomicGuard,
     ) -> Option<DrawUpdate> {
-        t!("Video::draw() [trace={trace}]");
         *self.parent_rect.lock() = Some(parent_rect);
         self.get_draw_calls(atom, parent_rect).await
     }
@@ -397,3 +393,9 @@ impl Drop for Video {
         );
     }
 }
+
+impl std::fmt::Debug for Video {
+    fn fmt(&self, f: &mut std::fmt::Formatter) -> std::fmt::Result {
+        write!(f, "{:?}", self.node.upgrade().unwrap())
+    }
+}

bin/app/src/ui/win.rs

@@ -441,22 +441,19 @@ impl Window {
         }
     }
 
-    #[instrument(skip_all)]
+    #[instrument(target = "ui::win")]
     pub async fn draw(&self, atom: &mut PropertyAtomicGuard) {
-        let trace_id = rand::random();
         let timest = unixtime();
-
         let virt_size = self.screen_size.get() / self.scale.get();
         let rect = Rectangle::from([0., 0., virt_size.w, virt_size.h]);
-        t!("Window::draw({rect:?}) [timest={timest}, trace_id={trace_id}]");
 
         let mut draw_calls = vec![];
         let mut child_calls = vec![];
 
         for child in self.get_children() {
             let obj = get_ui_object3(&child);
-            let Some(mut draw_update) = obj.draw(rect, trace_id, atom).await else {
-                t!("{child:?} draw returned none [trace_id={trace_id}]");
+            let Some(mut draw_update) = obj.draw(rect, atom).await else {
+                t!("{child:?} draw returned none");
                 continue
             };
 
@@ -470,8 +467,6 @@ impl Window {
         //t!("  => {:?}", draw_calls);
 
         self.render_api.replace_draw_calls(atom.batch_id, timest, draw_calls);
-
-        t!("Window::draw() - replaced draw call [timest={timest}, trace_id={trace_id}]");
     }
 
     async fn reload_locale(&self, atom: &mut PropertyAtomicGuard) {
@@ -498,3 +493,9 @@ impl Window {
         self.draw(atom).await;
     }
 }
+
+impl std::fmt::Debug for Window {
+    fn fmt(&self, f: &mut std::fmt::Formatter) -> std::fmt::Result {
+        write!(f, "{:?}", self.node.upgrade().unwrap())
+    }
+}