From 44c9b85c261d3a8a311e4867ab59ff7302c00c59 Mon Sep 17 00:00:00 2001 From: Prometheus1400 Date: Sun, 7 Dec 2025 16:29:59 -0800 Subject: [PATCH 1/2] better logging in daemon --- Cargo.lock | 2 + Cargo.toml | 3 +- core/src/comm.rs | 3 - daemon/Cargo.toml | 2 + daemon/src/actors/client_connection.rs | 61 ++++--- daemon/src/actors/pane.rs | 34 ++-- daemon/src/actors/pty.rs | 27 ++-- daemon/src/actors/session.rs | 37 ++--- daemon/src/actors/session_manager.rs | 32 ++-- daemon/src/actors/window.rs | 214 +++++++++++++------------ daemon/src/daemon.rs | 14 +- daemon/src/main.rs | 20 ++- daemon/src/prelude.rs | 2 +- 13 files changed, 243 insertions(+), 208 deletions(-) diff --git a/Cargo.lock b/Cargo.lock index dc8a72c..01831dd 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -1118,6 +1118,7 @@ dependencies = [ "bytes", "color-eyre", "crossterm 0.29.0", + "derive_more", "handle-macro", "itertools 0.14.0", "nix", @@ -1127,6 +1128,7 @@ dependencies = [ "serde", "tokio", "tracing", + "tracing-error", "tracing-subscriber", "vt100", ] diff --git a/Cargo.toml b/Cargo.toml index be72f64..59e5095 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -15,7 +15,8 @@ serde = { version = "1.0", features = ["derive"] } serde_json = { version = "1.0.145" } tokio = { version = "1.48", features = ["full"] } tracing = { version = "0.1" } +tracing-error = { version = "0.2" } tracing-appender = { version = "0.2" } -tracing-subscriber = { version = "0.3", features = ["env-filter"] } +tracing-subscriber = { version = "0.3", features = ["env-filter", "fmt"] } vt100 = { version = "0" } color-eyre = { version = "0.6" } diff --git a/core/src/comm.rs b/core/src/comm.rs index 9541d64..af8241a 100644 --- a/core/src/comm.rs +++ b/core/src/comm.rs @@ -48,15 +48,12 @@ pub async fn send_message(stream: &mut UnixStream, message: &impl Message) -> Re } pub async fn read_message(stream: &mut UnixStream) -> Result { - println!("reading message"); let mut num_bytes = [0u8; 4]; stream.read_exact(&mut num_bytes).await?; let num_bytes = u32::from_be_bytes(num_bytes); let mut message_bytes = vec![0u8; num_bytes as usize]; stream.read_exact(&mut message_bytes).await?; - println!("reading message2"); let res = serde_json::from_slice(&message_bytes)?; - println!("here"); Ok(res) } diff --git a/daemon/Cargo.toml b/daemon/Cargo.toml index d964d9f..8fa4df5 100644 --- a/daemon/Cargo.toml +++ b/daemon/Cargo.toml @@ -17,6 +17,7 @@ remux-core = { path = "../core" } bytes.workspace = true crossterm.workspace = true +derive_more.workspace = true itertools.workspace = true serde.workspace = true tokio.workspace = true @@ -24,6 +25,7 @@ tracing-subscriber.workspace = true tracing.workspace = true vt100.workspace = true color-eyre.workspace = true +tracing-error.workspace = true nix = { version = "0.30.1", features = ["term", "process", "signal"] } pty = "0.2.2" diff --git a/daemon/src/actors/client_connection.rs b/daemon/src/actors/client_connection.rs index 6e81fd9..258f011 100644 --- a/daemon/src/actors/client_connection.rs +++ b/daemon/src/actors/client_connection.rs @@ -1,4 +1,5 @@ use bytes::Bytes; +use derive_more::Display; use handle_macro::Handle; use remux_core::{ comm, @@ -7,7 +8,6 @@ use remux_core::{ states::DaemonState, }; use tokio::{net::UnixStream, sync::mpsc}; -use tracing::Instrument; use crate::{actors::session_manager::SessionManagerHandle, layout::SplitDirection, prelude::*}; @@ -47,7 +47,6 @@ pub struct ClientConnection { state: ClientConnectionState, } impl ClientConnection { - #[instrument(skip(stream, session_manager_handle))] pub fn spawn( stream: UnixStream, session_manager_handle: SessionManagerHandle, @@ -56,7 +55,6 @@ impl ClientConnection { let client = Self::new(stream, session_manager_handle); client.run(connecting_session_id) } - #[instrument(skip(stream, session_manager_handle))] fn new(stream: UnixStream, session_manager_handle: SessionManagerHandle) -> Self { let (tx, rx) = mpsc::channel(10); let handle = ClientConnectionHandle { tx }; @@ -71,12 +69,9 @@ impl ClientConnection { state: ClientConnectionState::Unattached, } } - #[instrument(skip(self), fields(client_id = self.id))] fn run(mut self, initial_session_id: u32) -> Result { - let span = tracing::Span::current(); let handle_clone = self.handle.clone(); - - let _task = tokio::spawn({ + let _task = tokio::spawn( async move { let handle = self.handle.clone(); self.session_manager_handle.client_connect(self.id, handle.clone(), initial_session_id, true).await?; @@ -84,13 +79,22 @@ impl ClientConnection { use remux_core::events::CliEvent; tokio::select! { Some(event) = self.rx.recv() => { + let span = error_span!("Recieved Client Connection Event"); + let _guard = span.enter(); + match &event { + SessionOutput(..) => { + trace!(event=?event); + } + _ => { + info!(event=?event); + } + } match event { InitialAttachResult(result) if matches!(self.state, ClientConnectionState::Unattached) => { - debug!("Client: InitialAttachResult({result:?})"); match result { Ok(daemon_state) => { let res = ResponseBuilder::default().result(ResponseResult::Success(response::Attach{initial_daemon_state: daemon_state})).build(); - debug!("Sending response: {res:?}"); + info!(respnse=?res, "Sending response"); comm::send_message(&mut self.stream, &res).await.unwrap(); self.state = ClientConnectionState::Attached; } @@ -100,75 +104,68 @@ impl ClientConnection { } } SuccessAttachToSession(session_id) => { - debug!("Client: SuccessAttachToSession"); self.state = ClientConnectionState::Attached; comm::send_event(&mut self.stream, DaemonEvent::ActiveSession(session_id)).await.unwrap(); } - FailedAttachToSession{..} => { - debug!("Client: FailedAttachToSession"); + FailedAttachToSession(..) => { comm::send_event(&mut self.stream, DaemonEvent::Disconnected).await.unwrap(); } - DetachFromSession{..} => { - debug!("Client: DetachFromSession"); + DetachFromSession(..) => { self.state = ClientConnectionState::Unattached; } Disconnect => { - trace!("Client: Disconnect"); comm::send_event(&mut self.stream, DaemonEvent::Disconnected).await.unwrap(); } SessionOutput(bytes) => { - trace!("Client: SessionOutput"); comm::send_event(&mut self.stream, DaemonEvent::Raw(bytes)).await.unwrap(); } NewSession(session_id) => { - trace!("Client: NewSession"); comm::send_event(&mut self.stream, DaemonEvent::NewSession(session_id)).await.unwrap(); } _ => { - error!("Unhandled or invalid event '{:?}' for current state '{:?}'", event, self.state); - panic!("Unhandled or invalid event '{:?}' for current state '{:?}'", event, self.state); - // TODO: better error handling + error!(event=?event, state=?self.state, "Unhandled or invalid event for current state"); } } }, res = comm::recv_cli_event(&mut self.stream), if matches!(self.state, ClientConnectionState::Attached) => { match res { Ok(event) => { + let span = error_span!("Recieved Cli Event", event=?event); + let _guard = span.enter(); + match &event { + CliEvent::Raw(..) => { + trace!(event=?event); + } + _ => { + info!(event=?event); + } + } match event { CliEvent::Raw(bytes) => { - trace!("Client Event Input: raw({bytes:?})"); self.session_manager_handle.user_input(self.id, bytes).await.unwrap(); }, CliEvent::TerminalResize{rows, cols} => { - debug!("Client Event Input: terminal resize(rows={rows}, cols={cols})"); - // todo!() + self.session_manager_handle.terminal_resize(rows, cols).await.unwrap(); }, CliEvent::Detach => { - debug!("Client Event Input: detach"); self.session_manager_handle.client_disconnect(self.id).await.unwrap(); }, CliEvent::KillPane => { - debug!("Client Event Input: kill pane"); self.session_manager_handle.user_kill_pane(self.id).await.unwrap(); }, CliEvent::SplitPaneHorizontal => { - debug!("Client Event Input: horizontal split pane"); self.session_manager_handle.user_split_pane(self.id, SplitDirection::Horizontal).await.unwrap(); }, CliEvent::SplitPaneVertical => { - debug!("Client Event Input: vertical split pane"); self.session_manager_handle.user_split_pane(self.id, SplitDirection::Vertical).await.unwrap(); }, CliEvent::NextPane => { - debug!("Client Event Input: next pane"); self.session_manager_handle.user_iterate_pane(self.id, true).await.unwrap(); }, CliEvent::PrevPane => { - debug!("Client Event Input: prev pane"); self.session_manager_handle.user_iterate_pane(self.id, false).await.unwrap(); }, CliEvent::SwitchSession(session_id) => { - debug!("Client Event Input: SwitchSession{session_id}"); self.session_manager_handle.client_switch_session(self.id, session_id).await.unwrap(); } } @@ -184,8 +181,8 @@ impl ClientConnection { } } Ok::<(), Error>(()) - }.instrument(span) - }); + }.instrument(error_span!(parent: None, "Client Actor", id=self.id)) + ); Ok(handle_clone) } diff --git a/daemon/src/actors/pane.rs b/daemon/src/actors/pane.rs index b7d8dba..0d908ce 100644 --- a/daemon/src/actors/pane.rs +++ b/daemon/src/actors/pane.rs @@ -12,7 +12,7 @@ use crate::{ prelude::*, }; -#[derive(Handle)] +#[derive(Handle, Debug)] pub enum PaneEvent { UserInput(Bytes), PtyOutput(Bytes), @@ -44,12 +44,11 @@ pub struct Pane { rect: Rect, } impl Pane { - #[instrument(skip(window_handle))] + #[instrument(skip(window_handle, rect), name = "Pane")] pub fn spawn(window_handle: WindowHandle, id: usize, rect: Rect) -> Result { let pane = Pane::new(window_handle, id, rect)?; pane.run() } - #[instrument(skip(window_handle))] fn new(window_handle: WindowHandle, id: usize, rect: Rect) -> Result { let (tx, rx) = mpsc::channel(10); let handle = PaneHandle { tx }; @@ -68,62 +67,57 @@ impl Pane { rect, }) } - #[instrument(skip(self))] fn run(mut self) -> Result { - let span = tracing::Span::current(); let handle_clone = self.handle.clone(); - let _task = tokio::spawn({ + let _task = tokio::spawn( async move { loop { if let Some(event) = self.rx.recv().await { + match &event { + UserInput(..) | PtyOutput(..) => { + trace!(event=?event); + } + _ => { + info!(event=?event); + } + } match event { UserInput(bytes) => { - trace!("Pane: UserInput({bytes:?})"); self.handle_input(bytes).await.unwrap(); } PtyOutput(bytes) => { - trace!("Pane: PtyOutput({bytes:?}"); if let Err(e) = self.handle_pty_output(bytes).await { error!("Error while handling PTY output: {}", e); } } PtyDied => { - debug!("Pane: PtyDied"); break; } Kill => { - debug!("Pane: Kill"); self.pty_handle.kill().await.unwrap(); break; } Render => { - trace!("Pane: Render"); - if let Err(e) = self.handle_render().await { - error!("Error while rendering pane: {}", e); - } + self.handle_render().await.unwrap(); } Rerender => { - debug!("Pane: Rerender"); self.handle_rerender().await.unwrap(); } Resize { rect } => { - debug!("Pane: Resize"); self.handle_resize(rect).await.unwrap(); } Hide => { - debug!("Pane: Hide"); self.pane_state = PaneState::Hidden; } Reveal => { - debug!("Pane: Reveal"); self.pane_state = PaneState::Visible; } } } } } - .instrument(span) - }); + .in_current_span(), + ); Ok(handle_clone) } diff --git a/daemon/src/actors/pty.rs b/daemon/src/actors/pty.rs index 833d25e..046aab8 100644 --- a/daemon/src/actors/pty.rs +++ b/daemon/src/actors/pty.rs @@ -43,13 +43,12 @@ pub struct Pty { rect: Rect, } impl Pty { - #[instrument(skip(pane_handle, rect))] + #[instrument(skip(pane_handle, rect), name = "Pty")] pub fn spawn(pane_handle: PaneHandle, rect: Rect) -> Result { let pty = Pty::new(pane_handle, rect); pty.run() } - #[instrument(skip(pane_handle, rect))] fn new(pane_handle: PaneHandle, rect: Rect) -> Self { let (tx, rx) = mpsc::channel::(10); let (pty_tx, pty_rx) = mpsc::unbounded_channel::(); @@ -63,9 +62,7 @@ impl Pty { } } - #[instrument(skip(self))] fn run(mut self) -> Result { - let span = tracing::Span::current(); debug!("forking and spawning child PTY process"); let fork_result = unsafe { forkpty(None, None)? }; @@ -85,6 +82,8 @@ impl Pty { tokio::select! { // read from PTY Ok(mut guard) = async_fd.readable() => { + let span = error_span!("Pty Reader"); + let _gard = span.enter(); let mut buf = [0u8; 1024]; match guard.try_io(|fd| unistd::read(fd.get_ref(), &mut buf).map_err(|e| e.into())) { Ok(Ok(n)) if n > 0 => { @@ -92,7 +91,7 @@ impl Pty { self.pane_handle.pty_output(Bytes::copy_from_slice(&buf[..n])).await.unwrap(); }, Ok(Ok(_)) => { - handler.kill().await?; + handler.kill().await.unwrap(); }, Ok(Err(e)) => { error!("Error reading: {e}"); @@ -103,9 +102,11 @@ impl Pty { }, // write to PTY data_opt = self.pty_rx.recv() => { + let span = error_span!("Pty Writer"); + let _gard = span.enter(); match data_opt { Some(data) => { - let mut guard = async_fd.writable().await?; + let mut guard = async_fd.writable().await.unwrap(); let _res = guard.try_io(|fd| { match unistd::write(fd.get_ref(), &data) { Ok(n) if n > 0 => trace!("wrote {n} bytes to pty"), @@ -125,19 +126,21 @@ impl Pty { }, // event handler Some(event) = self.rx.recv() => { - let res = match event.clone() { + let span = error_span!("Recieved Pty Event"); + let _guard = span.enter(); + let res = match &event { Kill => { - debug!("Pty: Kill"); + info!(event=?event); Self::handle_kill(child)?; break; } Input{bytes} => { - trace!("Pty: Input({bytes:?}"); + trace!(event=?event); self.handle_input(bytes.clone()) }, Resize { rect } => { - debug!("Pty: Resize"); - self.handle_resize(async_fd.get_ref().as_raw_fd(), rect) + info!(event=?event); + self.handle_resize(async_fd.get_ref().as_raw_fd(), *rect) } }; if let Err(e) = res { @@ -166,7 +169,7 @@ impl Pty { warn!("Could not notify pane that PTY died (Pane has likely already died) {}", e); } Ok(()) - }.instrument(span) + }.in_current_span() }); Ok(handle) diff --git a/daemon/src/actors/session.rs b/daemon/src/actors/session.rs index 74999c7..9fa1a2f 100644 --- a/daemon/src/actors/session.rs +++ b/daemon/src/actors/session.rs @@ -13,7 +13,7 @@ use crate::{ }; #[allow(unused)] -#[derive(Handle)] +#[derive(Handle, Debug)] pub enum SessionEvent { // user input UserInput(Bytes), @@ -27,7 +27,8 @@ pub enum SessionEvent { Redraw, // output - WindowOutput { bytes: Bytes }, + WindowOutput(Bytes), + TerminalResize { rows: u16, cols: u16 }, Kill, } use SessionEvent::*; @@ -40,12 +41,11 @@ pub struct Session { window_handle: WindowHandle, } impl Session { - #[instrument(skip(session_manager_handle), fields(session_id = id))] + #[instrument(parent=None, skip(session_manager_handle), name="Session")] pub fn spawn(id: u32, session_manager_handle: SessionManagerHandle) -> Result { let session = Session::new(id, session_manager_handle); session.run() } - #[instrument(skip(session_manager_handle), fields(session_id = id))] fn new(id: u32, session_manager_handle: SessionManagerHandle) -> Self { let (tx, rx) = mpsc::channel(10); let handle = SessionHandle { tx }; @@ -58,54 +58,55 @@ impl Session { window_handle, } } - #[instrument(skip(self), fields(session_id = self.id))] fn run(mut self) -> Result { - let span = tracing::Span::current(); let handle_clone = self.handle.clone(); - - let _task = tokio::spawn({ + let _task = tokio::spawn( async move { loop { if let Some(event) = self.rx.recv().await { + match &event { + WindowOutput(..) | UserInput(..) => { + trace!(event=?event); + } + _ => { + info!(event=?event); + } + } match event { UserInput(bytes) => { - trace!("Session: UserInput"); self.handle_user_input(bytes).await.unwrap(); } UserConnection => { - debug!("Session: UserConnection"); self.handle_new_connection().await.unwrap(); } UserSplitPane { direction } => { - debug!("Session: UserSplitPane"); self.handle_split_pane(direction).await.unwrap(); } UserIteratePane { is_next } => { - debug!("Session: UserIteratePane"); self.handle_iterate_pane(is_next).await.unwrap(); } UserKillPane => { - debug!("Session: UserKillPane"); self.handle_kill_pane().await.unwrap(); } - WindowOutput { bytes } => { - trace!("Session: WindowOutput"); + WindowOutput(bytes) => { self.handle_window_output(bytes).await.unwrap(); } Redraw => { self.window_handle.redraw().await.unwrap(); } Kill => { - debug!("Session: Kill"); self.window_handle.kill().await.unwrap(); break; } + TerminalResize { rows, cols } => { + self.window_handle.terminal_resize(rows, cols).await.unwrap(); + } } } } } - .instrument(span) - }); + .in_current_span(), + ); Ok(handle_clone) } diff --git a/daemon/src/actors/session_manager.rs b/daemon/src/actors/session_manager.rs index 38326bb..c5ac789 100644 --- a/daemon/src/actors/session_manager.rs +++ b/daemon/src/actors/session_manager.rs @@ -17,7 +17,7 @@ use crate::{ }; #[allow(unused)] -#[derive(Handle)] +#[derive(Handle, Debug)] pub enum SessionManagerEvent { // client -> session manager events ClientConnect { @@ -56,6 +56,10 @@ pub enum SessionManagerEvent { session_id: u32, bytes: Bytes, }, + TerminalResize { + rows: u16, + cols: u16, + }, } use SessionManagerEvent::*; @@ -69,13 +73,11 @@ pub struct SessionManager { daemon_state: DaemonState, } impl SessionManager { - #[instrument] pub fn spawn() -> Result { let session_manager = SessionManager::new(); session_manager.run() } - #[instrument] fn new() -> Self { let (tx, rx) = mpsc::channel(10); let handle = SessionManagerHandle { tx }; @@ -92,12 +94,19 @@ impl SessionManager { #[instrument(skip(self))] fn run(mut self) -> Result { - let span = tracing::Span::current(); let handle_clone = self.handle.clone(); let _task = tokio::spawn({ async move { loop { if let Some(event) = self.rx.recv().await { + match &event { + SessionSendOutput { .. } => { + trace!(event=?event); + } + _ => { + info!(event=?event); + } + } match event { ClientConnect { client_id, @@ -105,44 +114,41 @@ impl SessionManager { session_id, create_session, } => { - debug!("SessionManager: ClientConnect"); self.handle_client_connect(client_id, client_handle, session_id, create_session) .await .unwrap(); } ClientDisconnect { client_id } => { - debug!("SessionManager: ClientDisconnect"); self.handle_client_disconnect(client_id).await.unwrap(); } ClientSwitchSession { client_id, session_id } => { - debug!("SessionManager: ClientSwitchSession"); self.handle_client_switch_session(client_id, session_id).await.unwrap(); } UserInput { client_id, bytes } => { - trace!("SessionManager: UserInput"); self.handle_client_send_user_input(client_id, bytes).await.unwrap(); } UserSplitPane { client_id, direction } => { - debug!("SessionManager: UserSplitPane"); self.handle_client_split_pane(client_id, direction).await.unwrap(); } UserIteratePane { client_id, is_next } => { - debug!("SessionManager: UserIteratePane"); self.handle_client_iterate_pane(client_id, is_next).await.unwrap(); } UserKillPane { client_id } => { - debug!("SessionManager: UserKillPane"); self.handle_client_kill_pane(client_id).await.unwrap(); } SessionSendOutput { session_id, bytes } => { - trace!("SessionManager: SessionSendOutput"); self.handle_session_send_output(session_id, bytes).await.unwrap(); } + TerminalResize { rows, cols } => { + for session in self.sessions.values_mut() { + session.terminal_resize(rows, cols).await.unwrap(); + } + } } } } } - .instrument(span) + .instrument(error_span!(parent: None, "Session Manager")) }); Ok(handle_clone) diff --git a/daemon/src/actors/window.rs b/daemon/src/actors/window.rs index ce11ec6..70e28a5 100644 --- a/daemon/src/actors/window.rs +++ b/daemon/src/actors/window.rs @@ -31,6 +31,10 @@ pub enum WindowEvent { }, KillPane, Redraw, + TerminalResize { + rows: u16, + cols: u16, + }, Kill, } use WindowEvent::*; @@ -58,6 +62,117 @@ pub struct Window { #[allow(unused)] window_state: WindowState, } +impl Window { + #[instrument(skip(session_handle), name = "Window")] + pub fn spawn(session_handle: SessionHandle) -> Result { + let window = Window::new(session_handle)?; + window.run() + } + + fn new(session_handle: SessionHandle) -> Result { + let (tx, rx) = mpsc::channel(10); + let handle = WindowHandle { tx }; + + let init_pane_id = 0; + let init_layout_node = LayoutNode::Pane { id: init_pane_id }; + + let (cols, rows) = match terminal::size() { + Ok((c, r)) => (c, r), + Err(_) => (80, 24), + }; + + let root_rect = Rect { + x: 0, + y: 0, + width: cols, + height: rows, + }; + let mut layout_sizing_map = HashMap::new(); + layout_sizing_map.insert(init_pane_id, root_rect); + init_layout_node.calculate_layout(root_rect, &mut layout_sizing_map)?; + + let mut panes = HashMap::new(); + if let Some(rect) = layout_sizing_map.get(&init_pane_id) { + let pane_handle = Pane::spawn(handle.clone(), init_pane_id, *rect)?; + panes.insert(init_pane_id, pane_handle); + } + + Ok(Self { + session_handle, + handle, + rx, + layout: init_layout_node, + layout_sizing_map, + panes, + active_pane_id: init_pane_id, + next_pane_id: init_pane_id + 1, + window_state: WindowState::Focused, + pane_cursors: HashMap::new(), + root_rect, + }) + } + #[instrument(skip(self))] + fn run(mut self) -> Result { + let handle_clone = self.handle.clone(); + let _task = tokio::spawn({ + async move { + loop { + if let Some(event) = self.rx.recv().await { + match event { + UserInput(bytes) => { + trace!("Window: UserInput"); + self.handle_user_input(bytes).await.unwrap(); + } + PaneOutput { id, bytes, cursor } => { + trace!("Window: PaneOutput"); + self.handle_pane_output(id, bytes, cursor).await.unwrap(); + } + IteratePane { is_next } => { + debug!("Window: IteratePane"); + self.handle_iterate_pane(is_next).await.unwrap(); + } + SplitPane { direction } => { + debug!("Window: SplitPane"); + self.handle_split_pane(direction).await.unwrap(); + } + KillPane => { + debug!("Window: IteratePane"); + self.handle_kill_pane().await.unwrap(); + } + Redraw => { + debug!("Window: Redraw"); + self.handle_redraw().await.unwrap(); + } + Kill => { + debug!("Window: Kill"); + for pane in self.panes.values() { + pane.kill().await.unwrap(); + } + break; + } + TerminalResize { rows, cols } => { + for pane in self.panes.values_mut() { + pane.resize(Rect { + x: 0, + y: 0, + width: cols, + height: rows, + }) + .await + .unwrap(); + } + } + } + } + } + } + .in_current_span() + }); + + Ok(handle_clone) + } +} + impl Window { async fn handle_user_input(&mut self, bytes: Bytes) -> Result<()> { if let Some(pane) = self.panes.get(&self.active_pane_id) { @@ -203,102 +318,3 @@ impl Window { Ok(()) } } -impl Window { - #[instrument(skip(session_handle))] - pub fn spawn(session_handle: SessionHandle) -> Result { - let window = Window::new(session_handle)?; - window.run() - } - #[instrument(skip(session_handle))] - fn new(session_handle: SessionHandle) -> Result { - let (tx, rx) = mpsc::channel(10); - let handle = WindowHandle { tx }; - - let init_pane_id = 0; - let init_layout_node = LayoutNode::Pane { id: init_pane_id }; - - let (cols, rows) = match terminal::size() { - Ok((c, r)) => (c, r), - Err(_) => (80, 24), - }; - - let root_rect = Rect { - x: 0, - y: 0, - width: cols, - height: rows, - }; - let mut layout_sizing_map = HashMap::new(); - layout_sizing_map.insert(init_pane_id, root_rect); - init_layout_node.calculate_layout(root_rect, &mut layout_sizing_map)?; - - let mut panes = HashMap::new(); - if let Some(rect) = layout_sizing_map.get(&init_pane_id) { - let pane_handle = Pane::spawn(handle.clone(), init_pane_id, *rect)?; - panes.insert(init_pane_id, pane_handle); - } - - Ok(Self { - session_handle, - handle, - rx, - layout: init_layout_node, - layout_sizing_map, - panes, - active_pane_id: init_pane_id, - next_pane_id: init_pane_id + 1, - window_state: WindowState::Focused, - pane_cursors: HashMap::new(), - root_rect, - }) - } - #[instrument(skip(self))] - fn run(mut self) -> Result { - let span = tracing::Span::current(); - let handle_clone = self.handle.clone(); - let _task = tokio::spawn({ - async move { - loop { - if let Some(event) = self.rx.recv().await { - match event { - UserInput(bytes) => { - trace!("Window: UserInput"); - self.handle_user_input(bytes).await.unwrap(); - } - PaneOutput { id, bytes, cursor } => { - trace!("Window: PaneOutput"); - self.handle_pane_output(id, bytes, cursor).await.unwrap(); - } - IteratePane { is_next } => { - debug!("Window: IteratePane"); - self.handle_iterate_pane(is_next).await.unwrap(); - } - SplitPane { direction } => { - debug!("Window: SplitPane"); - self.handle_split_pane(direction).await.unwrap(); - } - KillPane => { - debug!("Window: IteratePane"); - self.handle_kill_pane().await.unwrap(); - } - Redraw => { - debug!("Window: Redraw"); - self.handle_redraw().await.unwrap(); - } - Kill => { - debug!("Window: Kill"); - for pane in self.panes.values() { - pane.kill().await.unwrap(); - } - break; - } - } - } - } - } - .instrument(span) - }); - - Ok(handle_clone) - } -} diff --git a/daemon/src/daemon.rs b/daemon/src/daemon.rs index d6aaf46..575063f 100644 --- a/daemon/src/daemon.rs +++ b/daemon/src/daemon.rs @@ -30,7 +30,7 @@ impl RemuxDaemon { }) } - #[instrument(skip(self))] + #[instrument(skip(self), name = "daemon")] pub async fn listen(&self) -> Result<()> { let socket_path = get_sock_path()?; @@ -38,11 +38,11 @@ impl RemuxDaemon { remove_file(&socket_path)?; } - info!("unix socket path: {:?}", socket_path); + info!(path = ?socket_path, "Connecting to unix socket"); let listener = UnixListener::bind(socket_path)?; loop { let (stream, _) = listener.accept().await?; - info!("accepting connection"); + info!("Accepting connection"); if let Err(e) = handle_message(self.session_manager_handle.clone(), stream).await { error!("{e}"); } @@ -55,10 +55,14 @@ async fn handle_message(session_manager_handle: SessionManagerHandle, mut stream use remux_core::messages::request::{self, DaemonRequestMessage, DaemonRequestMessageBody}; let req: DaemonRequestMessage = comm::read_message(&mut stream).await?; - debug!("Handling message: {req:?}"); + info!(request=?req, "Handling request"); match req.body { DaemonRequestMessageBody::Attach(request::Attach { session_id, create }) => { - debug!("running new client actor"); + info!( + connecting_session = session_id, + create = create, + "Creating new client actor" + ); let _client = ClientConnection::spawn(stream, session_manager_handle, session_id)?; } }; diff --git a/daemon/src/main.rs b/daemon/src/main.rs index 426106c..206324d 100644 --- a/daemon/src/main.rs +++ b/daemon/src/main.rs @@ -5,17 +5,16 @@ mod layout; mod prelude; use daemon::RemuxDaemon; -use tracing_subscriber::{EnvFilter, FmtSubscriber}; use crate::prelude::*; #[tokio::main] async fn main() { - color_eyre::install().unwrap(); if let Err(e) = setup_logging() { eprintln!("{e}"); std::process::exit(1); } + color_eyre::install().unwrap(); if let Err(e) = run().await { error!("{e}"); std::process::exit(1); @@ -23,13 +22,26 @@ async fn main() { } fn setup_logging() -> Result<()> { + use tracing_error::ErrorLayer; + use tracing_subscriber::{EnvFilter, FmtSubscriber, fmt::format::FmtSpan, layer::SubscriberExt}; + let filter = EnvFilter::try_from_default_env().unwrap_or_else(|_| EnvFilter::new("debug")); - let subscriber = FmtSubscriber::builder().with_env_filter(filter).finish(); + let subscriber = FmtSubscriber::builder() + .with_env_filter(filter) + .with_span_events(FmtSpan::NONE) + .with_line_number(false) + .with_file(false) + .with_target(false) + .with_level(true) + .with_thread_ids(false) + .finish() + .with(ErrorLayer::default()); + tracing::subscriber::set_global_default(subscriber)?; Ok(()) } -#[instrument] +#[instrument(err)] async fn run() -> Result<()> { let daemon = RemuxDaemon::new()?; info!("daemon started"); diff --git a/daemon/src/prelude.rs b/daemon/src/prelude.rs index 4e38f64..075093f 100644 --- a/daemon/src/prelude.rs +++ b/daemon/src/prelude.rs @@ -1,6 +1,6 @@ #![allow(unused_imports)] use tokio::task::JoinHandle; -pub use tracing::{debug, error, info, instrument, trace, warn}; +pub use tracing::{Instrument, debug, error, error_span, event, info, info_span, instrument, trace, warn}; pub type DaemonTask = JoinHandle>; From a7c677f7ae9c2d6151d70333d423b4748ac26b80 Mon Sep 17 00:00:00 2001 From: Prometheus1400 Date: Sun, 7 Dec 2025 16:47:35 -0800 Subject: [PATCH 2/2] fix logging for cli too --- Cargo.lock | 1 + Cargo.toml | 6 ++--- cli/Cargo.toml | 3 ++- cli/src/app.rs | 45 ++++++++++++++++---------------- cli/src/main.rs | 39 +++++++++++++++++++-------- cli/src/prelude.rs | 2 +- cli/src/ui/status_line_widget.rs | 4 --- daemon/Cargo.toml | 4 +-- daemon/src/daemon.rs | 2 +- 9 files changed, 60 insertions(+), 46 deletions(-) diff --git a/Cargo.lock b/Cargo.lock index 01831dd..5a72ff1 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -1091,6 +1091,7 @@ dependencies = [ "tokio", "tracing", "tracing-appender", + "tracing-error", "tracing-subscriber", "tui-term", "vt100", diff --git a/Cargo.toml b/Cargo.toml index 59e5095..5da7e93 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -7,16 +7,16 @@ edition = "2024" [workspace.dependencies] bytes = { version = "1.11.0", features = ["serde"] } +color-eyre = { version = "0.6" } crossterm = { version = "0.29.0" } derive_more = { version = "2", features = ["display"] } -itertools = { version = "0.14" } futures-util = { version = "0.3" } +itertools = { version = "0.14" } serde = { version = "1.0", features = ["derive"] } serde_json = { version = "1.0.145" } tokio = { version = "1.48", features = ["full"] } tracing = { version = "0.1" } -tracing-error = { version = "0.2" } tracing-appender = { version = "0.2" } +tracing-error = { version = "0.2" } tracing-subscriber = { version = "0.3", features = ["env-filter", "fmt"] } vt100 = { version = "0" } -color-eyre = { version = "0.6" } diff --git a/cli/Cargo.toml b/cli/Cargo.toml index 521bc2b..ae15eca 100644 --- a/cli/Cargo.toml +++ b/cli/Cargo.toml @@ -9,15 +9,16 @@ handle-macro = {path = "../handle-macro"} remux-core = { path = "../core" } bytes.workspace = true +color-eyre.workspace = true crossterm.workspace = true futures-util.workspace = true serde.workspace = true tokio.workspace = true tracing-appender.workspace = true +tracing-error.workspace = true tracing-subscriber.workspace = true tracing.workspace = true vt100.workspace = true -color-eyre.workspace = true clap = { version = "4.5.51", features = ["derive"] } mlua = { version = "0.11.4", features = ["lua54", "serde", "async", "vendored", "send"] } diff --git a/cli/src/app.rs b/cli/src/app.rs index fade55a..06fb16d 100644 --- a/cli/src/app.rs +++ b/cli/src/app.rs @@ -125,25 +125,22 @@ impl App { } } - #[instrument(skip(self))] + #[instrument(parent=None, skip(self), name="App")] pub async fn run(&mut self) -> Result<()> { let mut term = ratatui::init(); - debug!("starting app"); + debug!("Starting app"); let (input_tx, mut input_rx) = mpsc::channel::(100); let (lua_tx, mut lua_rx) = broadcast::channel(100); self.bg_tasks.extend(input::start_input_listeners(input_tx)); self.bg_tasks.push(lua::start_status_line_task(lua_tx)?); let mut ticker = interval(Duration::from_millis(50)); - debug!("Enabled raw mode"); - // execute!(stdout(), EnterAlternateScreen)?; - debug!("Entered alternate screen"); // need an initial render since ui updates app state to convey terminal size information term.draw(|f| ui::draw(f, &mut self.state))?; loop { if self.state.terminal.needs_resize { let (rows, cols) = self.state.terminal.size; - debug!("setting terminal emulator size (rows={rows}, cols={cols})"); + info!(rows = rows, cols = cols, "Setting terminal emulator size"); self.state.terminal.emulator.set_size(rows, cols); self.state.terminal.needs_resize = false; let (rows, cols) = self.state.terminal.size; @@ -151,53 +148,58 @@ impl App { } tokio::select! { Some(input) = input_rx.recv() => { + let span = error_span!("Recieved Input"); + let _guard = span.enter(); use Input::{Stdin, Resize}; - match input { + match &input { Stdin(bytes) => { - trace!("stdin({bytes:?}"); - self.dispatch_stdin(bytes).await.unwrap(); + trace!(input=?input); + self.dispatch_stdin(bytes.clone()).await.unwrap(); } Resize => { - debug!("resize"); - self.handle_resize(&mut term).await; + info!(input=?input); + self.handle_resize(&mut term).await.unwrap(); } } } Ok(mut status_line_state) = lua_rx.recv() => { - debug!("received status line state"); + trace!(status_line_state=?status_line_state, "received status line state"); status_line_state.apply_built_ins(&self.state); self.state.ui.status_line = status_line_state; } res = comm::recv_daemon_event(&mut self.stream) => { match res { Ok(event) => { + let span = error_span!("Recieved Daemon Event"); + let _guard = span.enter(); + match &event { + DaemonEvent::Raw(..) => { + trace!(event=?event); + } + _ => { + info!(event=?event); + } + } match event { DaemonEvent::Raw(bytes) => { - trace!("DaemonEvent(Raw({bytes:?}))"); self.state.terminal.emulator.process(&bytes); } DaemonEvent::Disconnected => { - debug!("DaemonEvent(Disconnected)"); break; } DaemonEvent::ActiveSession(session_id) => { - debug!("DaemonEvent(ActiveSession({session_id}))"); self.state.daemon.set_active_session(session_id); } DaemonEvent::NewSession(session_id) => { - debug!("DaemonEvent(NewSession({session_id}))"); self.state.daemon.add_session(session_id); } _ => { todo!(); } - // DaemonEvent::DeletedSession(_session_id) => { - // todo!("implement delete session"); - // } } } Err(e) => { - error!("Error receiving daemon event: {e}"); + error!(error=%e, "Error receiving daemon event"); break; } } @@ -217,7 +219,6 @@ impl App { Ok(()) } - #[instrument(skip(self, bytes))] async fn dispatch_stdin(&mut self, bytes: Bytes) -> Result<()> { match self.state.mode { AppMode::Normal => self.handle_stdin_for_normal_mode(bytes).await?, @@ -229,7 +230,6 @@ impl App { async fn handle_stdin_for_selecting_mode(&mut self, bytes: Bytes) -> Result<()> { let event = Event::parse_from(&bytes)?.unwrap(); - panic!("hi"); let selection_opt = match self.state.ui.selector.selector_type { SelectorType::Basic => BasicSelectorWidget::input(event, &mut self.state.ui.selector), @@ -260,7 +260,6 @@ impl App { self.dispatch_action(action).await; } input_parser::ParsedEvent::DaemonAction(cli_event) => { - debug!("sending cli event: {cli_event:?}"); comm::send_event(&mut self.stream, cli_event).await?; } } diff --git a/cli/src/main.rs b/cli/src/main.rs index 1c8c38f..d5c5d9f 100644 --- a/cli/src/main.rs +++ b/cli/src/main.rs @@ -50,20 +50,37 @@ async fn main() { fn setup_logging() -> Result { use tracing_appender::non_blocking; - use tracing_subscriber::{EnvFilter, fmt}; - + use tracing_error::ErrorLayer; + use tracing_subscriber::{EnvFilter, FmtSubscriber, fmt::format::FmtSpan, layer::SubscriberExt}; + // Create the log file let file = File::create("./logs/remux-cli.log")?; - let (non_blocking, guard) = non_blocking(file); - let env_filter = EnvFilter::try_from_default_env().unwrap_or_else(|_| EnvFilter::new("debug")); - let subscriber = fmt().with_writer(non_blocking).with_env_filter(env_filter).finish(); + let (non_blocking_writer, guard) = non_blocking(file); + + // Environment filter + let filter = EnvFilter::try_from_default_env().unwrap_or_else(|_| EnvFilter::new("debug")); + + // Build the subscriber + let subscriber = FmtSubscriber::builder() + .with_env_filter(filter) + .with_span_events(FmtSpan::NONE) + .with_line_number(false) + .with_file(false) + .with_target(false) + .with_level(true) + .with_thread_ids(false) + .with_writer(non_blocking_writer) + .finish() + .with(ErrorLayer::default()); + tracing::subscriber::set_global_default(subscriber)?; + Ok(guard) } #[instrument] async fn connect() -> Result { let socket_path = get_sock_path()?; - debug!("Connecting to {:?}", socket_path); + debug!(path=?socket_path, "Connecting to unix socket"); let stream = UnixStream::connect(socket_path.clone()).await?; Ok(stream) } @@ -71,7 +88,7 @@ async fn connect() -> Result { #[instrument] async fn run(command: Commands) -> Result<()> { let stream = connect().await?; - debug!("Running command: {:?}", command); + debug!("Running command"); match command { Commands::Attach { session_id } => { attach( @@ -89,12 +106,12 @@ async fn run(command: Commands) -> Result<()> { } } -#[instrument(skip(stream, attach_request))] +#[instrument(skip(stream))] async fn attach(mut stream: UnixStream, attach_request: CliRequestMessage) -> Result<()> { - debug!("Sending attach request: {:?}", attach_request); + debug!("Sending attach request"); let res = comm::send_and_recv_message(&mut stream, &attach_request).await?; - debug!("Recieved attach response: {:?}", res); - debug!("Recieved initial daemon state: {:?}", res.initial_daemon_state); + debug!(response=?res, "Recieved attach response"); + debug!(daemon_state=?res.initial_daemon_state, "Recieved initial daemon state"); debug!("Starting app"); let mut app = App::new(stream, res.initial_daemon_state); diff --git a/cli/src/prelude.rs b/cli/src/prelude.rs index 54c9d81..a132d50 100644 --- a/cli/src/prelude.rs +++ b/cli/src/prelude.rs @@ -1,7 +1,7 @@ #![allow(unused)] use tokio::task::JoinHandle; -pub use tracing::{debug, error, info, instrument, trace, warn}; +pub use tracing::{debug, error, error_span, info, instrument, trace, warn}; pub type CliTask = JoinHandle>; diff --git a/cli/src/ui/status_line_widget.rs b/cli/src/ui/status_line_widget.rs index 02bc282..4a4020c 100644 --- a/cli/src/ui/status_line_widget.rs +++ b/cli/src/ui/status_line_widget.rs @@ -2,7 +2,6 @@ use ratatui::{ layout::{Constraint, Direction, Layout}, widgets::{Paragraph, Widget}, }; -use tracing::info; use crate::states::status_line_state::StatusLineState; @@ -22,9 +21,6 @@ impl Widget for StatusLineWidget { return; } - info!("rendering status line widget"); - - // 1. Create 3 horizontal constraints for Left, Center, Right sections let chunks = Layout::default() .direction(Direction::Horizontal) .constraints([ diff --git a/daemon/Cargo.toml b/daemon/Cargo.toml index 8fa4df5..9bc7e61 100644 --- a/daemon/Cargo.toml +++ b/daemon/Cargo.toml @@ -16,16 +16,16 @@ handle-macro = {path = "../handle-macro"} remux-core = { path = "../core" } bytes.workspace = true +color-eyre.workspace = true crossterm.workspace = true derive_more.workspace = true itertools.workspace = true serde.workspace = true tokio.workspace = true +tracing-error.workspace = true tracing-subscriber.workspace = true tracing.workspace = true vt100.workspace = true -color-eyre.workspace = true -tracing-error.workspace = true nix = { version = "0.30.1", features = ["term", "process", "signal"] } pty = "0.2.2" diff --git a/daemon/src/daemon.rs b/daemon/src/daemon.rs index 575063f..491ac56 100644 --- a/daemon/src/daemon.rs +++ b/daemon/src/daemon.rs @@ -30,7 +30,7 @@ impl RemuxDaemon { }) } - #[instrument(skip(self), name = "daemon")] + #[instrument(skip(self), name = "Daemon")] pub async fn listen(&self) -> Result<()> { let socket_path = get_sock_path()?;