Skip to content

Commit 4e40fbd

Browse files
Cliftonzclaude
andcommitted
feat(observability): wire file logging + run_id correlation + startup banner
Phase G of v0.1.0 hardening (parallel-code-review items 6, 16): - feat(analytics): attach `RollingFileAppender` (daily rotation, JSON, INFO+) to the `Registry` alongside console and OTLP layers. Previously the file layer existed in `observability::logging::init_minimal_logging` but that function was never invoked from main.rs, so `~/.jarvy/logs/jarvy.log` was always empty and `jarvy ticket create` shipped a hollow log file to support. One subscriber now owns all sinks (review #1). - feat(analytics): drop hard-coded `LevelFilter::ERROR` on the OTLP bridge; default to `info`, override via `JARVY_OTLP_LEVEL`. `tool.installed`, `setup.inventory`, `hook.completed` events actually export now (review #2). - feat(setup_cmd): generate per-invocation `run_id` (uuid v7) and hold an `info_span!("setup", run_id)` for the entire `run_setup` call. Every event in the file log / OTLP backend now carries `run_id` so support can stitch parallel install threads back together (review #6). - feat(setup_cmd): emit `setup.start` event with version, os, arch, config_source (local/remote), config_path, ci_provider, jobs, dry_run — the first five questions support asks. Was buried in scattered `eprintln!`s before (review #11). - feat(setup_cmd): rayon worker threads re-enter the parent setup span via `parent_span.enter()` inside `pool.install`. Without this, every event from a parallel-install worker was span-orphaned in traces (review #7). Each tool gets its own `install_tool` span keyed by name+version. Outstanding from item 6 (deferred): - Extending `tool_failed`/`hook_failed` signature with pm/exit_code/stderr_redacted/os fields (touches every caller). - Promoting these from warn to error. Outstanding from item 16 (deferred): - Reconciling `duration_ms` event field vs `with_unit("s")` histogram to one canonical unit (touches ~5 telemetry events and any consuming dashboards). Co-Authored-By: Claude Opus 4.7 (1M context) <noreply@anthropic.com>
1 parent b34c681 commit 4e40fbd

2 files changed

Lines changed: 111 additions & 2 deletions

File tree

src/analytics.rs

Lines changed: 69 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -9,8 +9,10 @@
99
use std::env;
1010
use std::io::Write;
1111
use tracing::Level;
12+
use tracing_appender::rolling::{RollingFileAppender, Rotation};
1213
use tracing_subscriber::Layer;
1314
use tracing_subscriber::filter::{FilterFn, LevelFilter};
15+
use tracing_subscriber::fmt::format::FmtSpan;
1416
use tracing_subscriber::layer::SubscriberExt;
1517
use tracing_subscriber::registry::Registry;
1618

@@ -57,15 +59,51 @@ pub fn init_logging(enable_analytics: bool) {
5759
.with_writer(std::io::stderr)
5860
.with_filter(LevelFilter::ERROR);
5961

60-
// Only if analytics enabled, export errors to OTLP logs
62+
// File layer at ~/.jarvy/logs/jarvy.log (daily rotation, JSON).
63+
//
64+
// Previously the file layer existed in `observability::logging::init_*`
65+
// but those functions were never called from `main.rs` — so
66+
// `~/.jarvy/logs/jarvy.log` was always empty, `jarvy logs view` returned
67+
// nothing, and `jarvy ticket create` shipped a hollow log file to support.
68+
// Wire it into the same `Registry` as the console + OTLP layers so a
69+
// single `set_global_default` covers all sinks (observability review #1).
70+
let file_layer = match ensure_log_dir() {
71+
Ok(dir) => {
72+
let appender = RollingFileAppender::new(Rotation::DAILY, dir, "jarvy.log");
73+
let layer = tracing_subscriber::fmt::layer()
74+
.json()
75+
.with_writer(appender)
76+
.with_span_events(FmtSpan::CLOSE)
77+
.with_current_span(true)
78+
.with_target(true)
79+
.with_ansi(false)
80+
// Capture every level the user might care about during a
81+
// failed `jarvy setup`. Cheaper than rebuilding telemetry
82+
// from `eprintln!` after the fact.
83+
.with_filter(LevelFilter::INFO);
84+
Some(layer)
85+
}
86+
Err(e) => {
87+
eprintln!("Warning: file logging disabled — could not create log dir: {e}");
88+
None
89+
}
90+
};
91+
92+
// Only if analytics enabled, export to OTLP logs.
93+
//
94+
// Filter is now driven by `JARVY_OTLP_LEVEL` (default `info`) instead of
95+
// the previous hard-coded `LevelFilter::ERROR`. The old filter dropped
96+
// every `info!`-level event — `tool.installed`, `setup.inventory`,
97+
// `hook.completed` — so `logs = true` in TelemetryConfig was a lie at
98+
// export time (observability review #2).
6199
let mut bootstrap_error: Option<String> = None;
62100
let otel_layer_opt = if enable_analytics {
63101
match build_otlp_logger_provider() {
64102
Ok(logger_provider) => {
65103
let layer = opentelemetry_appender_tracing::layer::OpenTelemetryTracingBridge::new(
66104
&logger_provider,
67105
)
68-
.with_filter(LevelFilter::ERROR); // export only errors to OTEL
106+
.with_filter(otlp_level_filter());
69107
Some(layer)
70108
}
71109
Err(e) => {
@@ -85,6 +123,7 @@ pub fn init_logging(enable_analytics: bool) {
85123
let subscriber = Registry::default()
86124
.with(stdout_non_error)
87125
.with(stderr_errors)
126+
.with(file_layer)
88127
.with(otel_layer_opt);
89128

90129
let install_result = tracing::subscriber::set_global_default(subscriber);
@@ -108,6 +147,34 @@ pub fn init_logging(enable_analytics: bool) {
108147
}
109148
}
110149

150+
/// Resolve the OTLP-bridge level filter. `JARVY_OTLP_LEVEL` (or the legacy
151+
/// `JARVY_OTLP_LOGS` boolean) overrides the default `info`. Setting it to
152+
/// `error` recovers the old behavior for users who explicitly want quiet
153+
/// exports.
154+
fn otlp_level_filter() -> LevelFilter {
155+
match env::var("JARVY_OTLP_LEVEL")
156+
.map(|v| v.trim().to_ascii_lowercase())
157+
.as_deref()
158+
{
159+
Ok("error") => LevelFilter::ERROR,
160+
Ok("warn") => LevelFilter::WARN,
161+
Ok("info") => LevelFilter::INFO,
162+
Ok("debug") => LevelFilter::DEBUG,
163+
Ok("trace") => LevelFilter::TRACE,
164+
_ => LevelFilter::INFO,
165+
}
166+
}
167+
168+
/// Returns `~/.jarvy/logs`, creating it if necessary.
169+
fn ensure_log_dir() -> std::io::Result<std::path::PathBuf> {
170+
let dir = dirs::home_dir()
171+
.ok_or_else(|| std::io::Error::new(std::io::ErrorKind::NotFound, "no home directory"))?
172+
.join(".jarvy")
173+
.join("logs");
174+
std::fs::create_dir_all(&dir)?;
175+
Ok(dir)
176+
}
177+
111178
fn otlp_logs_endpoint() -> String {
112179
if let Ok(v) = env::var("JARVY_OTLP_LOGS_ENDPOINT") {
113180
if !v.trim().is_empty() {

src/commands/setup_cmd.rs

Lines changed: 42 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -89,6 +89,34 @@ pub fn run_setup(
8989
file.to_string()
9090
};
9191

92+
// Generate a per-invocation correlation ID. Every event emitted from
93+
// this `run_setup` call carries `run_id` so support can stitch parallel
94+
// install threads back together when reading `~/.jarvy/logs/jarvy.log`
95+
// or an OTLP backend (observability review #6, #7).
96+
let run_id = uuid::Uuid::now_v7();
97+
// Hold this span open for the entire setup so `tracing::info_span!`
98+
// child spans inherit `run_id` automatically.
99+
let setup_span = tracing::info_span!("setup", run_id = %run_id);
100+
let _setup_span_guard = setup_span.enter();
101+
102+
// Startup banner — the first five questions support asks ("what
103+
// version, what OS, what package manager, what config source, what CI
104+
// provider"). Without this the only signal in a ticket bundle is
105+
// `eprintln!`s scattered through the install loop (observability
106+
// review #11).
107+
tracing::info!(
108+
event = "setup.start",
109+
run_id = %run_id,
110+
version = env!("CARGO_PKG_VERSION"),
111+
os = std::env::consts::OS,
112+
arch = std::env::consts::ARCH,
113+
config_source = %if from.is_some() { "remote" } else { "local" },
114+
config_path = %config_path,
115+
ci_provider = ?ci_env.as_ref().map(|e| e.provider.to_string()),
116+
jobs = parallel_jobs,
117+
dry_run = dry_run,
118+
);
119+
92120
let config = Config::new_with_workspace(&config_path);
93121
let hooks_config = config.get_hooks();
94122
let hook_settings = HookConfig::from(&hooks_config.config);
@@ -318,11 +346,25 @@ pub fn run_setup(
318346
let error_collector: Arc<Mutex<Vec<(String, String, String)>>> =
319347
Arc::new(Mutex::new(Vec::new()));
320348

349+
// Capture the parent span (which carries `run_id`) so rayon
350+
// worker threads — which have their own thread-local span
351+
// stack — can re-enter it. Without this, every event emitted
352+
// from a parallel-install worker is span-orphaned in
353+
// `~/.jarvy/logs/jarvy.log` and OTLP traces (observability
354+
// review #7).
355+
let parent_span = tracing::Span::current();
321356
pool.install(|| {
322357
tool_groups
323358
.custom_install
324359
.par_iter()
325360
.for_each(|(name, version)| {
361+
let _g = parent_span.enter();
362+
let install_span = tracing::info_span!(
363+
"install_tool",
364+
tool = %name,
365+
version = %version,
366+
);
367+
let _is = install_span.enter();
326368
println!(
327369
"Installing {} version {} using custom installer",
328370
name, version

0 commit comments

Comments
 (0)