theirongolddev/gitlore
1
0
Fork 0
Code Issues Pull Requests Actions Packages Projects Releases Wiki Activity

feat(cli): Add verbosity controls, JSON log format, and triple-layer subscriber

Browse Source 
Overhaul the CLI logging infrastructure for production observability:

CLI flags:
- Add -v/-vv/-vvv (--verbose) for progressive stderr verbosity control:
  0=INFO, 1=DEBUG app, 2=DEBUG all, 3+=TRACE
- Add --log-format text|json for structured stderr output in automation
- Existing -q/--quiet overrides verbosity for silent operation

Subscriber architecture (main.rs):
- Replace single-layer subscriber with triple-layer setup:
  1. stderr layer: human-readable or JSON, filtered by -v flags
  2. file layer: always-on JSON to daily-rotated logs (lore.YYYY-MM-DD.log)
  3. MetricsLayer: captures span timing for robot-mode performance payloads
- Parse CLI before subscriber init so verbosity is known at setup time
- Load LoggingConfig early (with graceful fallback for pre-init commands)
- Clean up old log files before subscriber init to avoid holding deleted handles
- Hold WorkerGuard at function scope to ensure flush on exit

Doctor command:
- Add logging health check: validates log directory exists, reports file
  count and total size, warns on missing or inaccessible log directory

Co-Authored-By: Claude Opus 4.5 <noreply@anthropic.com>
This commit is contained in:
teernisse
2026-02-04 10:01:28 -05:00
parent 329c8f4539
commit 362503d3bf
3 changed files with 294 additions and 84 deletions
Download Patch File Download Diff File Expand all files Collapse all files

75
src/cli/commands/doctor.rs
View File

@@ -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<String>,
}
#[derive(Debug, Serialize)]
pub struct LoggingCheck {
#[serde(flatten)]
pub result: CheckResult,
#[serde(skip_serializing_if = "Option::is_none")]
pub log_dir: Option<String>,
#[serde(skip_serializing_if = "Option::is_none")]
pub file_count: Option<usize>,
#[serde(skip_serializing_if = "Option::is_none")]
pub total_bytes: Option<u64>,
}
/// 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!();

8
src/cli/mod.rs
View File

@@ -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,
}

181
src/main.rs
View File

@@ -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<tracing_appender::non_blocking::WorkerGuard>;
// 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<dyn std::error::Error>> {
let config = Config::load(config_override)?;
let display = if robot_mode || quiet {
@@ -400,6 +481,16 @@ async fn handle_ingest(
let force = args.force && !args.no_force;
let full = args.full && !args.no_full;
// 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)?;
let ingest_result: std::result::Result<(), Box<dyn std::error::Error>> = async {
match args.entity.as_deref() {
Some(resource_type) => {
// Single entity ingest
@@ -457,8 +548,24 @@ async fn handle_ingest(
}
}
}
Ok(())
}
.await;
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)
}
}
}
/// 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<dyn std::error::Error>> {
let mut config = Config::load(config_override)?;
if args.no_events {
@@ -1162,16 +1270,39 @@ async fn handle_sync_cmd(
robot_mode,
};
// 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)?;
let start = std::time::Instant::now();
let result = run_sync(&config, options).await?;
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);
print_sync_json(&result, elapsed.as_millis() as u64, Some(metrics));
} else {
print_sync(&result, elapsed);
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())
}
}
}
// ============================================================================