diff --git a/src/cli/commands/doctor.rs b/src/cli/commands/doctor.rs index 1d84667..40f0697 100644 --- a/src/cli/commands/doctor.rs +++ b/src/cli/commands/doctor.rs @@ -6,7 +6,7 @@ use serde::Serialize; use crate::core::config::Config; use crate::core::db::{create_connection, get_schema_version, verify_pragmas}; use crate::core::error::LoreError; -use crate::core::paths::{get_config_path, get_db_path}; +use crate::core::paths::{get_config_path, get_db_path, get_log_dir}; use crate::gitlab::GitLabClient; #[derive(Debug, Clone, Serialize)] @@ -37,6 +37,7 @@ pub struct DoctorChecks { pub gitlab: GitLabCheck, pub projects: ProjectsCheck, pub ollama: OllamaCheck, + pub logging: LoggingCheck, } #[derive(Debug, Serialize)] @@ -87,6 +88,18 @@ pub struct OllamaCheck { pub model: Option, } +#[derive(Debug, Serialize)] +pub struct LoggingCheck { + #[serde(flatten)] + pub result: CheckResult, + #[serde(skip_serializing_if = "Option::is_none")] + pub log_dir: Option, + #[serde(skip_serializing_if = "Option::is_none")] + pub file_count: Option, + #[serde(skip_serializing_if = "Option::is_none")] + pub total_bytes: Option, +} + /// Run the doctor command. pub async fn run_doctor(config_path: Option<&str>) -> DoctorResult { let config_path_buf = get_config_path(config_path); @@ -107,7 +120,10 @@ pub async fn run_doctor(config_path: Option<&str>) -> DoctorResult { // Check Ollama let ollama_check = check_ollama(config.as_ref()).await; - // Success if all required checks pass (ollama is optional) + // Check logging + let logging_check = check_logging(config.as_ref()); + + // Success if all required checks pass (ollama and logging are optional) let success = config_check.result.status == CheckStatus::Ok && database_check.result.status == CheckStatus::Ok && gitlab_check.result.status == CheckStatus::Ok @@ -121,6 +137,7 @@ pub async fn run_doctor(config_path: Option<&str>) -> DoctorResult { gitlab: gitlab_check, projects: projects_check, ollama: ollama_check, + logging: logging_check, }, } } @@ -457,6 +474,59 @@ async fn check_ollama(config: Option<&Config>) -> OllamaCheck { } } +fn check_logging(config: Option<&Config>) -> LoggingCheck { + let log_dir = get_log_dir(config.and_then(|c| c.logging.log_dir.as_deref())); + let log_dir_str = log_dir.display().to_string(); + + if !log_dir.exists() { + return LoggingCheck { + result: CheckResult { + status: CheckStatus::Ok, + message: Some(format!("{log_dir_str} (no log files yet)")), + }, + log_dir: Some(log_dir_str), + file_count: Some(0), + total_bytes: Some(0), + }; + } + + let mut file_count = 0usize; + let mut total_bytes = 0u64; + + if let Ok(entries) = std::fs::read_dir(&log_dir) { + for entry in entries.flatten() { + let name = entry.file_name(); + let name_str = name.to_string_lossy(); + if name_str.starts_with("lore.") { + file_count += 1; + if let Ok(meta) = entry.metadata() { + total_bytes += meta.len(); + } + } + } + } + + let size_display = if total_bytes < 1024 { + format!("{total_bytes} B") + } else if total_bytes < 1024 * 1024 { + format!("{:.1} KB", total_bytes as f64 / 1024.0) + } else { + format!("{:.1} MB", total_bytes as f64 / (1024.0 * 1024.0)) + }; + + LoggingCheck { + result: CheckResult { + status: CheckStatus::Ok, + message: Some(format!( + "{log_dir_str} ({file_count} files, {size_display})" + )), + }, + log_dir: Some(log_dir_str), + file_count: Some(file_count), + total_bytes: Some(total_bytes), + } +} + /// Format and print doctor results to console. pub fn print_doctor_results(result: &DoctorResult) { println!("\nlore doctor\n"); @@ -466,6 +536,7 @@ pub fn print_doctor_results(result: &DoctorResult) { print_check("GitLab", &result.checks.gitlab.result); print_check("Projects", &result.checks.projects.result); print_check("Ollama", &result.checks.ollama.result); + print_check("Logging", &result.checks.logging.result); println!(); diff --git a/src/cli/mod.rs b/src/cli/mod.rs index fb9cfae..8692577 100644 --- a/src/cli/mod.rs +++ b/src/cli/mod.rs @@ -31,6 +31,14 @@ pub struct Cli { #[arg(short = 'q', long, global = true)] pub quiet: bool, + /// Increase log verbosity (-v, -vv, -vvv) + #[arg(short = 'v', long = "verbose", action = clap::ArgAction::Count, global = true)] + pub verbose: u8, + + /// Log format for stderr output: text (default) or json + #[arg(long = "log-format", global = true, value_parser = ["text", "json"], default_value = "text")] + pub log_format: String, + #[command(subcommand)] pub command: Commands, } diff --git a/src/main.rs b/src/main.rs index d957ce7..b065f81 100644 --- a/src/main.rs +++ b/src/main.rs @@ -4,7 +4,7 @@ use clap::Parser; use console::style; use dialoguer::{Confirm, Input}; use serde::Serialize; -use tracing_subscriber::EnvFilter; +use tracing_subscriber::Layer; use tracing_subscriber::layer::SubscriberExt; use tracing_subscriber::util::SubscriberInitExt; @@ -30,8 +30,10 @@ use lore::core::db::{ LATEST_SCHEMA_VERSION, create_connection, get_schema_version, run_migrations, }; use lore::core::error::{LoreError, RobotErrorOutput}; -use lore::core::paths::get_config_path; -use lore::core::paths::get_db_path; +use lore::core::logging; +use lore::core::metrics::MetricsLayer; +use lore::core::paths::{get_config_path, get_db_path, get_log_dir}; +use lore::core::sync_run::SyncRunRecorder; #[tokio::main] async fn main() { @@ -41,25 +43,94 @@ async fn main() { libc::signal(libc::SIGPIPE, libc::SIG_DFL); } - // Initialize logging with progress-bar-aware writer. - // SuspendingWriter suspends the shared MultiProgress before each log line, - // preventing log output from interleaving with progress bar animations. - tracing_subscriber::registry() - .with( - tracing_subscriber::fmt::layer() - .with_target(false) - .with_writer(lore::cli::progress::SuspendingWriter), - ) - .with( - EnvFilter::from_default_env() - .add_directive("lore=info".parse().unwrap()) - .add_directive("warn".parse().unwrap()), - ) - .init(); - + // Parse CLI first so we know verbosity settings before initializing the subscriber. let cli = Cli::parse(); let robot_mode = cli.is_robot_mode(); + // Try to load logging config for file layer settings. + // If config isn't available yet (e.g. during `lore init`), use defaults. + let logging_config = lore::Config::load(cli.config.as_deref()) + .map(|c| c.logging) + .unwrap_or_default(); + + // Clean up old log files before initializing subscriber (so deleted handles aren't held open) + let log_dir = get_log_dir(logging_config.log_dir.as_deref()); + if logging_config.file_logging && logging_config.retention_days > 0 { + logging::cleanup_old_logs(&log_dir, logging_config.retention_days); + } + + // Build triple-layer subscriber: + // - stderr layer: human-readable or JSON, controlled by -v flags + // - file layer: always-on JSON to daily-rotated log files + // - metrics layer: captures span timing for robot-mode performance data + let stderr_filter = logging::build_stderr_filter(cli.verbose, cli.quiet); + let metrics_layer = MetricsLayer::new(); + + let registry = tracing_subscriber::registry(); + + // Hold the file writer guard at function scope so it flushes on exit. + // WorkerGuard::drop() flushes pending log entries — forgetting it loses them. + let _file_guard: Option; + + // stderr layer: format depends on --log-format flag + if cli.log_format == "json" { + let stderr_layer = tracing_subscriber::fmt::layer() + .json() + .with_writer(lore::cli::progress::SuspendingWriter) + .with_filter(stderr_filter); + + if logging_config.file_logging { + let file_filter = logging::build_file_filter(); + std::fs::create_dir_all(&log_dir).ok(); + let file_appender = tracing_appender::rolling::daily(&log_dir, "lore"); + let (non_blocking, guard) = tracing_appender::non_blocking(file_appender); + _file_guard = Some(guard); + let file_layer = tracing_subscriber::fmt::layer() + .json() + .with_writer(non_blocking) + .with_filter(file_filter); + registry + .with(stderr_layer) + .with(file_layer) + .with(metrics_layer.clone()) + .init(); + } else { + _file_guard = None; + registry + .with(stderr_layer) + .with(metrics_layer.clone()) + .init(); + } + } else { + let stderr_layer = tracing_subscriber::fmt::layer() + .with_target(false) + .with_writer(lore::cli::progress::SuspendingWriter) + .with_filter(stderr_filter); + + if logging_config.file_logging { + let file_filter = logging::build_file_filter(); + std::fs::create_dir_all(&log_dir).ok(); + let file_appender = tracing_appender::rolling::daily(&log_dir, "lore"); + let (non_blocking, guard) = tracing_appender::non_blocking(file_appender); + _file_guard = Some(guard); + let file_layer = tracing_subscriber::fmt::layer() + .json() + .with_writer(non_blocking) + .with_filter(file_filter); + registry + .with(stderr_layer) + .with(file_layer) + .with(metrics_layer.clone()) + .init(); + } else { + _file_guard = None; + registry + .with(stderr_layer) + .with(metrics_layer.clone()) + .init(); + } + } + // Apply color settings (console crate handles NO_COLOR/CLICOLOR natively in "auto" mode) match cli.color.as_str() { "never" => console::set_colors_enabled(false), @@ -76,9 +147,18 @@ async fn main() { Commands::Search(args) => handle_search(cli.config.as_deref(), args, robot_mode).await, Commands::Stats(args) => handle_stats(cli.config.as_deref(), args, robot_mode).await, Commands::Embed(args) => handle_embed(cli.config.as_deref(), args, robot_mode).await, - Commands::Sync(args) => handle_sync_cmd(cli.config.as_deref(), args, robot_mode).await, + Commands::Sync(args) => { + handle_sync_cmd(cli.config.as_deref(), args, robot_mode, &metrics_layer).await + } Commands::Ingest(args) => { - handle_ingest(cli.config.as_deref(), args, robot_mode, quiet).await + handle_ingest( + cli.config.as_deref(), + args, + robot_mode, + quiet, + &metrics_layer, + ) + .await } Commands::Count(args) => handle_count(cli.config.as_deref(), args, robot_mode).await, Commands::Status => handle_sync_status_cmd(cli.config.as_deref(), robot_mode).await, @@ -389,6 +469,7 @@ async fn handle_ingest( args: IngestArgs, robot_mode: bool, quiet: bool, + metrics: &MetricsLayer, ) -> Result<(), Box> { let config = Config::load(config_override)?; let display = if robot_mode || quiet { @@ -400,65 +481,91 @@ async fn handle_ingest( let force = args.force && !args.no_force; let full = args.full && !args.no_full; - match args.entity.as_deref() { - Some(resource_type) => { - // Single entity ingest - let result = run_ingest( - &config, - resource_type, - args.project.as_deref(), - force, - full, - display, - ) - .await?; + // Record ingest run lifecycle in sync_runs table + let entity_label = args.entity.as_deref().unwrap_or("all"); + let command = format!("ingest:{entity_label}"); + let db_path = get_db_path(config.storage.db_path.as_deref()); + let recorder_conn = create_connection(&db_path)?; + let run_id = uuid::Uuid::new_v4().simple().to_string(); + let run_id_short = &run_id[..8]; + let recorder = SyncRunRecorder::start(&recorder_conn, &command, run_id_short)?; - if robot_mode { - print_ingest_summary_json(&result); - } else { - print_ingest_summary(&result); + let ingest_result: std::result::Result<(), Box> = async { + match args.entity.as_deref() { + Some(resource_type) => { + // Single entity ingest + let result = run_ingest( + &config, + resource_type, + args.project.as_deref(), + force, + full, + display, + ) + .await?; + + if robot_mode { + print_ingest_summary_json(&result); + } else { + print_ingest_summary(&result); + } + } + None => { + // Ingest everything: issues then MRs + if !robot_mode && !quiet { + println!( + "{}", + style("Ingesting all content (issues + merge requests)...").blue() + ); + println!(); + } + + let issues_result = run_ingest( + &config, + "issues", + args.project.as_deref(), + force, + full, + display, + ) + .await?; + + let mrs_result = run_ingest( + &config, + "mrs", + args.project.as_deref(), + force, + full, + display, + ) + .await?; + + if robot_mode { + print_combined_ingest_json(&issues_result, &mrs_result); + } else { + print_ingest_summary(&issues_result); + print_ingest_summary(&mrs_result); + } } } - None => { - // Ingest everything: issues then MRs - if !robot_mode && !quiet { - println!( - "{}", - style("Ingesting all content (issues + merge requests)...").blue() - ); - println!(); - } + Ok(()) + } + .await; - let issues_result = run_ingest( - &config, - "issues", - args.project.as_deref(), - force, - full, - display, - ) - .await?; - - let mrs_result = run_ingest( - &config, - "mrs", - args.project.as_deref(), - force, - full, - display, - ) - .await?; - - if robot_mode { - print_combined_ingest_json(&issues_result, &mrs_result); - } else { - print_ingest_summary(&issues_result); - print_ingest_summary(&mrs_result); - } + match ingest_result { + Ok(()) => { + let stages = metrics.extract_timings(); + let total_items: usize = stages.iter().map(|s| s.items_processed).sum(); + let total_errors: usize = stages.iter().map(|s| s.errors).sum(); + let _ = recorder.succeed(&recorder_conn, &stages, total_items, total_errors); + Ok(()) + } + Err(e) => { + let stages = metrics.extract_timings(); + let _ = recorder.fail(&recorder_conn, &e.to_string(), Some(&stages)); + Err(e) } } - - Ok(()) } /// JSON output for combined ingest (issues + mrs). @@ -1148,6 +1255,7 @@ async fn handle_sync_cmd( config_override: Option<&str>, args: SyncArgs, robot_mode: bool, + metrics: &MetricsLayer, ) -> Result<(), Box> { let mut config = Config::load(config_override)?; if args.no_events { @@ -1162,16 +1270,39 @@ async fn handle_sync_cmd( robot_mode, }; - let start = std::time::Instant::now(); - let result = run_sync(&config, options).await?; - let elapsed = start.elapsed(); + // Record sync run lifecycle in sync_runs table + let db_path = get_db_path(config.storage.db_path.as_deref()); + let recorder_conn = create_connection(&db_path)?; + let run_id = uuid::Uuid::new_v4().simple().to_string(); + let run_id_short = &run_id[..8]; + let recorder = SyncRunRecorder::start(&recorder_conn, "sync", run_id_short)?; - if robot_mode { - print_sync_json(&result, elapsed.as_millis() as u64); - } else { - print_sync(&result, elapsed); + let start = std::time::Instant::now(); + match run_sync(&config, options, Some(run_id_short)).await { + Ok(result) => { + let elapsed = start.elapsed(); + let stages = metrics.extract_timings(); + let total_items = result.issues_updated + + result.mrs_updated + + result.documents_regenerated + + result.documents_embedded; + let total_errors = result.resource_events_failed; + // Best-effort: don't fail the command if recording fails + let _ = recorder.succeed(&recorder_conn, &stages, total_items, total_errors); + + if robot_mode { + print_sync_json(&result, elapsed.as_millis() as u64, Some(metrics)); + } else { + print_sync(&result, elapsed, Some(metrics)); + } + Ok(()) + } + Err(e) => { + let stages = metrics.extract_timings(); + let _ = recorder.fail(&recorder_conn, &e.to_string(), Some(&stages)); + Err(e.into()) + } } - Ok(()) } // ============================================================================