From 42d2a41d578533669d1f077eb4b92714dac10223 Mon Sep 17 00:00:00 2001 From: Nova Date: Fri, 2 Dec 2022 20:46:28 -0500 Subject: [PATCH] feat: tracing --- Cargo.toml | 4 ++- src/core/client.rs | 39 +++++++++++++++++++++++++++--- src/main.rs | 16 ++++++------ src/nodes/drawable/text.rs | 2 +- src/nodes/mod.rs | 37 +++++++++++++--------------- src/objects/input/mouse_pointer.rs | 2 +- src/wayland/mod.rs | 11 +++------ src/wayland/state.rs | 9 ++++--- src/wayland/surface.rs | 11 ++++++--- 9 files changed, 82 insertions(+), 49 deletions(-) diff --git a/Cargo.toml b/Cargo.toml index 2ceff71..71e4f92 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -30,11 +30,13 @@ thiserror = "1.0.31" send_wrapper = "0.6.0" prisma = "0.1.1" slog = "2.7.0" -slog-stdlog = "4.1.1" xkbcommon = { version = "0.5.0", default-features = false, optional = true } stardust-xr = "0.8.0" directories = "4.0.1" serde = { version = "1.0.145", features = ["derive"] } +tracing = "0.1.37" +tracing-subscriber = "0.3.16" +tracing-slog = "0.2.0" [dependencies.stereokit] default-features = false diff --git a/src/core/client.rs b/src/core/client.rs index fe2496f..b1c29a0 100644 --- a/src/core/client.rs +++ b/src/core/client.rs @@ -3,22 +3,29 @@ use crate::{ core::registry::Registry, nodes::{data, drawable, fields, hmd, input, items, root::Root, spatial, startup, Node}, }; -use color_eyre::eyre::{eyre, Result}; +use color_eyre::{ + eyre::{eyre, Result}, + Report, +}; use lazy_static::lazy_static; use once_cell::sync::OnceCell; use parking_lot::Mutex; use stardust_xr::messenger::{self, MessageSenderHandle}; use std::{ + fs, path::PathBuf, sync::{Arc, Weak}, }; use tokio::{net::UnixStream, sync::Notify, task::JoinHandle}; +use tracing::{info, warn}; lazy_static! { pub static ref CLIENTS: Registry = Registry::new(); pub static ref INTERNAL_CLIENT: Arc = CLIENTS.add(Client { event_loop: Weak::new(), index: 0, + pid: None, + exe: None, stop_notifier: Default::default(), join_handle: OnceCell::new(), @@ -33,6 +40,8 @@ lazy_static! { pub struct Client { event_loop: Weak, index: usize, + pid: Option, + exe: Option, stop_notifier: Arc, join_handle: OnceCell>>, @@ -47,7 +56,16 @@ impl Client { event_loop: &Arc, connection: UnixStream, ) -> Arc { - println!("New client connected"); + let pid = connection.peer_cred().ok().and_then(|c| c.pid()); + let exe = pid.and_then(|pid| fs::read_link(format!("/proc/{}/exe", pid)).ok()); + info!( + index = index, + pid, + exe = exe + .as_ref() + .and_then(|exe| exe.to_str().map(|s| s.to_string())), + "New client connected" + ); let (mut messenger_tx, mut messenger_rx) = messenger::create(connection); let scenegraph = Arc::new(Scenegraph::default()); @@ -55,6 +73,8 @@ impl Client { let client = CLIENTS.add(Client { event_loop: Arc::downgrade(event_loop), index, + pid, + exe, stop_notifier: Default::default(), join_handle: OnceCell::new(), @@ -88,11 +108,14 @@ impl Client { } }; - let result = tokio::select! { + let result: Result<(), Report> = tokio::select! { _ = client.stop_notifier.notified() => Ok(()), e = dispatch_loop => e, e = flush_loop => e, }; + if let Err(e) = &result { + warn!(error = e.root_cause(), "Client disconnected with error!"); + } client.disconnect().await; result } @@ -118,6 +141,14 @@ impl Drop for Client { fn drop(&mut self) { self.stop_notifier.notify_one(); CLIENTS.remove(self); - println!("Client disconnected"); + info!( + index = self.index, + pid = self.pid, + exe = self + .exe + .as_ref() + .and_then(|exe| exe.to_str().map(|s| s.to_string())), + "Client disconnected" + ); } } diff --git a/src/main.rs b/src/main.rs index 0473502..b22f243 100644 --- a/src/main.rs +++ b/src/main.rs @@ -21,6 +21,7 @@ use stereokit::render::SphericalHarmonics; use stereokit::texture::Texture; use stereokit::{lifecycle::DisplayMode, Settings}; use tokio::{runtime::Handle, sync::oneshot}; +use tracing::info; #[derive(Parser)] #[clap(author, version, about, long_about = None)] @@ -39,6 +40,7 @@ struct CliArgs { } fn main() -> Result<()> { + tracing_subscriber::fmt::init(); let project_dirs = ProjectDirs::from("", "", "stardust").unwrap(); let cli_args = Arc::new(CliArgs::parse()); @@ -55,7 +57,7 @@ fn main() -> Result<()> { .depth_mode(DepthMode::D32) .init() .expect("StereoKit failed to initialize"); - println!("Init StereoKit"); + info!("Init StereoKit"); // Skytex/light stuff { @@ -104,7 +106,7 @@ fn main() -> Result<()> { #[cfg(feature = "wayland")] let mut wayland = wayland::Wayland::new()?; - println!("Stardust ready!"); + info!("Stardust ready!"); stereokit.run( |sk, draw_ctx| { hmd::frame(sk); @@ -131,7 +133,7 @@ fn main() -> Result<()> { wayland.make_context_current(); }, |_| { - println!("Cleanly shut down StereoKit"); + info!("Cleanly shut down StereoKit"); }, ); @@ -142,7 +144,7 @@ fn main() -> Result<()> { event_thread .join() .expect("Failed to cleanly shut down event loop")?; - println!("Cleanly shut down Stardust"); + info!("Cleanly shut down Stardust"); Ok(()) } @@ -157,8 +159,8 @@ async fn event_loop( let (event_loop, event_loop_join_handle) = EventLoop::new().expect("Couldn't create server socket"); - println!("Init event loop"); - println!("Stardust socket created at {}", event_loop.socket_path); + info!("Init event loop"); + info!("Stardust socket created at {}", event_loop.socket_path); let result = tokio::select! { biased; @@ -167,7 +169,7 @@ async fn event_loop( e = event_loop_join_handle => e?, }; - println!("Cleanly shut down event loop"); + info!("Cleanly shut down event loop"); unsafe { stereokit::sys::sk_quit(); diff --git a/src/nodes/drawable/text.rs b/src/nodes/drawable/text.rs index d3a2269..00e0e6c 100644 --- a/src/nodes/drawable/text.rs +++ b/src/nodes/drawable/text.rs @@ -94,7 +94,7 @@ impl Text { .font_path .as_deref() .and_then(|path| Font::from_file(sk, path)) - .unwrap_or(Font::default(sk)); + .unwrap_or_else(|| Font::default(sk)); Ok(SendWrapper::new(TextStyle::new( sk, font, diff --git a/src/nodes/mod.rs b/src/nodes/mod.rs index ea08aab..23077f7 100644 --- a/src/nodes/mod.rs +++ b/src/nodes/mod.rs @@ -9,10 +9,11 @@ pub mod root; pub mod spatial; pub mod startup; -use color_eyre::eyre::{bail, eyre, Result}; +use color_eyre::eyre::{eyre, Result}; use nanoid::nanoid; use once_cell::sync::OnceCell; use parking_lot::Mutex; +use stardust_xr::messenger::MessageSenderHandle; use stardust_xr::scenegraph::ScenegraphError; use std::sync::atomic::{AtomicBool, Ordering}; use std::sync::{Arc, Weak}; @@ -44,6 +45,8 @@ pub type Method = fn(&Node, Arc, &[u8]) -> Result>; pub struct Node { pub(super) uid: String, path: String, + client: Weak, + message_sender_handle: Option, // trailing_slash_pos: usize, local_signals: DashMap>, local_methods: DashMap>, @@ -76,8 +79,6 @@ pub struct Node { // Startup pub startup_settings: OnceCell>, - - pub(crate) client: Weak, } impl Node { @@ -101,6 +102,7 @@ impl Node { let node = Node { uid: nanoid!(), client: Arc::downgrade(client), + message_sender_handle: client.message_sender_handle.clone(), path, // trailing_slash_pos: parent.len(), local_signals: Default::default(), @@ -132,9 +134,9 @@ impl Node { self.get_client().unwrap().scenegraph.add_node(self) } pub fn destroy(&self) { - let _ = self - .get_client() - .map(|c| c.scenegraph.remove_node(self.get_path())); + if let Some(client) = self.get_client() { + client.scenegraph.remove_node(self.get_path()); + } } pub fn destroy_flex(node: &Node, _calling_client: Arc, _data: &[u8]) -> Result<()> { @@ -220,29 +222,24 @@ impl Node { .get_valid_contents() .iter() .filter(|alias| alias.info.remote_signals.iter().any(|e| e == &method)) - .for_each(|alias| { - let _ = alias - .node - .upgrade() - .unwrap() - .send_remote_signal(method, data); + .filter_map(|alias| alias.node.upgrade()) + .for_each(|node| { + let _ = node.send_remote_signal(method, data); }); let path = self.path.clone(); let method = method.to_string(); let data = data.to_vec(); - if let Some(client) = self.get_client() { - if let Some(message_sender_handle) = client.message_sender_handle.as_ref() { - message_sender_handle.signal(path.as_str(), method.as_str(), data.as_slice())?; - } - } + self.message_sender_handle + .as_ref() + .map(|handle| handle.signal(path.as_str(), method.as_str(), data.as_slice())) + .transpose()?; Ok(()) } pub async fn execute_remote_method(&self, method: &str, data: Vec) -> Result> { - let Some(client) = self.get_client() else {bail!("Client does not exist somehow?")}; - let message_sender_handle = client + let message_sender_handle = self .message_sender_handle .as_ref() - .ok_or(eyre!("Messenger does not exist for this node's client"))?; + .ok_or(eyre!("Messenger does not exist for this node"))?; message_sender_handle .method(self.path.as_str(), method, &data)? diff --git a/src/objects/input/mouse_pointer.rs b/src/objects/input/mouse_pointer.rs index 629260d..1366981 100644 --- a/src/objects/input/mouse_pointer.rs +++ b/src/objects/input/mouse_pointer.rs @@ -17,7 +17,7 @@ use stereokit::{ StereoKit, }; -const SK_KEYMAP: &'static str = include_str!("sk.kmp"); +const SK_KEYMAP: &str = include_str!("sk.kmp"); pub struct MousePointer { node: Arc, diff --git a/src/wayland/mod.rs b/src/wayland/mod.rs index f33fdbd..8c73a15 100644 --- a/src/wayland/mod.rs +++ b/src/wayland/mod.rs @@ -19,12 +19,13 @@ use smithay::{ backend::{egl::EGLContext, renderer::gles2::Gles2Renderer}, reexports::wayland_server::{backend::GlobalId, Display, ListeningSocket, Resource}, }; +use tracing::info; use std::{ ffi::c_void, os::unix::{net::UnixListener, prelude::FromRawFd}, sync::Arc, }; -use std::{os::unix::prelude::AsRawFd, time::Duration}; +use std::{os::unix::prelude::AsRawFd}; use stereokit as sk; use stereokit::StereoKit; use tokio::{ @@ -64,8 +65,7 @@ pub struct Wayland { } impl Wayland { pub fn new() -> Result { - let log = ::slog::Logger::root(::slog_stdlog::StdLog.fuse(), slog::o!()); - slog_stdlog::init()?; + let log = ::slog::Logger::root(::tracing_slog::TracingSlogDrain.fuse(), slog::o!()); let egl_raw_handles = get_sk_egl()?; let renderer = unsafe { @@ -108,7 +108,7 @@ impl Wayland { ) -> Result>> { let socket = ListeningSocket::bind_auto("wayland", 0..33)?; if let Some(socket_name) = socket.socket_name() { - println!("Wayland compositor {:?} active", socket_name); + info!("Wayland compositor {:?} active", socket_name); } let listen_async = @@ -146,8 +146,6 @@ impl Wayland { } pub fn frame(&mut self, sk: &StereoKit) { - let time_ms = (sk.time_getf() * 1000.) as u64; - for core_surface in CORE_SURFACES.get_valid_contents() { let Some(client_id) = core_surface @@ -161,7 +159,6 @@ impl Wayland { sk, &mut self.renderer, output, - Duration::from_millis(time_ms), &self.log, |data| { PanelItem::on_mapped(&core_surface, data, seat_data); diff --git a/src/wayland/state.rs b/src/wayland/state.rs index 40decbc..4398c57 100644 --- a/src/wayland/state.rs +++ b/src/wayland/state.rs @@ -27,15 +27,16 @@ use smithay::{ }, }; use std::sync::{Arc, Weak}; +use tracing::info; pub struct ClientState; impl ClientData for ClientState { fn initialized(&self, client_id: ClientId) { - println!("Wayland client {:?} connected", client_id); + info!("Wayland client {:?} connected", client_id); } fn disconnected(&self, client_id: ClientId, reason: DisconnectReason) { - println!( + info!( "Wayland client {:?} disconnected because {:#?}", client_id, reason ); @@ -98,7 +99,7 @@ impl WaylandState { ); display_handle.create_global::(3, ()); - println!("Init Wayland compositor"); + info!("Init Wayland compositor"); Arc::new_cyclic(|weak| { Mutex::new(WaylandState { @@ -127,7 +128,7 @@ impl WaylandState { } impl Drop for WaylandState { fn drop(&mut self) { - println!("Cleanly shut down the Wayland compositor"); + info!("Cleanly shut down the Wayland compositor"); } } impl BufferHandler for WaylandState { diff --git a/src/wayland/surface.rs b/src/wayland/surface.rs index 6b43d90..3308a45 100644 --- a/src/wayland/surface.rs +++ b/src/wayland/surface.rs @@ -135,7 +135,6 @@ impl CoreSurface { sk: &StereoKit, renderer: &mut Gles2Renderer, output: Output, - time: Duration, log: &Logger, on_mapped: F, if_mapped: M, @@ -182,9 +181,13 @@ impl CoreSurface { if_mapped(data); }); - send_frames_surface_tree(&wl_surface, &output, time, None, |_, _| { - Some(output.clone()) - }); + send_frames_surface_tree( + &wl_surface, + &output, + Duration::from_secs_f64(sk.time_get()), + None, + |_, _| Some(output.clone()), + ); } pub fn set_material_offset(&self, material_offset: u32) {