feat: tracing

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

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<Client> = Registry::new();
 	pub static ref INTERNAL_CLIENT: Arc<Client> = 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<EventLoop>,
 	index: usize,
+	pid: Option<i32>,
+	exe: Option<PathBuf>,
 	stop_notifier: Arc<Notify>,
 	join_handle: OnceCell<JoinHandle<Result<()>>>,
 
@@ -47,7 +56,16 @@ impl Client {
 		event_loop: &Arc<EventLoop>,
 		connection: UnixStream,
 	) -> Arc<Self> {
-		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"
+		);
 	}
 }

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();

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,

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<Client>, &[u8]) -> Result<Vec<u8>>;
 pub struct Node {
 	pub(super) uid: String,
 	path: String,
+	client: Weak<Client>,
+	message_sender_handle: Option<MessageSenderHandle>,
 	// trailing_slash_pos: usize,
 	local_signals: DashMap<String, Signal, BuildHasherDefault<FxHasher>>,
 	local_methods: DashMap<String, Method, BuildHasherDefault<FxHasher>>,
@@ -76,8 +79,6 @@ pub struct Node {
 
 	// Startup
 	pub startup_settings: OnceCell<Mutex<StartupSettings>>,
-
-	pub(crate) client: Weak<Client>,
 }
 
 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<Client>, _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<u8>) -> Result<Vec<u8>> {
-		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)?

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<Node>,

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<Self> {
-		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<JoinHandle<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);

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::<Self, WlDataDeviceManager, _>(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 {

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) {