diff options
author | har7an <99636919+har7an@users.noreply.github.com> | 2022-11-08 10:56:23 +0000 |
---|---|---|
committer | GitHub <noreply@github.com> | 2022-11-08 10:56:23 +0000 |
commit | 453142775c96752730d7caf85532e616e2aaa719 (patch) | |
tree | 607aff5d44ec5894fa98b7e4d108f8bb2815684c | |
parent | 39c8d97054ff5a2745df455666dc2decd1fefc0e (diff) |
errors: Remove `log::error` in server (#1881)
* server/wasm_vm: Replace `log::error!`
with better error logging by means of `non_fatal`. This preserves the
original error and allows adding context information on top. Also makes
error formatting more uniform across the application.
* server/tab: Replace `log::error!`
with better error logging by means of `non_fatal`. This preserves the
original error and allows adding context information on top. Also makes
error formatting more uniform across the application.
* server/route: Replace `log::error!`
and propagate the error to the caller instead.
* server/pty: Replace `log::error!`
with better error logging by means of `non_fatal`. This preserves the
original error and allows adding context information on top. Also makes
error formatting more uniform across the application.
Also add per-instruction error context to make it clear what we tried to
accomplish when an error occured.
* server/panes/tiled_panes: Merge dependencies
and sort them into a better order.
* server/panes/tiled_panes: Replace `log::error!`
with better error logging by means of `non_fatal`. This preserves the
original error and allows adding context information on top. Also makes
error formatting more uniform across the application.
* server/os_input_output: Merge depndencies
and sort them into a better order.
* server/logging_pipe: Replace `log::error!`
with better error logging by means of `non_fatal`. This preserves the
original error and allows adding context information on top. Also makes
error formatting more uniform across the application.
* server/os_io: Remove uses of `log::error`
* changelog: Add PR #1881
* server/os_io: Gracefully handle failing resize
for terminals IDs that don't exist, instead of propagating the error to
the user.
* server/lib: Remove leftover log message
* server/pty: Log error cause
rather than providing a hard-coded error reason which is plain wrong in
this context.
* server/screen: Remove calls to `log::error!`
and change `get_active_tab(_mut)?` to return a `Result` instead of an
`Option`. This already makes many places in the code obsolete where
previously "failed to get active tab..." was logged manually.
Rather than logging, use the `anyhow::Error`s we have, along with all
their context information, and log these instead.
-rw-r--r-- | CHANGELOG.md | 1 | ||||
-rw-r--r-- | zellij-server/src/lib.rs | 5 | ||||
-rw-r--r-- | zellij-server/src/logging_pipe.rs | 37 | ||||
-rw-r--r-- | zellij-server/src/os_input_output.rs | 82 | ||||
-rw-r--r-- | zellij-server/src/panes/tiled_panes/mod.rs | 56 | ||||
-rw-r--r-- | zellij-server/src/pty.rs | 53 | ||||
-rw-r--r-- | zellij-server/src/route.rs | 5 | ||||
-rw-r--r-- | zellij-server/src/screen.rs | 336 | ||||
-rw-r--r-- | zellij-server/src/tab/mod.rs | 17 | ||||
-rw-r--r-- | zellij-server/src/wasm_vm.rs | 4 |
10 files changed, 343 insertions, 253 deletions
diff --git a/CHANGELOG.md b/CHANGELOG.md index 3cede18f1..bed8647c7 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -29,6 +29,7 @@ The format is based on [Keep a Changelog](https://keepachangelog.com/en/1.0.0/) * fix: allow cli actions to be run outside of a tty environment (https://github.com/zellij-org/zellij/pull/1905) * Terminal compatibility: send focus in/out events to terminal panes (https://github.com/zellij-org/zellij/pull/1908) * fix: various bugs with no-frames and floating panes (https://github.com/zellij-org/zellij/pull/1909) +* debugging: Improve error logging in server (https://github.com/zellij-org/zellij/pull/1881) ## [0.32.0] - 2022-10-25 diff --git a/zellij-server/src/lib.rs b/zellij-server/src/lib.rs index dc28a9aea..07e8d0515 100644 --- a/zellij-server/src/lib.rs +++ b/zellij-server/src/lib.rs @@ -573,11 +573,6 @@ pub fn start_server(mut os_input: Box<dyn ServerOsApi>, socket_path: PathBuf) { }, ServerInstruction::ActiveClients(client_id) => { let client_ids = session_state.read().unwrap().client_ids(); - log::error!( - "Sending client_ids {:?} to client {}", - client_ids, - client_id - ); send_to_client!( client_id, os_input, diff --git a/zellij-server/src/logging_pipe.rs b/zellij-server/src/logging_pipe.rs index 085a672fd..d54de9b09 100644 --- a/zellij-server/src/logging_pipe.rs +++ b/zellij-server/src/logging_pipe.rs @@ -5,7 +5,7 @@ use std::{ use log::{debug, error}; use wasmer_wasi::{WasiFile, WasiFsError}; -use zellij_utils::serde; +use zellij_utils::{errors::prelude::*, serde}; use chrono::prelude::*; use serde::{Deserialize, Serialize}; @@ -75,27 +75,30 @@ impl Write for LoggingPipe { fn flush(&mut self) -> std::io::Result<()> { self.buffer.make_contiguous(); - if let Ok(converted_buffer) = std::str::from_utf8(self.buffer.as_slices().0) { - if converted_buffer.contains('\n') { - let mut consumed_bytes = 0; - let mut split_converted_buffer = converted_buffer.split('\n').peekable(); - - while let Some(msg) = split_converted_buffer.next() { - if split_converted_buffer.peek().is_none() { - // Log last chunk iff the last char is endline. Otherwise do not do it. - if converted_buffer.ends_with('\n') && !msg.is_empty() { + match std::str::from_utf8(self.buffer.as_slices().0) { + Ok(converted_buffer) => { + if converted_buffer.contains('\n') { + let mut consumed_bytes = 0; + let mut split_converted_buffer = converted_buffer.split('\n').peekable(); + + while let Some(msg) = split_converted_buffer.next() { + if split_converted_buffer.peek().is_none() { + // Log last chunk iff the last char is endline. Otherwise do not do it. + if converted_buffer.ends_with('\n') && !msg.is_empty() { + self.log_message(msg); + consumed_bytes += msg.len() + 1; + } + } else { self.log_message(msg); consumed_bytes += msg.len() + 1; } - } else { - self.log_message(msg); - consumed_bytes += msg.len() + 1; } + drop(self.buffer.drain(..consumed_bytes)); } - drop(self.buffer.drain(..consumed_bytes)); - } - } else { - error!("Buffer conversion didn't work. This is unexpected"); + }, + Err(e) => Err::<(), _>(e) + .context("failed to flush logging pipe buffer") + .non_fatal(), } Ok(()) diff --git a/zellij-server/src/os_input_output.rs b/zellij-server/src/os_input_output.rs index 322cfb9fd..24a2ace21 100644 --- a/zellij-server/src/os_input_output.rs +++ b/zellij-server/src/os_input_output.rs @@ -1,45 +1,44 @@ -use std::collections::{BTreeMap, HashMap, HashSet}; -use std::{fs::File, io::Write}; +use crate::{panes::PaneId, ClientId}; -use crate::panes::PaneId; -use zellij_utils::tempfile::tempfile; - -use std::env; -use std::os::unix::io::RawFd; -use std::os::unix::process::CommandExt; -use std::path::PathBuf; -use std::process::{Child, Command}; -use std::sync::{Arc, Mutex}; - -use zellij_utils::errors::prelude::*; -use zellij_utils::{async_std, interprocess, libc, nix, signal_hook}; - -use async_std::fs::File as AsyncFile; -use async_std::os::unix::io::FromRawFd; +use async_std::{fs::File as AsyncFile, io::ReadExt, os::unix::io::FromRawFd}; use interprocess::local_socket::LocalSocketStream; - -use sysinfo::{ProcessExt, ProcessRefreshKind, System, SystemExt}; - -use nix::pty::{openpty, OpenptyResult, Winsize}; -use nix::sys::signal::{kill, Signal}; -use nix::sys::termios; - -use nix::unistd; +use nix::{ + pty::{openpty, OpenptyResult, Winsize}, + sys::{ + signal::{kill, Signal}, + termios, + }, + unistd, +}; use signal_hook::consts::*; +use sysinfo::{ProcessExt, ProcessRefreshKind, System, SystemExt}; use zellij_utils::{ + async_std, data::Palette, + errors::prelude::*, input::command::{RunCommand, TerminalAction}, + interprocess, ipc::{ClientToServerMsg, IpcReceiverWithContext, IpcSenderWithContext, ServerToClientMsg}, + libc, nix, shared::default_palette, + signal_hook, + tempfile::tempfile, }; -use async_std::io::ReadExt; -pub use async_trait::async_trait; +use std::{ + collections::{BTreeMap, HashMap, HashSet}, + env, + fs::File, + io::Write, + os::unix::{io::RawFd, process::CommandExt}, + path::PathBuf, + process::{Child, Command}, + sync::{Arc, Mutex}, +}; +pub use async_trait::async_trait; pub use nix::unistd::Pid; -use crate::ClientId; - fn set_terminal_size_using_fd(fd: RawFd, columns: u16, rows: u16) { // TODO: do this with the nix ioctl use libc::ioctl; @@ -164,10 +163,11 @@ fn handle_openpty( command.current_dir(current_dir); } else { // TODO: propagate this to the user - log::error!( - "Failed to set CWD for new pane. {} does not exist or is not a folder", + return Err(anyhow!( + "Failed to set CWD for new pane. '{}' does not exist or is not a folder", current_dir.display() - ); + )) + .context("failed to open PTY"); } } command @@ -417,16 +417,18 @@ pub trait ServerOsApi: Send + Sync { impl ServerOsApi for ServerOsInputOutput { fn set_terminal_size_using_terminal_id(&self, id: u32, cols: u16, rows: u16) -> Result<()> { + let err_context = || { + format!( + "failed to set terminal id {} to size ({}, {})", + id, rows, cols + ) + }; + match self .terminal_id_to_raw_fd .lock() .to_anyhow() - .with_context(|| { - format!( - "failed to set terminal id {} to size ({}, {})", - id, rows, cols - ) - })? + .with_context(err_context)? .get(&id) { Some(Some(fd)) => { @@ -435,7 +437,9 @@ impl ServerOsApi for ServerOsInputOutput { } }, _ => { - log::error!("Failed to find terminal fd for id: {id}, so cannot resize terminal"); + Err::<(), _>(anyhow!("failed to find terminal fd for id {id}")) + .with_context(err_context) + .non_fatal(); }, } Ok(()) diff --git a/zellij-server/src/panes/tiled_panes/mod.rs b/zellij-server/src/panes/tiled_panes/mod.rs index 3bbd872a2..52b287955 100644 --- a/zellij-server/src/panes/tiled_panes/mod.rs +++ b/zellij-server/src/panes/tiled_panes/mod.rs @@ -1,29 +1,29 @@ mod pane_resizer; mod tiled_pane_grid; -use crate::tab::{Pane, MIN_TERMINAL_HEIGHT, MIN_TERMINAL_WIDTH}; -use tiled_pane_grid::{split, TiledPaneGrid}; - use crate::{ os_input_output::ServerOsApi, output::Output, panes::{ActivePanes, PaneId}, - ui::boundaries::Boundaries, - ui::pane_contents_and_ui::PaneContentsAndUi, + tab::{Pane, MIN_TERMINAL_HEIGHT, MIN_TERMINAL_WIDTH}, + ui::{boundaries::Boundaries, pane_contents_and_ui::PaneContentsAndUi}, ClientId, }; -use std::cell::RefCell; -use std::collections::{BTreeMap, HashMap, HashSet}; -use std::rc::Rc; -use std::time::Instant; -use zellij_utils::errors::prelude::*; +use tiled_pane_grid::{split, TiledPaneGrid}; use zellij_utils::{ data::{ModeInfo, Style}, - input::command::RunCommand, - input::layout::SplitDirection, + errors::prelude::*, + input::{command::RunCommand, layout::SplitDirection}, pane_size::{Offset, PaneGeom, Size, SizeInPixels, Viewport}, }; +use std::{ + cell::RefCell, + collections::{BTreeMap, HashMap, HashSet}, + rc::Rc, + time::Instant, +}; + macro_rules! resize_pty { ($pane:expr, $os_input:expr) => { if let PaneId::Terminal(ref pid) = $pane.pid() { @@ -226,17 +226,18 @@ impl TiledPanes { *self.display_area.borrow(), *self.viewport.borrow(), ); - let result = match direction { + match direction { SplitDirection::Horizontal => { pane_grid.layout(direction, (*self.display_area.borrow()).cols) }, SplitDirection::Vertical => { pane_grid.layout(direction, (*self.display_area.borrow()).rows) }, - }; - if let Err(e) = &result { - log::error!("{:?} relayout of the tab failed: {}", direction, e); } + .or_else(|e| Err(anyError::msg(e))) + .with_context(|| format!("{:?} relayout of tab failed", direction)) + .non_fatal(); + self.set_pane_frames(self.draw_pane_frames); } pub fn set_pane_frames(&mut self, draw_pane_frames: bool) { @@ -492,16 +493,23 @@ impl TiledPanes { display_area.cols = cols; }, Err(e) => { - log::error!("Failed to horizontally resize the tab: {:?}", e); + Err::<(), _>(anyError::msg(e)) + .context("failed to resize tab horizontally") + .non_fatal(); + }, + }; + match pane_grid.layout(SplitDirection::Vertical, rows) { + Ok(_) => { + let row_difference = rows as isize - display_area.rows as isize; + viewport.rows = (viewport.rows as isize + row_difference) as usize; + display_area.rows = rows; + }, + Err(e) => { + Err::<(), _>(anyError::msg(e)) + .context("failed to resize tab vertically") + .non_fatal(); }, }; - if pane_grid.layout(SplitDirection::Vertical, rows).is_ok() { - let row_difference = rows as isize - display_area.rows as isize; - viewport.rows = (viewport.rows as isize + row_difference) as usize; - display_area.rows = rows; - } else { - log::error!("Failed to vertically resize the tab!!!"); - } } self.set_pane_frames(self.draw_pane_frames); } diff --git a/zellij-server/src/pty.rs b/zellij-server/src/pty.rs index da8fd20dc..3f081bf75 100644 --- a/zellij-server/src/pty.rs +++ b/zellij-server/src/pty.rs @@ -87,7 +87,6 @@ pub(crate) struct Pty { } pub(crate) fn pty_thread_main(mut pty: Pty, layout: Box<Layout>) -> Result<()> { - let err_context = || "failed in pty thread main".to_string(); loop { let (event, mut err_ctx) = pty.bus.recv().expect("failed to receive event on channel"); err_ctx.add_call(ContextType::Pty((&event).into())); @@ -98,6 +97,9 @@ pub(crate) fn pty_thread_main(mut pty: Pty, layout: Box<Layout>) -> Result<()> { name, client_or_tab_index, ) => { + let err_context = + || format!("failed to spawn terminal for {:?}", client_or_tab_index); + let (hold_on_close, run_command, pane_title) = match &terminal_action { Some(TerminalAction::RunCommand(run_command)) => ( run_command.hold_on_close, @@ -146,7 +148,7 @@ pub(crate) fn pty_thread_main(mut pty: Pty, layout: Box<Layout>) -> Result<()> { .with_context(err_context)?; } } else { - log::error!("Failed to spawn terminal: command not found"); + log::error!("Failed to spawn terminal: {:?}", err); pty.close_pane(PaneId::Terminal(*terminal_id)) .with_context(err_context)?; } @@ -156,6 +158,9 @@ pub(crate) fn pty_thread_main(mut pty: Pty, layout: Box<Layout>) -> Result<()> { } }, PtyInstruction::OpenInPlaceEditor(temp_file, line_number, client_id) => { + let err_context = + || format!("failed to open in-place editor for client {}", client_id); + match pty.spawn_terminal( Some(TerminalAction::OpenFile(temp_file, line_number)), ClientOrTabIndex::ClientId(client_id), @@ -170,11 +175,14 @@ pub(crate) fn pty_thread_main(mut pty: Pty, layout: Box<Layout>) -> Result<()> { .with_context(err_context)?; }, Err(e) => { - log::error!("Failed to open editor: {}", e); + Err::<(), _>(e).with_context(err_context).non_fatal(); }, } }, PtyInstruction::SpawnTerminalVertically(terminal_action, name, client_id) => { + let err_context = + || format!("failed to spawn terminal vertically for client {client_id}"); + let (hold_on_close, run_command, pane_title) = match &terminal_action { Some(TerminalAction::RunCommand(run_command)) => ( run_command.hold_on_close, @@ -242,6 +250,9 @@ pub(crate) fn pty_thread_main(mut pty: Pty, layout: Box<Layout>) -> Result<()> { } }, PtyInstruction::SpawnTerminalHorizontally(terminal_action, name, client_id) => { + let err_context = + || format!("failed to spawn terminal horizontally for client {client_id}"); + let (hold_on_close, run_command, pane_title) = match &terminal_action { Some(TerminalAction::RunCommand(run_command)) => ( run_command.hold_on_close, @@ -315,9 +326,13 @@ pub(crate) fn pty_thread_main(mut pty: Pty, layout: Box<Layout>) -> Result<()> { pty.bus .senders .send_to_screen(ScreenInstruction::GoToTab(tab_index, Some(client_id))) - .with_context(err_context)?; + .with_context(|| { + format!("failed to move client {} to tab {}", client_id, tab_index) + })?; }, PtyInstruction::NewTab(terminal_action, tab_layout, tab_name, client_id) => { + let err_context = || format!("failed to open new tab for client {}", client_id); + pty.spawn_terminals_for_layout( tab_layout.unwrap_or_else(|| layout.new_tab()), terminal_action.clone(), @@ -341,20 +356,26 @@ pub(crate) fn pty_thread_main(mut pty: Pty, layout: Box<Layout>) -> Result<()> { } }, PtyInstruction::ClosePane(id) => { - pty.close_pane(id).with_context(err_context)?; - pty.bus - .senders - .send_to_server(ServerInstruction::UnblockInputThread) - .with_context(err_context)?; + pty.close_pane(id) + .and_then(|_| { + pty.bus + .senders + .send_to_server(ServerInstruction::UnblockInputThread) + }) + .with_context(|| format!("failed to close pane {:?}", id))?; }, PtyInstruction::CloseTab(ids) => { - pty.close_tab(ids).with_context(err_context)?; - pty.bus - .senders - .send_to_server(ServerInstruction::UnblockInputThread) - .with_context(err_context)?; + pty.close_tab(ids) + .and_then(|_| { + pty.bus + .senders + .send_to_server(ServerInstruction::UnblockInputThread) + }) + .context("failed to close tabs")?; }, PtyInstruction::ReRunCommandInPane(pane_id, run_command) => { + let err_context = || format!("failed to rerun command in pane {:?}", pane_id); + match pty .rerun_command_in_pane(pane_id, run_command.clone()) .with_context(err_context) @@ -585,9 +606,7 @@ impl Pty { // stripped later )); }, - Err(e) => { - log::error!("Failed to spawn terminal: {}", e); - }, + Err(e) => Err::<(), _>(e).with_context(err_context).non_fatal(), } } else { match self diff --git a/zellij-server/src/route.rs b/zellij-server/src/route.rs index 0d2da7b7d..0c8417128 100644 --- a/zellij-server/src/route.rs +++ b/zellij-server/src/route.rs @@ -795,14 +795,15 @@ pub(crate) fn route_thread_main( } }, None => { - log::error!("Received empty message from client"); let _ = os_input.send_to_client( client_id, ServerToClientMsg::Exit(ExitReason::Error( "Received empty message".to_string(), )), ); - break; + + return Err(anyhow!("received empty message from client")) + .with_context(err_context); }, } } diff --git a/zellij-server/src/screen.rs b/zellij-server/src/screen.rs index 3d6d28514..01a4b33f0 100644 --- a/zellij-server/src/screen.rs +++ b/zellij-server/src/screen.rs @@ -46,41 +46,41 @@ use zellij_utils::{ /// argument is optional and not needed when the closure returns `()` macro_rules! active_tab { ($screen:ident, $client_id:ident, $closure:expr) => { - if let Some(active_tab) = $screen.get_active_tab_mut($client_id) { - // This could be made more ergonomic by declaring the type of 'active_tab' in the - // closure, known as "Type Ascription". Then we could hint the type here and forego the - // "&mut Tab" in all the closures below... - // See: https://github.com/rust-lang/rust/issues/23416 - $closure(active_tab); - } else { - log::error!("Active tab not found for client id: {:?}", $client_id); - } + match $screen.get_active_tab_mut($client_id) { + Ok(active_tab) => { + // This could be made more ergonomic by declaring the type of 'active_tab' in the + // closure, known as "Type Ascription". Then we could hint the type here and forego the + // "&mut Tab" in all the closures below... + // See: https://github.com/rust-lang/rust/issues/23416 + $closure(active_tab); + }, + Err(err) => Err::<(), _>(err).non_fatal(), + }; }; // Same as above, but with an added `?` for when the close returns a `Result` type. ($screen:ident, $client_id:ident, $closure:expr, ?) => { - if let Some(active_tab) = $screen.get_active_tab_mut($client_id) { + match $screen.get_active_tab_mut($client_id) { + Ok(active_tab) => { $closure(active_tab)?; - } else { - log::error!("Active tab not found for client id: {:?}", $client_id); - } + }, + Err(err) => Err::<(), _>(err).non_fatal(), + }; }; } macro_rules! active_tab_and_connected_client_id { ($screen:ident, $client_id:ident, $closure:expr) => { match $screen.get_active_tab_mut($client_id) { - Some(active_tab) => { + Ok(active_tab) => { $closure(active_tab, $client_id); }, - None => { + Err(_) => { if let Some(client_id) = $screen.get_first_client_id() { match $screen.get_active_tab_mut(client_id) { - Some(active_tab) => { + Ok(active_tab) => { $closure(active_tab, client_id); }, - None => { - log::error!("Active tab not found for client id: {:?}", $client_id); - }, + Err(err) => Err::<(), _>(err).non_fatal(), } } else { log::error!("No client ids in screen found"); @@ -91,18 +91,16 @@ macro_rules! active_tab_and_connected_client_id { // Same as above, but with an added `?` for when the closure returns a `Result` type. ($screen:ident, $client_id:ident, $closure:expr, ?) => { match $screen.get_active_tab_mut($client_id) { - Some(active_tab) => { + Ok(active_tab) => { $closure(active_tab, $client_id)?; }, - None => { + Err(_) => { if let Some(client_id) = $screen.get_first_client_id() { match $screen.get_active_tab_mut(client_id) { - Some(active_tab) => { + Ok(active_tab) => { $closure(active_tab, client_id)?; }, - None => { - log::error!("Active tab not found for client id: {:?}", $client_id); - }, + Err(err) => Err::<(), _>(err).non_fatal(), } } else { log::error!("No client ids in screen found"); @@ -440,10 +438,13 @@ impl Screen { let err_context = || "failed to move clients from closed tab".to_string(); if self.tabs.is_empty() { - log::error!( + Err::<(), _>(anyhow!( "No tabs left, cannot move clients: {:?} from closed tab", client_ids_and_mode_infos - ); + )) + .with_context(err_context) + .non_fatal(); + return Ok(()); } let first_tab_index = *self @@ -530,44 +531,48 @@ impl Screen { }; if let Some(new_tab) = self.tabs.values().find(|t| t.position == new_tab_pos) { - if let Some(current_tab) = self.get_active_tab(client_id) { - // If new active tab is same as the current one, do nothing. - if current_tab.position == new_tab_pos { - return Ok(()); - } + //if let Some(current_tab) = self.get_active_tab(client_id) { |