diff --git a/Cargo.lock b/Cargo.lock index aebdbf3b..cda13440 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -259,6 +259,7 @@ dependencies = [ "shlex", "sysinfo", "tempfile", + "thiserror 2.0.18", "time", "tiny-bip39", "tokio", diff --git a/crates/atuin-ai/src/commands.rs b/crates/atuin-ai/src/commands.rs index cdbc8f2d..c6790f55 100644 --- a/crates/atuin-ai/src/commands.rs +++ b/crates/atuin-ai/src/commands.rs @@ -1,13 +1,8 @@ -use std::{ - fs, - path::{Path, PathBuf}, -}; - +use atuin_client::logs::FromSettings; +use atuin_client::settings::Settings; +use atuin_common::logs::{FileConfig, LogConfig, StderrConfig}; use atuin_common::shell::Shell; use clap::{Args, Subcommand}; -use eyre::Result; -use tracing_appender::rolling::{RollingFileAppender, Rotation}; -use tracing_subscriber::{EnvFilter, Layer, fmt, layer::SubscriberExt, util::SubscriberInitExt}; pub mod init; pub(crate) mod inline; @@ -27,7 +22,7 @@ pub struct AiArgs { } #[derive(Subcommand, Debug)] -pub enum Commands { +pub enum Command { /// Initialize shell integration Init { /// Shell to generate integration for; defaults to "auto" @@ -50,109 +45,30 @@ pub enum Commands { }, } -pub async fn run( - command: Commands, - settings: &atuin_client::settings::Settings, -) -> eyre::Result<()> { +impl Command { + pub fn log_config(&self, settings: &Settings) -> LogConfig { + match self { + Self::Inline { args, .. } => LogConfig { + file: FileConfig::from_settings(&settings.logs, &settings.logs.ai), + stderr: args.verbose.then(StderrConfig::default), + }, + _ => LogConfig::stderr_only(), + } + } +} + +pub async fn run(command: Command, settings: &Settings) -> eyre::Result<()> { match command { - Commands::Init { shell } => init::run(shell).await, - Commands::Inline { + Command::Init { shell } => init::run(shell).await, + Command::Inline { command, hook, args, .. - } => { - if settings.logs.ai_enabled() { - init_logging(settings, args.verbose)?; - } - - inline::run(command, args.api_endpoint, args.api_token, settings, hook).await - } + } => inline::run(command, args.api_endpoint, args.api_token, settings, hook).await, } } pub(crate) fn detect_shell() -> Option { Some(Shell::current().to_string()) } - -/// Initializes logging for the AI commands. -fn init_logging(settings: &atuin_client::settings::Settings, verbose: bool) -> Result<()> { - // ATUIN_LOG env var overrides config file level settings - let env_log_set = std::env::var("ATUIN_LOG").is_ok(); - - // Base filter from env var (or empty if not set) - let base_filter = - EnvFilter::from_env("ATUIN_LOG").add_directive("sqlx_sqlite::regexp=off".parse()?); - - // Use config level unless ATUIN_LOG is set - let filter = if env_log_set { - base_filter - } else { - EnvFilter::default() - .add_directive(settings.logs.ai_level().as_directive().parse()?) - .add_directive("sqlx_sqlite::regexp=off".parse()?) - }; - - let log_dir = PathBuf::from(&settings.logs.dir); - let ai_log_filename = settings.logs.ai.file.clone(); - - // Clean up old log files - cleanup_old_logs(&log_dir, &ai_log_filename, settings.logs.ai_retention()); - - let console_layer = if verbose { - Some( - fmt::layer() - .with_writer(std::io::stderr) - .with_ansi(true) - .with_target(false) - .with_filter(filter.clone()), - ) - } else { - None - }; - - let file_appender = RollingFileAppender::new(Rotation::DAILY, &log_dir, &ai_log_filename); - - let base = tracing_subscriber::registry().with( - fmt::layer() - .with_writer(file_appender) - .with_ansi(false) - .with_filter(filter), - ); - - if let Some(console_layer) = console_layer { - base.with(console_layer).init(); - } else { - base.init(); - }; - - Ok(()) -} - -fn cleanup_old_logs(log_dir: &Path, prefix: &str, retention_days: u64) { - let cutoff = std::time::SystemTime::now() - - std::time::Duration::from_secs(retention_days * 24 * 60 * 60); - - let Ok(entries) = fs::read_dir(log_dir) else { - return; - }; - - for entry in entries.flatten() { - let path = entry.path(); - let Some(name) = path.file_name().and_then(|n| n.to_str()) else { - continue; - }; - - // Match files like "search.log.2024-02-23" or "daemon.log.2024-02-23" - if !name.starts_with(prefix) || name == prefix { - continue; - } - - if let Ok(metadata) = entry.metadata() - && let Ok(modified) = metadata.modified() - && modified < cutoff - { - let _ = fs::remove_file(&path); - } - } -} diff --git a/crates/atuin-client/Cargo.toml b/crates/atuin-client/Cargo.toml index 2ce4949d..3a58b1c0 100644 --- a/crates/atuin-client/Cargo.toml +++ b/crates/atuin-client/Cargo.toml @@ -21,9 +21,7 @@ daemon = [] check-update = [] [dependencies] -atuin-common = { path = "../atuin-common", version = "18.17.1" } derive_more = { workspace = true } - tracing = { workspace = true } base64 = { workspace = true } time = { workspace = true, features = ["macros", "formatting", "parsing"] } @@ -80,6 +78,11 @@ palette = { version = "0.7.5", features = ["serializing"] } strum_macros = "0.27" strum = { version = "0.27", features = ["strum_macros"] } +[dependencies.atuin-common] +path = "../atuin-common" +version = "18.17.1" +features = ["tracing"] + [dev-dependencies] tokio = { version = "1", features = ["full"] } pretty_assertions = { workspace = true } diff --git a/crates/atuin-client/src/lib.rs b/crates/atuin-client/src/lib.rs index e0430999..41b4ff2a 100644 --- a/crates/atuin-client/src/lib.rs +++ b/crates/atuin-client/src/lib.rs @@ -22,6 +22,7 @@ pub mod encryption; pub mod history; pub mod import; pub mod logout; +pub mod logs; pub mod meta; pub mod ordering; pub mod plugin; diff --git a/crates/atuin-client/src/logs.rs b/crates/atuin-client/src/logs.rs new file mode 100644 index 00000000..b7ed8640 --- /dev/null +++ b/crates/atuin-client/src/logs.rs @@ -0,0 +1,34 @@ +use crate::settings; +use atuin_common::logs::{FileConfig, LogConfig}; +use std::path::PathBuf; + +pub trait FromSettings: Sized { + type Output; + fn from_settings(settings: &settings::Logs, child: &settings::LogConfig) -> Self::Output; +} + +impl FromSettings for FileConfig { + type Output = Option; + + fn from_settings(settings: &settings::Logs, child: &settings::LogConfig) -> Option { + if !child.enabled.unwrap_or(settings.enabled) { + return None; + } + Some(Self { + path: PathBuf::from_iter([&settings.dir, &child.file]), + level: child.level.unwrap_or(settings.level), + retention_days: child.retention.unwrap_or(settings.retention), + }) + } +} + +impl FromSettings for LogConfig { + type Output = Self; + + fn from_settings(settings: &settings::Logs, child: &settings::LogConfig) -> Self { + Self { + file: FileConfig::from_settings(settings, child), + stderr: None, + } + } +} diff --git a/crates/atuin-client/src/settings.rs b/crates/atuin-client/src/settings.rs index 25a05c6f..c40813c5 100644 --- a/crates/atuin-client/src/settings.rs +++ b/crates/atuin-client/src/settings.rs @@ -1,6 +1,4 @@ -use std::{collections::HashMap, io::prelude::*, path::PathBuf, str::FromStr, sync::OnceLock}; -use tokio::sync::OnceCell; - +use atuin_common::logs::LogLevel; use atuin_common::record::HostId; use atuin_common::utils; use clap::ValueEnum; @@ -14,7 +12,9 @@ use regex::RegexSet; use semver::Version; use serde::{Deserialize, Serialize}; use serde_with::DeserializeFromStr; +use std::{collections::HashMap, io::prelude::*, path::PathBuf, str::FromStr, sync::OnceLock}; use time::{OffsetDateTime, UtcOffset, format_description::FormatItem, macros::format_description}; +use tokio::sync::OnceCell; pub const HISTORY_PAGE_SIZE: i64 = 100; static EXAMPLE_CONFIG: &str = include_str!("../config.toml"); @@ -573,31 +573,6 @@ pub struct Tmux { pub height: String, } -/// Log level for file logging. Maps to tracing's LevelFilter. -#[derive(Clone, Copy, Debug, Default, PartialEq, Eq, Deserialize, Serialize)] -#[serde(rename_all = "lowercase")] -pub enum LogLevel { - Trace, - Debug, - #[default] - Info, - Warn, - Error, -} - -impl LogLevel { - /// Convert to a tracing directive string for use with EnvFilter. - pub fn as_directive(&self) -> &'static str { - match self { - LogLevel::Trace => "trace", - LogLevel::Debug => "debug", - LogLevel::Info => "info", - LogLevel::Warn => "warn", - LogLevel::Error => "error", - } - } -} - /// Configuration for a specific log type (search or daemon). #[derive(Clone, Debug, Default, Deserialize, Serialize)] pub struct LogConfig { @@ -614,6 +589,15 @@ pub struct LogConfig { pub retention: Option, } +impl LogConfig { + pub fn new(file: impl Into) -> Self { + Self { + file: file.into(), + ..Default::default() + } + } +} + #[derive(Clone, Debug, Deserialize, Serialize)] pub struct Logs { /// Enable file logging globally. Defaults to true. @@ -632,7 +616,7 @@ pub struct Logs { #[serde(default = "Logs::default_retention")] pub retention: u64, - /// Search log settings + /// Search log settings; only used with `--interactive` #[serde(default)] pub search: LogConfig, @@ -763,18 +747,9 @@ impl Default for Logs { dir: "".to_string(), level: LogLevel::default(), retention: Self::default_retention(), - search: LogConfig { - file: "search.log".to_string(), - ..Default::default() - }, - daemon: LogConfig { - file: "daemon.log".to_string(), - ..Default::default() - }, - ai: LogConfig { - file: "ai.log".to_string(), - ..Default::default() - }, + search: LogConfig::new("search.log"), + daemon: LogConfig::new("daemon.log"), + ai: LogConfig::new("ai.log"), } } } @@ -787,78 +762,6 @@ impl Logs { fn default_retention() -> u64 { 4 } - - /// Returns whether search logging is enabled. - /// Uses search-specific setting if set, otherwise falls back to global. - pub fn search_enabled(&self) -> bool { - self.search.enabled.unwrap_or(self.enabled) - } - - /// Returns whether daemon logging is enabled. - /// Uses daemon-specific setting if set, otherwise falls back to global. - pub fn daemon_enabled(&self) -> bool { - self.daemon.enabled.unwrap_or(self.enabled) - } - - /// Returns whether AI logging is enabled. - /// Uses AI-specific setting if set, otherwise falls back to global. - pub fn ai_enabled(&self) -> bool { - self.ai.enabled.unwrap_or(self.enabled) - } - - /// Returns the log level for search logging. - /// Uses search-specific setting if set, otherwise falls back to global. - pub fn search_level(&self) -> LogLevel { - self.search.level.unwrap_or(self.level) - } - - /// Returns the log level for daemon logging. - /// Uses daemon-specific setting if set, otherwise falls back to global. - pub fn daemon_level(&self) -> LogLevel { - self.daemon.level.unwrap_or(self.level) - } - - /// Returns the log level for AI logging. - /// Uses AI-specific setting if set, otherwise falls back to global. - pub fn ai_level(&self) -> LogLevel { - self.ai.level.unwrap_or(self.level) - } - - /// Returns the retention days for search logging. - /// Uses search-specific setting if set, otherwise falls back to global. - pub fn search_retention(&self) -> u64 { - self.search.retention.unwrap_or(self.retention) - } - - /// Returns the retention days for daemon logging. - /// Uses daemon-specific setting if set, otherwise falls back to global. - pub fn daemon_retention(&self) -> u64 { - self.daemon.retention.unwrap_or(self.retention) - } - - /// Returns the retention days for AI logging. - /// Uses AI-specific setting if set, otherwise falls back to global. - pub fn ai_retention(&self) -> u64 { - self.ai.retention.unwrap_or(self.retention) - } - - /// Returns the full path for the search log file. - pub fn search_path(&self) -> PathBuf { - let path = PathBuf::from(&self.search.file); - PathBuf::from(&self.dir).join(path) - } - - /// Returns the full path for the daemon log file. - pub fn daemon_path(&self) -> PathBuf { - let path = PathBuf::from(&self.daemon.file); - PathBuf::from(&self.dir).join(path) - } - - /// Returns the full path for the AI log file. - pub fn ai_path(&self) -> PathBuf { - let path = PathBuf::from(&self.ai.file); - PathBuf::from(&self.dir).join(path) - } } impl Default for Search { diff --git a/crates/atuin-common/Cargo.toml b/crates/atuin-common/Cargo.toml index 113cd799..02181742 100644 --- a/crates/atuin-common/Cargo.toml +++ b/crates/atuin-common/Cargo.toml @@ -14,7 +14,7 @@ repository = { workspace = true } [features] # Enables the `test_utils` module. -test-utils = ["dep:tracing", "dep:tracing-subscriber"] +test-utils = ["tracing", "dep:tracing-subscriber"] [dependencies] derive_more = { workspace = true } diff --git a/crates/atuin-common/src/lib.rs b/crates/atuin-common/src/lib.rs index 607353d8..cde6302f 100644 --- a/crates/atuin-common/src/lib.rs +++ b/crates/atuin-common/src/lib.rs @@ -58,6 +58,7 @@ macro_rules! new_uuid { } pub mod api; +pub mod logs; pub mod record; pub mod shell; #[cfg(feature = "test-utils")] diff --git a/crates/atuin-common/src/logs.rs b/crates/atuin-common/src/logs.rs new file mode 100644 index 00000000..7422511f --- /dev/null +++ b/crates/atuin-common/src/logs.rs @@ -0,0 +1,83 @@ +use serde::{Deserialize, Serialize}; +use std::ffi::OsStr; +use std::path::{Path, PathBuf}; + +/// Log level for file logging. Maps to tracing's LevelFilter. +#[derive(Clone, Copy, Debug, Default, PartialEq, Eq, Deserialize, Serialize)] +#[serde(rename_all = "lowercase")] +pub enum LogLevel { + Trace, + Debug, + #[default] + Info, + Warn, + Error, +} + +impl LogLevel { + #[cfg(feature = "tracing")] + pub fn to_tracing(&self) -> tracing::Level { + use tracing::Level; + match self { + LogLevel::Trace => Level::TRACE, + LogLevel::Debug => Level::DEBUG, + LogLevel::Info => Level::INFO, + LogLevel::Warn => Level::WARN, + LogLevel::Error => Level::ERROR, + } + } +} + +#[derive(Debug)] +pub struct FileConfig { + pub path: PathBuf, + pub level: LogLevel, + pub retention_days: u64, +} + +impl FileConfig { + pub fn directory(&self) -> &Path { + self.path.parent().unwrap_or_else(|| Path::new("")) + } + + pub fn name(&self) -> &OsStr { + self.path.file_name().unwrap_or_else(|| OsStr::new("")) + } +} + +#[derive(Debug, Default)] +pub struct StderrConfig { + pub show_time: bool, + pub show_target: bool, +} + +impl StderrConfig { + pub fn verbose() -> Self { + Self { + show_time: true, + show_target: true, + } + } +} + +#[derive(Debug)] +pub struct LogConfig { + pub file: Option, + pub stderr: Option, +} + +impl LogConfig { + pub fn file_only(file: FileConfig) -> Self { + Self { + file: Some(file), + stderr: None, + } + } + + pub fn stderr_only() -> Self { + Self { + file: None, + stderr: Some(StderrConfig::default()), + } + } +} diff --git a/crates/atuin/Cargo.toml b/crates/atuin/Cargo.toml index aec120bb..4888a108 100644 --- a/crates/atuin/Cargo.toml +++ b/crates/atuin/Cargo.toml @@ -46,7 +46,7 @@ check-update = ["atuin-client/check-update"] [dependencies] atuin-ai = { path = "../atuin-ai", version = "18.17.1", optional = true, default-features = false } atuin-client = { path = "../atuin-client", version = "18.17.1", optional = true, default-features = false } -atuin-common = { workspace = true } +atuin-common = { workspace = true, features = ["tracing"] } atuin-dotfiles = { workspace = true } atuin-history = { workspace = true } atuin-daemon = { path = "../atuin-daemon", version = "18.17.1", optional = true, default-features = false } @@ -91,6 +91,7 @@ norm = { version = "0.1.1", features = ["fzf-v2"] } atuin-nucleo-matcher = { workspace = true } tempfile = { workspace = true } shlex = "1.3.0" +thiserror = { workspace = true } # settings editor with comment and relative ordering preservation toml_edit = { workspace = true } diff --git a/crates/atuin/src/command/client.rs b/crates/atuin/src/command/client.rs index 0048655d..369699a7 100644 --- a/crates/atuin/src/command/client.rs +++ b/crates/atuin/src/command/client.rs @@ -1,44 +1,13 @@ -use std::fs::{self, OpenOptions}; -use std::path::{Path, PathBuf}; +use std::path::PathBuf; use clap::Subcommand; use eyre::{Result, WrapErr}; +use atuin_client::logs::FromSettings; use atuin_client::{ database::Sqlite, record::sqlite_store::SqliteStore, settings::Settings, theme, }; -use tracing_appender::rolling::{RollingFileAppender, Rotation}; -use tracing_subscriber::{ - Layer, filter::EnvFilter, filter::LevelFilter, fmt, fmt::format::FmtSpan, prelude::*, -}; - -fn cleanup_old_logs(log_dir: &Path, prefix: &str, retention_days: u64) { - let cutoff = std::time::SystemTime::now() - - std::time::Duration::from_secs(retention_days * 24 * 60 * 60); - - let Ok(entries) = fs::read_dir(log_dir) else { - return; - }; - - for entry in entries.flatten() { - let path = entry.path(); - let Some(name) = path.file_name().and_then(|n| n.to_str()) else { - continue; - }; - - // Match files like "search.log.2024-02-23" or "daemon.log.2024-02-23" - if !name.starts_with(prefix) || name == prefix { - continue; - } - - if let Ok(metadata) = entry.metadata() - && let Ok(modified) = metadata.modified() - && modified < cutoff - { - let _ = fs::remove_file(&path); - } - } -} +use atuin_common::logs::{self, LogConfig}; #[cfg(feature = "sync")] mod sync; @@ -144,7 +113,7 @@ pub enum Cmd { /// Run the AI assistant #[cfg(feature = "ai")] #[command(subcommand)] - Ai(atuin_ai::commands::Commands), + Ai(atuin_ai::commands::Command), /// Start an MCP server exposing history search to AI tools (stdio) #[cfg(feature = "ai")] @@ -179,6 +148,7 @@ impl Cmd { // doing anything else. History commands are performance-sensitive and run before and after // every shell command, so we want to skip any unnecessary initialization for them. let settings = Settings::new().wrap_err("could not load client settings")?; + self.init_logging(&settings); let theme_manager = theme::ThemeManager::new(settings.theme.debug, None); let res = runtime.block_on(self.run_inner(settings, theme_manager)); @@ -193,152 +163,6 @@ impl Cmd { mut settings: Settings, mut theme_manager: theme::ThemeManager, ) -> Result<()> { - // ATUIN_LOG env var overrides config file level settings - let env_log_set = std::env::var("ATUIN_LOG").is_ok(); - - // Base filter from env var (or empty if not set) - let base_filter = - EnvFilter::from_env("ATUIN_LOG").add_directive("sqlx_sqlite::regexp=off".parse()?); - - let is_interactive_search = matches!(&self, Self::Search(cmd) if cmd.is_interactive()); - // Use file-based logging for interactive search (TUI mode) - let use_search_logging = is_interactive_search && settings.logs.search_enabled(); - - // Use file-based logging for daemon - #[cfg(feature = "daemon")] - let use_daemon_logging = matches!(&self, Self::Daemon(_)) && settings.logs.daemon_enabled(); - - #[cfg(not(feature = "daemon"))] - let use_daemon_logging = false; - - // Check if daemon should also log to console - #[cfg(feature = "daemon")] - let daemon_show_logs = matches!(&self, Self::Daemon(cmd) if cmd.show_logs()); - - #[cfg(not(feature = "daemon"))] - let daemon_show_logs = false; - - // Set up span timing JSON logs if ATUIN_SPAN is set - let span_path = std::env::var("ATUIN_SPAN").ok().map(|p| { - if p.is_empty() { - "atuin-spans.json".to_string() - } else { - p - } - }); - - // Helper to create span timing layer - macro_rules! make_span_layer { - ($path:expr) => {{ - let span_file = OpenOptions::new() - .create(true) - .truncate(true) - .write(true) - .open($path)?; - Some( - fmt::layer() - .json() - .with_writer(span_file) - .with_span_events(FmtSpan::NEW | FmtSpan::CLOSE) - .with_filter(LevelFilter::TRACE), - ) - }}; - } - - // Build the subscriber with all configured layers - if use_search_logging { - let search_filename = settings.logs.search.file.clone(); - let log_dir = PathBuf::from(&settings.logs.dir); - fs::create_dir_all(&log_dir)?; - - // Clean up old log files - cleanup_old_logs(&log_dir, &search_filename, settings.logs.search_retention()); - - let file_appender = - RollingFileAppender::new(Rotation::DAILY, &log_dir, &search_filename); - - // Use config level unless ATUIN_LOG is set - let filter = if env_log_set { - base_filter - } else { - EnvFilter::default() - .add_directive(settings.logs.search_level().as_directive().parse()?) - .add_directive("sqlx_sqlite::regexp=off".parse()?) - }; - - let base = tracing_subscriber::registry().with( - fmt::layer() - .with_writer(file_appender) - .with_ansi(false) - .with_filter(filter), - ); - - match &span_path { - Some(sp) => { - base.with(make_span_layer!(sp)).init(); - } - None => { - base.init(); - } - } - } else if use_daemon_logging { - let daemon_filename = settings.logs.daemon.file.clone(); - let log_dir = PathBuf::from(&settings.logs.dir); - fs::create_dir_all(&log_dir)?; - - // Clean up old log files - cleanup_old_logs(&log_dir, &daemon_filename, settings.logs.daemon_retention()); - - let file_appender = - RollingFileAppender::new(Rotation::DAILY, &log_dir, &daemon_filename); - - // Use config level unless ATUIN_LOG is set - let file_filter = if env_log_set { - base_filter - } else { - EnvFilter::default() - .add_directive(settings.logs.daemon_level().as_directive().parse()?) - .add_directive("sqlx_sqlite::regexp=off".parse()?) - }; - - let file_layer = fmt::layer() - .with_writer(file_appender) - .with_ansi(false) - .with_filter(file_filter); - - // Optionally add console layer for --show-logs - if daemon_show_logs { - let console_filter = EnvFilter::from_env("ATUIN_LOG") - .add_directive("sqlx_sqlite::regexp=off".parse()?); - - let console_layer = fmt::layer().with_filter(console_filter); - - let base = tracing_subscriber::registry() - .with(file_layer) - .with(console_layer); - - match &span_path { - Some(sp) => { - base.with(make_span_layer!(sp)).init(); - } - None => { - base.init(); - } - } - } else { - let base = tracing_subscriber::registry().with(file_layer); - - match &span_path { - Some(sp) => { - base.with(make_span_layer!(sp)).init(); - } - None => { - base.init(); - } - } - } - } - tracing::trace!(command = ?self, "client command"); // Skip initializing any databases for history @@ -408,4 +232,32 @@ impl Cmd { Self::Mcp => atuin_ai::mcp::run(&db).await, } } + + fn log_config(&self, settings: &Settings) -> Option { + match self { + Self::History(cmd) => cmd.log_config(), + + Self::Search(cmd) if cmd.is_interactive() => Some(LogConfig::from_settings( + &settings.logs, + &settings.logs.search, + )), + + #[cfg(feature = "daemon")] + Self::Daemon(cmd) => Some(LogConfig { + file: logs::FileConfig::from_settings(&settings.logs, &settings.logs.daemon), + stderr: cmd.show_logs().then(logs::StderrConfig::verbose), + }), + + #[cfg(feature = "ai")] + Self::Ai(cmd) => Some(cmd.log_config(settings)), + + _ => Some(LogConfig::stderr_only()), + } + } + + fn init_logging(&self, settings: &Settings) { + if let Some(config) = self.log_config(settings) { + crate::logs::init_logging(&config); + } + } } diff --git a/crates/atuin/src/command/client/history.rs b/crates/atuin/src/command/client/history.rs index 99ee19f1..ca55f172 100644 --- a/crates/atuin/src/command/client/history.rs +++ b/crates/atuin/src/command/client/history.rs @@ -5,6 +5,7 @@ use std::{ time::Duration, }; +use atuin_common::logs::LogConfig; use atuin_common::utils::{self, Escapable as _}; use clap::Subcommand; use eyre::{Context, Result, bail}; @@ -60,6 +61,11 @@ pub enum Cmd { intent: Option, command: Vec, + + /// Passed by shell hooks; this flag disables logging to avoid corrupting the terminal and + /// to minimize the amount of time the command takes to run. + #[arg(long, hide = true)] + hook: bool, }, /// Finishes a new command in the history (adds time, exit code) @@ -69,6 +75,11 @@ pub enum Cmd { exit: i64, #[arg(long, short)] duration: Option, + + /// Passed by shell hooks; this flag disables logging to avoid corrupting the terminal and + /// to minimize the amount of time the command takes to run. + #[arg(long, hide = true)] + hook: bool, }, /// Stream history events from the daemon as they are received @@ -1105,6 +1116,7 @@ impl Cmd { author, intent, command, + .. } => { let command = if cmd_env { std::env::var("ATUIN_COMMAND_LINE").unwrap_or_default() @@ -1121,9 +1133,9 @@ impl Cmd { Ok(()) } - Self::End { id, exit, duration } => { - end_history_entry(settings, &id, exit, duration).await - } + Self::End { + id, exit, duration, .. + } => end_history_entry(settings, &id, exit, duration).await, Self::Tail => { #[cfg(feature = "daemon")] { @@ -1220,6 +1232,18 @@ impl Cmd { } } } + + fn logs_enabled(&self) -> bool { + match self { + // Enable logs if not invoked from a shell hook. + Self::Start { hook, .. } | Self::End { hook, .. } => !*hook, + _ => true, + } + } + + pub fn log_config(&self) -> Option { + self.logs_enabled().then(LogConfig::stderr_only) + } } #[cfg(test)] diff --git a/crates/atuin/src/command/mod.rs b/crates/atuin/src/command/mod.rs index 6cd221a4..8ffbab93 100644 --- a/crates/atuin/src/command/mod.rs +++ b/crates/atuin/src/command/mod.rs @@ -1,3 +1,4 @@ +use atuin_common::logs::LogConfig; use clap::Subcommand; use eyre::Result; @@ -48,6 +49,13 @@ impl AtuinCmd { umask(mode); } + match self { + // Client commands initialize their own logging + #[cfg(feature = "client")] + Self::Client(_) => {} + _ => crate::logs::init_logging(&LogConfig::stderr_only()), + } + match self { #[cfg(feature = "client")] Self::Client(client) => client.run(), diff --git a/crates/atuin/src/logs.rs b/crates/atuin/src/logs.rs new file mode 100644 index 00000000..23d75f96 --- /dev/null +++ b/crates/atuin/src/logs.rs @@ -0,0 +1,166 @@ +use atuin_common::logs::{FileConfig, LogConfig, StderrConfig}; +use std::fs::OpenOptions; +use std::io::IsTerminal; +use tracing::Level; +use tracing_appender::rolling::{self, RollingFileAppender, Rotation}; +use tracing_subscriber::filter::{self, EnvFilter, LevelFilter}; +use tracing_subscriber::fmt; +use tracing_subscriber::fmt::format::FmtSpan; +use tracing_subscriber::prelude::*; + +pub fn init_logging(config: &LogConfig) { + // We have to dispatch the time config statically; see + // https://github.com/tokio-rs/tracing/issues/3180 + match &config.stderr { + Some(StderrConfig { + show_time: false, .. + }) => with_stderr_time::<()>(config), + _ => with_stderr_time::(config), + } +} + +fn get_base_filter(config: &LogConfig) -> EnvFilter { + let level = config + .file + .as_ref() + .map_or(Level::WARN, |f| f.level.to_tracing()); + EnvFilter::default().add_directive(level.into()) +} + +fn clean_up_old_logs(config: &FileConfig) { + let Some(cutoff) = config + .retention_days + .checked_mul(24 * 60 * 60) + .and_then(|s| std::time::SystemTime::now().checked_sub(std::time::Duration::from_secs(s))) + else { + return; + }; + + let Ok(entries) = std::fs::read_dir(config.directory()) else { + return; + }; + + let Some(prefix) = config.name().to_str() else { + return; + }; + + for entry in entries.flatten() { + let path = entry.path(); + let Some(name) = path.file_name().and_then(|n| n.to_str()) else { + continue; + }; + + // Match files like "search.log.2024-02-23" or "daemon.log.2024-02-23" + if !name.starts_with(prefix) || name == prefix { + continue; + } + + if let Ok(metadata) = entry.metadata() + && let Ok(modified) = metadata.modified() + && modified < cutoff + { + let _ = std::fs::remove_file(&path); + } + } +} + +#[derive(Debug, thiserror::Error)] +enum FileWriterError { + #[error("log file name must be utf-8")] + NonUtf8Filename, + #[error("{0}")] + RollingFileAppender(#[from] rolling::InitError), +} + +fn make_file_writer(config: &FileConfig) -> Result { + let prefix = config + .name() + .to_str() + .ok_or(FileWriterError::NonUtf8Filename)?; + let writer = RollingFileAppender::builder() + .rotation(Rotation::DAILY) + .filename_prefix(prefix) + .build(config.directory())?; + Ok(writer) +} + +fn with_stderr_time(config: &LogConfig) +where + StderrTime: fmt::time::FormatTime + Default + Send + Sync + 'static, +{ + // ATUIN_LOG env var overrides config file level settings + let filter: EnvFilter = std::env::var("ATUIN_LOG") + .map_or_else( + |_| get_base_filter(config), + |s| filter::Builder::default().parse_lossy(s), + ) + .add_directive("sqlx_sqlite::regexp=off".parse().unwrap()); + + if let Some(file) = &config.file { + clean_up_old_logs(file); + } + + let file_layer = config.file.as_ref().map(|file| { + let writer = make_file_writer(file)?; + let layer = fmt::layer() + .with_writer(writer) + .with_ansi(false) + .with_filter(filter.clone()); + Ok::<_, FileWriterError>(layer) + }); + + let stderr_layer = config.stderr.as_ref().map(|stderr| { + fmt::layer() + .with_writer(std::io::stderr) + .with_ansi(std::io::stderr().is_terminal()) + .with_target(stderr.show_target) + .map_event_format(|f| f.with_timer(StderrTime::default())) + .with_filter(filter) + }); + + let span_layer = std::env::var("ATUIN_SPAN").ok().and_then(|value| { + let path = if value.is_empty() { + "atuin-spans.json".to_owned() + } else { + value + }; + let file = OpenOptions::new() + .create(true) + .truncate(true) + .write(true) + .open(path) + .ok()?; + let layer = fmt::layer() + .json() + .with_writer(file) + .with_span_events(FmtSpan::NEW | FmtSpan::CLOSE) + .with_filter(LevelFilter::TRACE); + Some(layer) + }); + + let (file_layer, file_error) = match file_layer.transpose() { + Ok(layer) => (layer, None), + Err(e) => (None, Some(e)), + }; + let has_stderr_layer = stderr_layer.is_some(); + + if let Err(e) = tracing_subscriber::registry() + .with(file_layer) + .with(stderr_layer) + .with(span_layer) + .try_init() + { + if has_stderr_layer || cfg!(debug_assertions) { + eprintln!("failed to initialize logging: {e}"); + } + return; + } + + if let Some(e) = file_error { + if has_stderr_layer { + tracing::warn!("failed to initialize log file: {e}"); + } else if cfg!(debug_assertions) { + eprintln!("failed to initialize log file: {e}"); + } + } +} diff --git a/crates/atuin/src/main.rs b/crates/atuin/src/main.rs index 255db36a..41587abf 100644 --- a/crates/atuin/src/main.rs +++ b/crates/atuin/src/main.rs @@ -9,6 +9,7 @@ use eyre::Result; use command::AtuinCmd; mod command; +pub(crate) mod logs; #[cfg(feature = "sync")] mod print_error; diff --git a/crates/atuin/src/shell/atuin.bash b/crates/atuin/src/shell/atuin.bash index 8b540bd7..686439ec 100644 --- a/crates/atuin/src/shell/atuin.bash +++ b/crates/atuin/src/shell/atuin.bash @@ -86,7 +86,7 @@ __atuin_preexec() { __atuin_update_preexec_backend local id - id=$(atuin history start -- "$1" 2>/dev/null) + id=$(atuin history start --hook -- "$1" 2>/dev/null) export ATUIN_HISTORY_ID=$id [[ -n ${__atuin_skip_osc133:-} ]] || __atuin_osc133_command_executed __atuin_preexec_time=${EPOCHREALTIME-} @@ -141,7 +141,7 @@ __atuin_precmd() { fi [[ -n ${__atuin_skip_osc133:-} ]] || __atuin_osc133_command_finished "$EXIT" - (ATUIN_LOG=error atuin history end --exit "$EXIT" ${duration:+"--duration=$duration"} -- "$ATUIN_HISTORY_ID" &) >/dev/null 2>&1 + (atuin history end --hook --exit "$EXIT" ${duration:+"--duration=$duration"} -- "$ATUIN_HISTORY_ID" >/dev/null 2>&1 &) export ATUIN_HISTORY_ID="" } @@ -163,7 +163,7 @@ if ((BASH_VERSINFO[0] >= 5 || BASH_VERSINFO[0] == 4 && BASH_VERSINFO[1] >= 4)); __atuin_evaluate_prompt() { __atuin_set_ret_value "${__bp_last_ret_value-}" "${__bp_last_argument_prev_command-}" __atuin_prompt=${PS1@P} - + # Note: Strip the control characters ^A (\001) and ^B (\002), which # Bash internally uses to enclose the escape sequences. They are # produced by '\[' and '\]', respectively, in $PS1 and used to tell @@ -323,7 +323,7 @@ __atuin_search_cmd() { popup_width="${ATUIN_TMUX_POPUP_WIDTH:-80%}" # Keep default value anyways popup_height="${ATUIN_TMUX_POPUP_HEIGHT:-60%}" tmux display-popup -d "$cdir" -w "$popup_width" -h "$popup_height" -E -E -- \ - sh -c "PATH='$PATH' ATUIN_SESSION='$ATUIN_SESSION' ATUIN_SHELL=bash ATUIN_LOG=error ATUIN_QUERY='$escaped_query' atuin search $escaped_args -i 2>'$result_file'" + sh -c "PATH='$PATH' ATUIN_SESSION='$ATUIN_SESSION' ATUIN_SHELL=bash ATUIN_QUERY='$escaped_query' atuin search $escaped_args -i 2>'$result_file'" if [[ -f "$result_file" ]]; then cat "$result_file" @@ -332,7 +332,7 @@ __atuin_search_cmd() { __atuin_tmux_popup_cleanup trap - EXIT HUP INT TERM else - ATUIN_SHELL=bash ATUIN_LOG=error ATUIN_QUERY=$READLINE_LINE atuin search "${search_args[@]}" -i 3>&1 1>&2 2>&3 3>&- + ATUIN_SHELL=bash ATUIN_QUERY=$READLINE_LINE atuin search "${search_args[@]}" -i 3>&1 1>&2 2>&3 3>&- fi } diff --git a/crates/atuin/src/shell/atuin.fish b/crates/atuin/src/shell/atuin.fish index 15b33451..96746fe5 100644 --- a/crates/atuin/src/shell/atuin.fish +++ b/crates/atuin/src/shell/atuin.fish @@ -20,7 +20,7 @@ end function _atuin_preexec --on-event fish_preexec if not test -n "$fish_private_mode" - set -g ATUIN_HISTORY_ID (atuin history start -- "$argv[1]" 2>/dev/null) + set -g ATUIN_HISTORY_ID (atuin history start --hook -- "$argv[1]" 2>/dev/null) _atuin_osc133_command_executed end end @@ -30,7 +30,7 @@ function _atuin_postexec --on-event fish_postexec if test -n "$ATUIN_HISTORY_ID" _atuin_osc133_command_finished $s - ATUIN_LOG=error atuin history end --exit $s -- $ATUIN_HISTORY_ID &>/dev/null & + atuin history end --hook --exit $s -- $ATUIN_HISTORY_ID &>/dev/null & disown end @@ -102,7 +102,7 @@ function _atuin_search set -l tmpdir (mktemp -d) if not test -d "$tmpdir" # if mktemp got errors - set ATUIN_H (ATUIN_SHELL=fish ATUIN_LOG=error ATUIN_QUERY=(commandline -b) atuin search --keymap-mode=$keymap_mode $argv -i 3>&1 1>&2 2>&3 3>&- | string collect) + set ATUIN_H (ATUIN_SHELL=fish ATUIN_QUERY=(commandline -b) atuin search --keymap-mode=$keymap_mode $argv -i 3>&1 1>&2 2>&3 3>&- | string collect) set ATUIN_STATUS $pipestatus[1] else set -l result_file "$tmpdir/result" @@ -119,7 +119,7 @@ function _atuin_search set -l popup_width (test -n "$ATUIN_TMUX_POPUP_WIDTH" && echo "$ATUIN_TMUX_POPUP_WIDTH" || echo "80%") set -l popup_height (test -n "$ATUIN_TMUX_POPUP_HEIGHT" && echo "$ATUIN_TMUX_POPUP_HEIGHT" || echo "60%") tmux display-popup -d "$cdir" -w "$popup_width" -h "$popup_height" -E -E -- \ - sh -c "PATH='$PATH' ATUIN_SESSION='$ATUIN_SESSION' ATUIN_SHELL=fish ATUIN_LOG=error ATUIN_QUERY='$query' atuin search --keymap-mode=$keymap_mode$escaped_args -i 2>'$result_file'" + sh -c "PATH='$PATH' ATUIN_SESSION='$ATUIN_SESSION' ATUIN_SHELL=fish ATUIN_QUERY='$query' atuin search --keymap-mode=$keymap_mode$escaped_args -i 2>'$result_file'" set ATUIN_STATUS $status if test -f "$result_file" @@ -132,7 +132,7 @@ function _atuin_search # In fish 3.4 and above we can use `"$(some command)"` to keep multiple lines separate; # but to support fish 3.3 we need to use `(some command | string collect)`. # https://fishshell.com/docs/current/relnotes.html#id24 (fish 3.4 "Notable improvements and fixes") - set ATUIN_H (ATUIN_SHELL=fish ATUIN_LOG=error ATUIN_QUERY=(commandline -b) atuin search --keymap-mode=$keymap_mode $argv -i 3>&1 1>&2 2>&3 3>&- | string collect) + set ATUIN_H (ATUIN_SHELL=fish ATUIN_QUERY=(commandline -b) atuin search --keymap-mode=$keymap_mode $argv -i 3>&1 1>&2 2>&3 3>&- | string collect) set ATUIN_STATUS $pipestatus[1] end diff --git a/crates/atuin/src/shell/atuin.nu b/crates/atuin/src/shell/atuin.nu index c4de1967..fdb87550 100644 --- a/crates/atuin/src/shell/atuin.nu +++ b/crates/atuin/src/shell/atuin.nu @@ -48,7 +48,7 @@ let _atuin_pre_execution = {|| return } if not ($cmd | str starts-with $ATUIN_KEYBINDING_TOKEN) { - $env.ATUIN_HISTORY_ID = (atuin history start -- $cmd | complete | get stdout | str trim) + $env.ATUIN_HISTORY_ID = (atuin history start --hook -- $cmd | complete | get stdout | str trim) _atuin_osc133_command_executed } } @@ -59,15 +59,12 @@ let _atuin_pre_prompt = {|| return } _atuin_osc133_command_finished $last_exit - with-env { ATUIN_LOG: error } { - if (version).minor >= 104 or (version).major > 0 { - job spawn { - ^atuin history end $'--exit=($env.LAST_EXIT_CODE)' -- $env.ATUIN_HISTORY_ID | complete - } | ignore - } else { - do { atuin history end $'--exit=($last_exit)' -- $env.ATUIN_HISTORY_ID } | complete - } - + if (version).minor >= 104 or (version).major > 0 { + job spawn { + ^atuin history end --hook $'--exit=($env.LAST_EXIT_CODE)' -- $env.ATUIN_HISTORY_ID | complete + } | ignore + } else { + do { atuin history end --hook $'--exit=($last_exit)' -- $env.ATUIN_HISTORY_ID } | complete } hide-env -i ATUIN_HISTORY_ID } @@ -77,7 +74,7 @@ def _atuin_search_cmd [...flags: string] { [ $ATUIN_KEYBINDING_TOKEN, ([ - `with-env { ATUIN_LOG: error, ATUIN_QUERY: (commandline), ATUIN_SHELL: nu } {`, + `with-env { ATUIN_QUERY: (commandline), ATUIN_SHELL: nu } {`, ([ 'let output = (run-external atuin search', ($flags | append [--interactive] | each {|e| $'"($e)"'}), @@ -95,7 +92,7 @@ def _atuin_search_cmd [...flags: string] { [ $ATUIN_KEYBINDING_TOKEN, ([ - `with-env { ATUIN_LOG: error, ATUIN_QUERY: (commandline) } {`, + `with-env { ATUIN_QUERY: (commandline) } {`, 'commandline edit', '(run-external atuin search', ($flags | append [--interactive] | each {|e| $'"($e)"'}), diff --git a/crates/atuin/src/shell/atuin.ps1 b/crates/atuin/src/shell/atuin.ps1 index 431ee2c3..fa059977 100644 --- a/crates/atuin/src/shell/atuin.ps1 +++ b/crates/atuin/src/shell/atuin.ps1 @@ -77,7 +77,7 @@ New-Module -Name Atuin -ScriptBlock { # Fire and forget the atuin history end command to avoid blocking the shell during a potential sync. $process = New-Object System.Diagnostics.Process $process.StartInfo.FileName = "atuin" - $process.StartInfo.Arguments = "history end --exit=$exitCode $durationArg -- $script:atuinHistoryId" + $process.StartInfo.Arguments = "history end --hook --exit=$exitCode $durationArg -- $script:atuinHistoryId" $process.StartInfo.UseShellExecute = $false $process.StartInfo.CreateNoWindow = $true $process.StartInfo.RedirectStandardInput = $true @@ -117,7 +117,7 @@ New-Module -Name Atuin -ScriptBlock { # This makes it unreliable, so we go through an environment variable, which should always be consistent across versions. try { $env:ATUIN_COMMAND_LINE = $line - $script:atuinHistoryId = atuin history start --command-from-env + $script:atuinHistoryId = atuin history start --hook --command-from-env } catch { # Ignore errors to avoid breaking the shell, see above. diff --git a/crates/atuin/src/shell/atuin.xsh b/crates/atuin/src/shell/atuin.xsh index a0283402..501d02d5 100644 --- a/crates/atuin/src/shell/atuin.xsh +++ b/crates/atuin/src/shell/atuin.xsh @@ -14,7 +14,7 @@ if "ATUIN_SESSION" not in ${...} or ${...}.get("ATUIN_SHLVL", "") != ${...}.get( def _atuin_precommand(cmd: str): cmd = cmd.rstrip("\n") try: - $ATUIN_HISTORY_ID = $(atuin history start -- @(cmd) 2>@(os.devnull)).rstrip("\n") + $ATUIN_HISTORY_ID = $(atuin history start --hook -- @(cmd) 2>@(os.devnull)).rstrip("\n") except: $ATUIN_HISTORY_ID = "" @@ -27,12 +27,12 @@ def _atuin_postcommand(cmd: str, rtn: int, out, ts): duration = ts[1] - ts[0] # Duration is float representing seconds, but atuin expects integer of nanoseconds nanos = round(duration * 10 ** 9) - with ${...}.swap(ATUIN_LOG="error"): - # This causes the entire .xonshrc to be re-executed, which is incredibly slow - # This happens when using a subshell and using output redirection at the same time - # For more details, see https://github.com/xonsh/xonsh/issues/5224 - # (atuin history end --exit @(rtn) -- $ATUIN_HISTORY_ID &) > /dev/null 2>&1 - atuin history end --exit @(rtn) --duration @(nanos) -- $ATUIN_HISTORY_ID > @(os.devnull) 2>&1 + + # This causes the entire .xonshrc to be re-executed, which is incredibly slow + # This happens when using a subshell and using output redirection at the same time + # For more details, see https://github.com/xonsh/xonsh/issues/5224 + # (atuin history end --hook --exit @(rtn) -- $ATUIN_HISTORY_ID &) > /dev/null 2>&1 + atuin history end --hook --exit @(rtn) --duration @(nanos) -- $ATUIN_HISTORY_ID > @(os.devnull) 2>&1 del $ATUIN_HISTORY_ID diff --git a/crates/atuin/src/shell/atuin.zsh b/crates/atuin/src/shell/atuin.zsh index f8461006..26436139 100644 --- a/crates/atuin/src/shell/atuin.zsh +++ b/crates/atuin/src/shell/atuin.zsh @@ -70,7 +70,7 @@ __atuin_osc133_wrap_prompt() { _atuin_preexec() { local id - id=$(atuin history start -- "$1" 2>/dev/null) + id=$(atuin history start --hook -- "$1" 2>/dev/null) export ATUIN_HISTORY_ID="$id" __atuin_osc133_command_executed __atuin_preexec_time=${EPOCHREALTIME-} @@ -89,7 +89,7 @@ _atuin_precmd() { fi __atuin_osc133_command_finished "$EXIT" - (ATUIN_LOG=error atuin history end --exit $EXIT ${duration:+--duration=$duration} -- $ATUIN_HISTORY_ID &) >/dev/null 2>&1 + (atuin history end --hook --exit $EXIT ${duration:+--duration=$duration} -- $ATUIN_HISTORY_ID >/dev/null 2>&1 &) export ATUIN_HISTORY_ID="" } @@ -141,7 +141,7 @@ __atuin_search_cmd() { popup_width="${ATUIN_TMUX_POPUP_WIDTH:-80%}" # Keep default value anyways popup_height="${ATUIN_TMUX_POPUP_HEIGHT:-60%}" tmux display-popup -d "$cdir" -w "$popup_width" -h "$popup_height" -E -E -- \ - sh -c "PATH='$PATH' ATUIN_SESSION='$ATUIN_SESSION' ATUIN_SHELL=zsh ATUIN_LOG=error ATUIN_QUERY='$escaped_query' atuin search $escaped_args -i 2>'$result_file'" + sh -c "PATH='$PATH' ATUIN_SESSION='$ATUIN_SESSION' ATUIN_SHELL=zsh ATUIN_QUERY='$escaped_query' atuin search $escaped_args -i 2>'$result_file'" if [[ -f "$result_file" ]]; then cat "$result_file" @@ -150,7 +150,7 @@ __atuin_search_cmd() { __atuin_tmux_popup_cleanup trap - EXIT HUP INT TERM else - ATUIN_SHELL=zsh ATUIN_LOG=error ATUIN_QUERY=$BUFFER atuin search "${search_args[@]}" -i 3>&1 1>&2 2>&3 3>&- + ATUIN_SHELL=zsh ATUIN_QUERY=$BUFFER atuin search "${search_args[@]}" -i 3>&1 1>&2 2>&3 3>&- fi }