feat(trace,file-history): add tracing instrumentation and diagnostic hints

Add structured tracing spans to trace and file-history pipelines so debug
logging (-vv) shows path resolution counts, MR match counts, and discussion
counts at each stage. This makes empty-result debugging straightforward.

Add a hints field to TraceResult and FileHistoryResult that carries
machine-readable diagnostic strings explaining *why* results may be empty
(e.g., "Run 'lore sync' to fetch MR file changes"). The CLI renders these
as info lines; robot mode includes them in JSON when non-empty.

Also: fix filter_map(Result::ok) → collect::<Result> in trace.rs (same
pattern fixed in prior commit for file_history/path_resolver), and switch
conn.prepare → conn.prepare_cached for the MR query.

Co-Authored-By: Claude Opus 4.6 <noreply@anthropic.com>
This commit is contained in:
teernisse
2026-02-18 13:28:37 -05:00
parent c0ca501662
commit 8442bcf367
3 changed files with 192 additions and 27 deletions

View File

@@ -1,5 +1,7 @@
use serde::Serialize; use serde::Serialize;
use tracing::info;
use crate::Config; use crate::Config;
use crate::cli::render::{self, Icons, Theme}; use crate::cli::render::{self, Icons, Theme};
use crate::core::db::create_connection; use crate::core::db::create_connection;
@@ -46,6 +48,9 @@ pub struct FileHistoryResult {
pub discussions: Vec<FileDiscussion>, pub discussions: Vec<FileDiscussion>,
pub total_mrs: usize, pub total_mrs: usize,
pub paths_searched: usize, pub paths_searched: usize,
/// Diagnostic hints explaining why results may be empty.
#[serde(skip_serializing_if = "Vec::is_empty")]
pub hints: Vec<String>,
} }
/// Run the file-history query. /// Run the file-history query.
@@ -77,6 +82,11 @@ pub fn run_file_history(
let paths_searched = all_paths.len(); let paths_searched = all_paths.len();
info!(
paths = paths_searched,
renames_followed, "file-history: resolved {} path(s) for '{}'", paths_searched, path
);
// Build placeholders for IN clause // Build placeholders for IN clause
let placeholders: Vec<String> = (0..all_paths.len()) let placeholders: Vec<String> = (0..all_paths.len())
.map(|i| format!("?{}", i + 2)) .map(|i| format!("?{}", i + 2))
@@ -135,14 +145,31 @@ pub fn run_file_history(
web_url: row.get(8)?, web_url: row.get(8)?,
}) })
})? })?
.filter_map(std::result::Result::ok) .collect::<std::result::Result<Vec<_>, _>>()?;
.collect();
let total_mrs = merge_requests.len(); let total_mrs = merge_requests.len();
info!(
mr_count = total_mrs,
"file-history: found {} MR(s) touching '{}'", total_mrs, path
);
// Optionally fetch DiffNote discussions on this file // Optionally fetch DiffNote discussions on this file
let discussions = if include_discussions && !merge_requests.is_empty() { let discussions = if include_discussions && !merge_requests.is_empty() {
fetch_file_discussions(&conn, &all_paths, project_id)? let discs = fetch_file_discussions(&conn, &all_paths, project_id)?;
info!(
discussion_count = discs.len(),
"file-history: found {} discussion(s)",
discs.len()
);
discs
} else {
Vec::new()
};
// Build diagnostic hints when no results found
let hints = if total_mrs == 0 {
build_file_history_hints(&conn, project_id, &all_paths)?
} else { } else {
Vec::new() Vec::new()
}; };
@@ -155,6 +182,7 @@ pub fn run_file_history(
discussions, discussions,
total_mrs, total_mrs,
paths_searched, paths_searched,
hints,
}) })
} }
@@ -179,8 +207,7 @@ fn fetch_file_discussions(
JOIN discussions d ON d.id = n.discussion_id \ JOIN discussions d ON d.id = n.discussion_id \
WHERE n.position_new_path IN ({in_clause}) {project_filter} \ WHERE n.position_new_path IN ({in_clause}) {project_filter} \
AND n.is_system = 0 \ AND n.is_system = 0 \
ORDER BY n.created_at DESC \ ORDER BY n.created_at DESC"
LIMIT 50"
); );
let mut stmt = conn.prepare(&sql)?; let mut stmt = conn.prepare(&sql)?;
@@ -210,12 +237,57 @@ fn fetch_file_discussions(
created_at_iso: ms_to_iso(created_at), created_at_iso: ms_to_iso(created_at),
}) })
})? })?
.filter_map(std::result::Result::ok) .collect::<std::result::Result<Vec<_>, _>>()?;
.collect();
Ok(discussions) Ok(discussions)
} }
/// Build diagnostic hints explaining why a file-history query returned no results.
fn build_file_history_hints(
conn: &rusqlite::Connection,
project_id: Option<i64>,
paths: &[String],
) -> Result<Vec<String>> {
let mut hints = Vec::new();
// Check if mr_file_changes has ANY rows for this project
let has_file_changes: bool = if let Some(pid) = project_id {
conn.query_row(
"SELECT EXISTS(SELECT 1 FROM mr_file_changes WHERE project_id = ?1 LIMIT 1)",
rusqlite::params![pid],
|row| row.get(0),
)?
} else {
conn.query_row(
"SELECT EXISTS(SELECT 1 FROM mr_file_changes LIMIT 1)",
[],
|row| row.get(0),
)?
};
if !has_file_changes {
hints.push(
"No MR file changes have been synced yet. Run 'lore sync' to fetch file change data."
.to_string(),
);
return Ok(hints);
}
// File changes exist but none match these paths
let path_list = paths
.iter()
.map(|p| format!("'{p}'"))
.collect::<Vec<_>>()
.join(", ");
hints.push(format!(
"Searched paths [{}] were not found in MR file changes. \
The file may predate the sync window or use a different path.",
path_list
));
Ok(hints)
}
// ── Human output ──────────────────────────────────────────────────────────── // ── Human output ────────────────────────────────────────────────────────────
pub fn print_file_history(result: &FileHistoryResult) { pub fn print_file_history(result: &FileHistoryResult) {
@@ -250,10 +322,16 @@ pub fn print_file_history(result: &FileHistoryResult) {
Icons::info(), Icons::info(),
Theme::dim().render("No merge requests found touching this file.") Theme::dim().render("No merge requests found touching this file.")
); );
if !result.renames_followed && result.rename_chain.len() == 1 {
println!( println!(
" {}", " {} Searched: {}",
Theme::dim().render("Hint: Run 'lore sync' to fetch MR file changes.") Icons::info(),
Theme::dim().render(&result.rename_chain[0])
); );
}
for hint in &result.hints {
println!(" {} {}", Icons::info(), Theme::dim().render(hint));
}
println!(); println!();
return; return;
} }
@@ -327,6 +405,7 @@ pub fn print_file_history_json(result: &FileHistoryResult, elapsed_ms: u64) {
"total_mrs": result.total_mrs, "total_mrs": result.total_mrs,
"renames_followed": result.renames_followed, "renames_followed": result.renames_followed,
"paths_searched": result.paths_searched, "paths_searched": result.paths_searched,
"hints": if result.hints.is_empty() { None } else { Some(&result.hints) },
} }
}); });

View File

@@ -50,17 +50,23 @@ pub fn print_trace(result: &TraceResult) {
); );
} }
// Show searched paths when there are renames but no chains
if result.trace_chains.is_empty() { if result.trace_chains.is_empty() {
println!( println!(
"\n {} {}", "\n {} {}",
Icons::info(), Icons::info(),
Theme::dim().render("No trace chains found for this file.") Theme::dim().render("No trace chains found for this file.")
); );
if !result.renames_followed && result.resolved_paths.len() == 1 {
println!( println!(
" {}", " {} Searched: {}",
Theme::dim() Icons::info(),
.render("Hint: Run 'lore sync' to fetch MR file changes and cross-references.") Theme::dim().render(&result.resolved_paths[0])
); );
}
for hint in &result.hints {
println!(" {} {}", Icons::info(), Theme::dim().render(hint));
}
println!(); println!();
return; return;
} }
@@ -195,6 +201,7 @@ pub fn print_trace_json(result: &TraceResult, elapsed_ms: u64, line_requested: O
"elapsed_ms": elapsed_ms, "elapsed_ms": elapsed_ms,
"total_chains": result.total_chains, "total_chains": result.total_chains,
"renames_followed": result.renames_followed, "renames_followed": result.renames_followed,
"hints": if result.hints.is_empty() { None } else { Some(&result.hints) },
} }
}); });

View File

@@ -1,4 +1,5 @@
use serde::Serialize; use serde::Serialize;
use tracing::info;
use super::error::Result; use super::error::Result;
use super::file_history::resolve_rename_chain; use super::file_history::resolve_rename_chain;
@@ -51,6 +52,9 @@ pub struct TraceResult {
pub renames_followed: bool, pub renames_followed: bool,
pub trace_chains: Vec<TraceChain>, pub trace_chains: Vec<TraceChain>,
pub total_chains: usize, pub total_chains: usize,
/// Diagnostic hints explaining why results may be empty.
#[serde(skip_serializing_if = "Vec::is_empty")]
pub hints: Vec<String>,
} }
/// Run the trace query: file -> MR -> issue chain. /// Run the trace query: file -> MR -> issue chain.
@@ -75,6 +79,14 @@ pub fn run_trace(
(vec![path.to_string()], false) (vec![path.to_string()], false)
}; };
info!(
paths = all_paths.len(),
renames_followed,
"trace: resolved {} path(s) for '{}'",
all_paths.len(),
path
);
// Build placeholders for IN clause // Build placeholders for IN clause
let placeholders: Vec<String> = (0..all_paths.len()) let placeholders: Vec<String> = (0..all_paths.len())
.map(|i| format!("?{}", i + 2)) .map(|i| format!("?{}", i + 2))
@@ -100,7 +112,7 @@ pub fn run_trace(
all_paths.len() + 2 all_paths.len() + 2
); );
let mut stmt = conn.prepare(&mr_sql)?; let mut stmt = conn.prepare_cached(&mr_sql)?;
let mut params: Vec<Box<dyn rusqlite::types::ToSql>> = Vec::new(); let mut params: Vec<Box<dyn rusqlite::types::ToSql>> = Vec::new();
params.push(Box::new(project_id.unwrap_or(0))); params.push(Box::new(project_id.unwrap_or(0)));
@@ -137,8 +149,14 @@ pub fn run_trace(
web_url: row.get(8)?, web_url: row.get(8)?,
}) })
})? })?
.filter_map(std::result::Result::ok) .collect::<std::result::Result<Vec<_>, _>>()?;
.collect();
info!(
mr_count = mr_rows.len(),
"trace: found {} MR(s) touching '{}'",
mr_rows.len(),
path
);
// Step 2: For each MR, find linked issues + optional discussions // Step 2: For each MR, find linked issues + optional discussions
let mut trace_chains = Vec::with_capacity(mr_rows.len()); let mut trace_chains = Vec::with_capacity(mr_rows.len());
@@ -152,6 +170,16 @@ pub fn run_trace(
Vec::new() Vec::new()
}; };
info!(
mr_iid = mr.iid,
issues = issues.len(),
discussions = discussions.len(),
"trace: MR !{}: {} issue(s), {} discussion(s)",
mr.iid,
issues.len(),
discussions.len()
);
trace_chains.push(TraceChain { trace_chains.push(TraceChain {
mr_iid: mr.iid, mr_iid: mr.iid,
mr_title: mr.title.clone(), mr_title: mr.title.clone(),
@@ -168,12 +196,20 @@ pub fn run_trace(
let total_chains = trace_chains.len(); let total_chains = trace_chains.len();
// Build diagnostic hints when no results found
let hints = if total_chains == 0 {
build_trace_hints(conn, project_id, &all_paths)?
} else {
Vec::new()
};
Ok(TraceResult { Ok(TraceResult {
path: path.to_string(), path: path.to_string(),
resolved_paths: all_paths, resolved_paths: all_paths,
renames_followed, renames_followed,
trace_chains, trace_chains,
total_chains, total_chains,
hints,
}) })
} }
@@ -191,7 +227,7 @@ fn fetch_linked_issues(conn: &rusqlite::Connection, mr_id: i64) -> Result<Vec<Tr
CASE er.reference_type WHEN 'closes' THEN 0 WHEN 'related' THEN 1 ELSE 2 END, \ CASE er.reference_type WHEN 'closes' THEN 0 WHEN 'related' THEN 1 ELSE 2 END, \
i.iid"; i.iid";
let mut stmt = conn.prepare(sql)?; let mut stmt = conn.prepare_cached(sql)?;
let issues: Vec<TraceIssue> = stmt let issues: Vec<TraceIssue> = stmt
.query_map(rusqlite::params![mr_id], |row| { .query_map(rusqlite::params![mr_id], |row| {
Ok(TraceIssue { Ok(TraceIssue {
@@ -202,8 +238,7 @@ fn fetch_linked_issues(conn: &rusqlite::Connection, mr_id: i64) -> Result<Vec<Tr
web_url: row.get(4)?, web_url: row.get(4)?,
}) })
})? })?
.filter_map(std::result::Result::ok) .collect::<std::result::Result<Vec<_>, _>>()?;
.collect();
Ok(issues) Ok(issues)
} }
@@ -225,11 +260,10 @@ fn fetch_trace_discussions(
WHERE d.merge_request_id = ?1 \ WHERE d.merge_request_id = ?1 \
AND n.position_new_path IN ({in_clause}) \ AND n.position_new_path IN ({in_clause}) \
AND n.is_system = 0 \ AND n.is_system = 0 \
ORDER BY n.created_at DESC \ ORDER BY n.created_at DESC"
LIMIT 20"
); );
let mut stmt = conn.prepare(&sql)?; let mut stmt = conn.prepare_cached(&sql)?;
let mut params: Vec<Box<dyn rusqlite::types::ToSql>> = Vec::new(); let mut params: Vec<Box<dyn rusqlite::types::ToSql>> = Vec::new();
params.push(Box::new(mr_id)); params.push(Box::new(mr_id));
@@ -251,12 +285,57 @@ fn fetch_trace_discussions(
created_at_iso: ms_to_iso(created_at), created_at_iso: ms_to_iso(created_at),
}) })
})? })?
.filter_map(std::result::Result::ok) .collect::<std::result::Result<Vec<_>, _>>()?;
.collect();
Ok(discussions) Ok(discussions)
} }
/// Build diagnostic hints explaining why a trace query returned no results.
fn build_trace_hints(
conn: &rusqlite::Connection,
project_id: Option<i64>,
paths: &[String],
) -> Result<Vec<String>> {
let mut hints = Vec::new();
// Check if mr_file_changes has ANY rows for this project
let has_file_changes: bool = if let Some(pid) = project_id {
conn.query_row(
"SELECT EXISTS(SELECT 1 FROM mr_file_changes WHERE project_id = ?1 LIMIT 1)",
rusqlite::params![pid],
|row| row.get(0),
)?
} else {
conn.query_row(
"SELECT EXISTS(SELECT 1 FROM mr_file_changes LIMIT 1)",
[],
|row| row.get(0),
)?
};
if !has_file_changes {
hints.push(
"No MR file changes have been synced yet. Run 'lore sync' to fetch file change data."
.to_string(),
);
return Ok(hints);
}
// File changes exist but none match these paths
let path_list = paths
.iter()
.map(|p| format!("'{p}'"))
.collect::<Vec<_>>()
.join(", ");
hints.push(format!(
"Searched paths [{}] were not found in MR file changes. \
The file may predate the sync window or use a different path.",
path_list
));
Ok(hints)
}
#[cfg(test)] #[cfg(test)]
#[path = "trace_tests.rs"] #[path = "trace_tests.rs"]
mod tests; mod tests;