1 files changed, 589 insertions, 16 deletions
diff --git a/src/logging.rs b/src/logging.rs
index 899a9588..323910ca 100644
--- a/src/logging.rs
+++ b/src/logging.rs
@@ -1,20 +1,22 @@
-pub(crate) fn init_file_logging(file_name: &str) {
-    use std::fs::{self, OpenOptions};
-    use tracing_subscriber::EnvFilter;
+use std::fs::{self, File, OpenOptions};
+use std::io::{self, Write};
+use std::path::{Path, PathBuf};
+use std::sync::{Arc, Mutex};
 
-    let log_dir = crate::config::config_dir();
-    let _ = fs::create_dir_all(&log_dir);
-    let log_path = log_dir.join(file_name);
+use tracing_subscriber::fmt::writer::MakeWriter;
+use tracing_subscriber::EnvFilter;
 
-    if let Ok(meta) = fs::metadata(&log_path) {
-        if meta.len() > 5 * 1024 * 1024 {
-            let _ = fs::remove_file(&log_path);
-        }
-    }
+const DEFAULT_MAX_LOG_BYTES: u64 = 5 * 1024 * 1024;
+const DEFAULT_RETAINED_LOG_FILES: usize = 4;
 
-    let file = match OpenOptions::new().create(true).append(true).open(&log_path) {
-        Ok(file) => file,
-        Err(_) => return,
+pub(crate) fn init_file_logging(file_name: &str) {
+    let Ok(make_writer) = RotatingFileMakeWriter::new(
+        crate::config::config_dir(),
+        file_name,
+        DEFAULT_MAX_LOG_BYTES,
+        DEFAULT_RETAINED_LOG_FILES,
+    ) else {
+        return;
     };
 
     let filter =
@@ -22,8 +24,579 @@ pub(crate) fn init_file_logging(file_name: &str) {
 
     let _ = tracing_subscriber::fmt()
         .with_env_filter(filter)
-        .with_writer(file)
+        .with_writer(make_writer)
         .with_ansi(false)
-        .with_target(false)
+        .with_target(true)
         .try_init();
 }
+
+pub(crate) fn help_log_paths_summary() -> String {
+    let dir = crate::config::config_dir();
+    format!(
+        "{} (plus herdr-client.log, herdr-server.log)",
+        dir.join("herdr.log").display()
+    )
+}
+
+pub(crate) fn startup(role: &'static str) {
+    tracing::info!(
+        event = "app.startup",
+        subsystem = role,
+        outcome = "started",
+        pid = std::process::id(),
+        "herdr starting"
+    );
+}
+
+pub(crate) fn shutdown(role: &'static str) {
+    tracing::info!(
+        event = "app.shutdown",
+        subsystem = role,
+        outcome = "completed",
+        pid = std::process::id(),
+        "herdr exiting"
+    );
+}
+
+pub(crate) fn api_request_started(request_id: &str, method: &'static str, changes_ui: bool) {
+    tracing::info!(
+        event = "api.request.start",
+        subsystem = "api",
+        outcome = "started",
+        request_id,
+        method,
+        changes_ui,
+        "api request received"
+    );
+}
+
+pub(crate) fn api_request_completed(request_id: &str, method: &'static str, outcome: &'static str) {
+    tracing::info!(
+        event = "api.request.complete",
+        subsystem = "api",
+        outcome,
+        request_id,
+        method,
+        "api request completed"
+    );
+}
+
+pub(crate) fn api_request_failed(request_id: &str, method: &'static str, err: &str) {
+    tracing::warn!(
+        event = "api.request.fail",
+        subsystem = "api",
+        outcome = "error",
+        request_id,
+        method,
+        err,
+        "api request failed"
+    );
+}
+
+pub(crate) fn api_wait_started(request_id: &str, pane_id: &str, timeout_ms: Option<u64>) {
+    tracing::info!(
+        event = "api.wait.start",
+        subsystem = "api",
+        outcome = "started",
+        request_id,
+        pane_id,
+        timeout_ms,
+        "api output wait started"
+    );
+}
+
+pub(crate) fn api_wait_completed(request_id: &str, pane_id: &str, outcome: &'static str) {
+    tracing::info!(
+        event = "api.wait.complete",
+        subsystem = "api",
+        outcome,
+        request_id,
+        pane_id,
+        "api output wait finished"
+    );
+}
+
+pub(crate) fn api_wait_timed_out(request_id: &str, pane_id: &str) {
+    tracing::warn!(
+        event = "api.wait.timeout",
+        subsystem = "api",
+        outcome = "timeout",
+        request_id,
+        pane_id,
+        "api output wait timed out"
+    );
+}
+
+pub(crate) fn pane_spawn_started(
+    pane_id: u32,
+    rows: u16,
+    cols: u16,
+    scrollback_limit_bytes: usize,
+) {
+    tracing::info!(
+        event = "pane.spawn.start",
+        subsystem = "pane",
+        outcome = "started",
+        pane_id,
+        rows,
+        cols,
+        scrollback_limit_bytes,
+        "spawning pane terminal"
+    );
+}
+
+pub(crate) fn pane_spawned(pane_id: u32, pid: u32) {
+    tracing::info!(
+        event = "pane.spawned",
+        subsystem = "pane",
+        outcome = "ok",
+        pane_id,
+        pid,
+        "pane child spawned"
+    );
+}
+
+pub(crate) fn pane_exited(pane_id: u32, status: &str) {
+    tracing::info!(
+        event = "pane.exit",
+        subsystem = "pane",
+        outcome = "completed",
+        pane_id,
+        status,
+        "pane child exited"
+    );
+}
+
+pub(crate) fn pane_exit_failed(pane_id: u32, err: &str) {
+    tracing::error!(
+        event = "pane.exit",
+        subsystem = "pane",
+        outcome = "error",
+        pane_id,
+        err,
+        "pane child wait failed"
+    );
+}
+
+pub(crate) fn workspace_created(workspace_id: &str, root_pane_id: u32) {
+    tracing::info!(
+        event = "workspace.create",
+        subsystem = "workspace",
+        outcome = "ok",
+        workspace_id,
+        pane_id = root_pane_id,
+        "workspace created"
+    );
+}
+
+pub(crate) fn workspace_focused(workspace_id: &str) {
+    tracing::info!(
+        event = "workspace.focus",
+        subsystem = "workspace",
+        outcome = "ok",
+        workspace_id,
+        "workspace focused"
+    );
+}
+
+pub(crate) fn workspace_closed(workspace_id: &str) {
+    tracing::info!(
+        event = "workspace.close",
+        subsystem = "workspace",
+        outcome = "ok",
+        workspace_id,
+        "workspace closed"
+    );
+}
+
+pub(crate) fn workspace_renamed(workspace_id: &str) {
+    tracing::info!(
+        event = "workspace.rename",
+        subsystem = "workspace",
+        outcome = "ok",
+        workspace_id,
+        "workspace renamed"
+    );
+}
+
+pub(crate) fn tab_created(workspace_id: &str, tab_id: &str, root_pane_id: u32) {
+    tracing::info!(
+        event = "tab.create",
+        subsystem = "tab",
+        outcome = "ok",
+        workspace_id,
+        tab_id,
+        pane_id = root_pane_id,
+        "tab created"
+    );
+}
+
+pub(crate) fn tab_focused(workspace_id: &str, tab_id: &str) {
+    tracing::info!(
+        event = "tab.focus",
+        subsystem = "tab",
+        outcome = "ok",
+        workspace_id,
+        tab_id,
+        "tab focused"
+    );
+}
+
+pub(crate) fn tab_closed(workspace_id: &str, tab_id: &str) {
+    tracing::info!(
+        event = "tab.close",
+        subsystem = "tab",
+        outcome = "ok",
+        workspace_id,
+        tab_id,
+        "tab closed"
+    );
+}
+
+pub(crate) fn tab_renamed(workspace_id: &str, tab_id: &str) {
+    tracing::info!(
+        event = "tab.rename",
+        subsystem = "tab",
+        outcome = "ok",
+        workspace_id,
+        tab_id,
+        "tab renamed"
+    );
+}
+
+pub(crate) fn session_saved(path: &Path, workspaces: usize) {
+    tracing::info!(
+        event = "persist.save",
+        subsystem = "persist",
+        outcome = "ok",
+        path = %path.display(),
+        workspaces,
+        "session saved"
+    );
+}
+
+pub(crate) fn session_save_failed(path: &Path, err: &str) {
+    tracing::error!(
+        event = "persist.save",
+        subsystem = "persist",
+        outcome = "error",
+        path = %path.display(),
+        err,
+        "failed to save session"
+    );
+}
+
+pub(crate) fn session_cleared(path: &Path) {
+    tracing::info!(
+        event = "persist.clear",
+        subsystem = "persist",
+        outcome = "ok",
+        path = %path.display(),
+        "session cleared"
+    );
+}
+
+pub(crate) fn session_clear_failed(path: &Path, err: &str) {
+    tracing::error!(
+        event = "persist.clear",
+        subsystem = "persist",
+        outcome = "error",
+        path = %path.display(),
+        err,
+        "failed to clear session"
+    );
+}
+
+pub(crate) fn session_restored(workspaces: usize, outcome: &'static str) {
+    tracing::info!(
+        event = "persist.restore",
+        subsystem = "persist",
+        outcome,
+        workspaces,
+        "session restore evaluated"
+    );
+}
+
+pub(crate) fn update_check_started() {
+    tracing::info!(
+        event = "update.check.start",
+        subsystem = "update",
+        outcome = "started",
+        "checking for updates"
+    );
+}
+
+pub(crate) fn update_check_failed(err: &str) {
+    tracing::warn!(
+        event = "update.check.complete",
+        subsystem = "update",
+        outcome = "error",
+        err,
+        "update check failed"
+    );
+}
+
+pub(crate) fn update_available(version: &str) {
+    tracing::info!(
+        event = "update.available",
+        subsystem = "update",
+        outcome = "ok",
+        version,
+        "update available"
+    );
+}
+
+pub(crate) fn config_write_failed(path: &Path, context: &str, err: &str) {
+    tracing::warn!(
+        event = "config.write",
+        subsystem = "config",
+        outcome = "error",
+        path = %path.display(),
+        context,
+        err,
+        "failed to write config"
+    );
+}
+
+pub(crate) fn integration_action(
+    action: &'static str,
+    target: &'static str,
+    outcome: &'static str,
+) {
+    tracing::info!(
+        event = "integration.action",
+        subsystem = "integration",
+        outcome,
+        action,
+        target,
+        "integration action finished"
+    );
+}
+
+struct RotatingFileMakeWriter {
+    state: Arc<Mutex<RotatingFileState>>,
+}
+
+impl RotatingFileMakeWriter {
+    fn new(
+        dir: PathBuf,
+        file_name: &str,
+        max_bytes: u64,
+        retained_files: usize,
+    ) -> io::Result<Self> {
+        fs::create_dir_all(&dir)?;
+        let path = dir.join(file_name);
+        let mut state = RotatingFileState {
+            path,
+            max_bytes,
+            retained_files,
+            file: None,
+            current_size: 0,
+            disabled: false,
+        };
+        state.open_current_file()?;
+        Ok(Self {
+            state: Arc::new(Mutex::new(state)),
+        })
+    }
+}
+
+impl<'a> MakeWriter<'a> for RotatingFileMakeWriter {
+    type Writer = RotatingFileGuard;
+
+    fn make_writer(&'a self) -> Self::Writer {
+        RotatingFileGuard {
+            state: Arc::clone(&self.state),
+        }
+    }
+}
+
+struct RotatingFileGuard {
+    state: Arc<Mutex<RotatingFileState>>,
+}
+
+impl Write for RotatingFileGuard {
+    fn write(&mut self, buf: &[u8]) -> io::Result<usize> {
+        let Ok(mut state) = self.state.lock() else {
+            return Ok(buf.len());
+        };
+        if state.disabled {
+            return Ok(buf.len());
+        }
+        if state.rotate_if_needed(buf.len() as u64).is_err() {
+            state.disabled = true;
+            return Ok(buf.len());
+        }
+        if let Some(file) = state.file.as_mut() {
+            match file.write(buf) {
+                Ok(written) => {
+                    state.current_size = state.current_size.saturating_add(written as u64);
+                    Ok(written)
+                }
+                Err(_) => {
+                    state.disabled = true;
+                    Ok(buf.len())
+                }
+            }
+        } else {
+            Ok(buf.len())
+        }
+    }
+
+    fn flush(&mut self) -> io::Result<()> {
+        let Ok(mut state) = self.state.lock() else {
+            return Ok(());
+        };
+        if state.disabled {
+            return Ok(());
+        }
+        match state.file.as_mut() {
+            Some(file) => match file.flush() {
+                Ok(()) => Ok(()),
+                Err(_) => {
+                    state.disabled = true;
+                    Ok(())
+                }
+            },
+            None => Ok(()),
+        }
+    }
+}
+
+struct RotatingFileState {
+    path: PathBuf,
+    max_bytes: u64,
+    retained_files: usize,
+    file: Option<File>,
+    current_size: u64,
+    disabled: bool,
+}
+
+impl RotatingFileState {
+    fn rotate_if_needed(&mut self, incoming_len: u64) -> io::Result<()> {
+        if self.file.is_none() {
+            self.open_current_file()?;
+        }
+        if self.max_bytes == 0 || self.current_size.saturating_add(incoming_len) <= self.max_bytes {
+            return Ok(());
+        }
+        self.rotate_files()?;
+        self.open_current_file()
+    }
+
+    fn open_current_file(&mut self) -> io::Result<()> {
+        let file = OpenOptions::new()
+            .create(true)
+            .append(true)
+            .open(&self.path)?;
+        self.current_size = file.metadata().map(|meta| meta.len()).unwrap_or(0);
+        self.file = Some(file);
+        Ok(())
+    }
+
+    fn rotate_files(&mut self) -> io::Result<()> {
+        self.file.take();
+        if self.retained_files == 0 {
+            match fs::remove_file(&self.path) {
+                Ok(()) => {}
+                Err(err) if err.kind() == io::ErrorKind::NotFound => {}
+                Err(err) => return Err(err),
+            }
+            self.current_size = 0;
+            return Ok(());
+        }
+
+        let oldest = rotated_log_path(&self.path, self.retained_files);
+        match fs::remove_file(&oldest) {
+            Ok(()) => {}
+            Err(err) if err.kind() == io::ErrorKind::NotFound => {}
+            Err(err) => return Err(err),
+        }
+
+        for index in (1..=self.retained_files).rev() {
+            let source = if index == 1 {
+                self.path.clone()
+            } else {
+                rotated_log_path(&self.path, index - 1)
+            };
+            let target = rotated_log_path(&self.path, index);
+            if !source.exists() {
+                continue;
+            }
+            fs::rename(source, target)?;
+        }
+
+        self.current_size = 0;
+        Ok(())
+    }
+}
+
+fn rotated_log_path(path: &Path, index: usize) -> PathBuf {
+    let suffix = format!(".{}", index);
+    let file_name = path
+        .file_name()
+        .map(|name| {
+            let mut name = name.to_os_string();
+            name.push(&suffix);
+            name
+        })
+        .unwrap_or_else(|| suffix.clone().into());
+    path.with_file_name(file_name)
+}
+
+#[cfg(test)]
+mod tests {
+    use super::*;
+
+    fn temp_log_path(name: &str) -> PathBuf {
+        let unique = format!(
+            "herdr-logging-tests-{}-{}-{}",
+            name,
+            std::process::id(),
+            std::time::SystemTime::now()
+                .duration_since(std::time::UNIX_EPOCH)
+                .unwrap()
+                .as_nanos()
+        );
+        std::env::temp_dir().join(unique).join("herdr.log")
+    }
+
+    #[test]
+    fn rotated_log_path_appends_numeric_suffix() {
+        let path = PathBuf::from("/tmp/herdr.log");
+        assert_eq!(
+            rotated_log_path(&path, 2),
+            PathBuf::from("/tmp/herdr.log.2")
+        );
+    }
+
+    #[test]
+    fn rotate_files_shifts_existing_generations() {
+        let path = temp_log_path("rotate");
+        fs::create_dir_all(path.parent().unwrap()).unwrap();
+        fs::write(&path, "current").unwrap();
+        fs::write(rotated_log_path(&path, 1), "older").unwrap();
+
+        let mut state = RotatingFileState {
+            path: path.clone(),
+            max_bytes: 128,
+            retained_files: 2,
+            file: None,
+            current_size: 0,
+            disabled: false,
+        };
+        state.rotate_files().unwrap();
+
+        assert_eq!(
+            fs::read_to_string(rotated_log_path(&path, 1)).unwrap(),
+            "current"
+        );
+        assert_eq!(
+            fs::read_to_string(rotated_log_path(&path, 2)).unwrap(),
+            "older"
+        );
+        assert!(!path.exists());
+
+        let _ = fs::remove_dir_all(path.parent().unwrap());
+    }
+}