feat: log LLM calls with timing at search, classification, and rewrite steps

Co-Authored-By: Claude Sonnet 4.6 <noreply@anthropic.com>
master
oabrivard 3 months ago
parent b2b0b286c0
commit 9fffde8312

@ -271,6 +271,10 @@ async fn run_generation_inner(
if deleted > 0 { if deleted > 0 {
tracing::info!(deleted = deleted, "Cleaned up old article history entries"); tracing::info!(deleted = deleted, "Cleaned up old article history entries");
} }
// Truncate old LLM call logs
db::llm_call_log::truncate_old(&state.pool, user_id, settings.article_history_days)
.await
.ok();
} }
if settings.categories.is_empty() { if settings.categories.is_empty() {
@ -504,6 +508,7 @@ async fn run_generation_inner(
); );
let class_schema = build_classification_schema(); let class_schema = build_classification_schema();
let llm_start = std::time::Instant::now();
let class_response = provider let class_response = provider
.generate_rewrite_pass( .generate_rewrite_pass(
&model_research, &model_research,
@ -512,6 +517,9 @@ async fn run_generation_inner(
&class_schema, &class_schema,
) )
.await?; .await?;
let llm_duration = llm_start.elapsed().as_millis() as u64;
log_llm_call(&state.pool, user_id, job_id, "classification_phase1", &model_research,
&class_system, &class_user, &class_response, llm_duration).await;
// 1e. Parse classification and fill categories // 1e. Parse classification and fill categories
let (phase1_classified, phase1_overflow) = parse_classification_response( let (phase1_classified, phase1_overflow) = parse_classification_response(
@ -659,9 +667,13 @@ async fn run_generation_inner(
Some(&category_gaps), Some(&category_gaps),
); );
let llm_start = std::time::Instant::now();
let raw_results = provider let raw_results = provider
.generate_search_pass(&model_research, &system_prompt, &user_prompt, &search_schema) .generate_search_pass(&model_research, &system_prompt, &user_prompt, &search_schema)
.await?; .await?;
let llm_duration = llm_start.elapsed().as_millis() as u64;
log_llm_call(&state.pool, user_id, job_id, "search", &model_research,
&system_prompt, &user_prompt, &raw_results, llm_duration).await;
// Parse + filter // Parse + filter
emit_progress(tx, "parsing", "Analyse des resultats...", 55); emit_progress(tx, "parsing", "Analyse des resultats...", 55);
@ -801,6 +813,7 @@ async fn run_generation_inner(
); );
let class_schema = build_classification_schema(); let class_schema = build_classification_schema();
let llm_start = std::time::Instant::now();
let class_response = provider let class_response = provider
.generate_rewrite_pass( .generate_rewrite_pass(
&model_research, &model_research,
@ -809,6 +822,9 @@ async fn run_generation_inner(
&class_schema, &class_schema,
) )
.await?; .await?;
let llm_duration = llm_start.elapsed().as_millis() as u64;
log_llm_call(&state.pool, user_id, job_id, "classification_phase2", &model_research,
&class_system, &class_user, &class_response, llm_duration).await;
let (phase2_classified, phase2_overflow) = parse_classification_response( let (phase2_classified, phase2_overflow) = parse_classification_response(
&class_response, &class_response,
@ -898,9 +914,13 @@ async fn run_generation_inner(
let (rewrite_system, rewrite_user) = prompts::build_rewrite_prompt(&all_scraped); let (rewrite_system, rewrite_user) = prompts::build_rewrite_prompt(&all_scraped);
let rewrite_schema = build_rewrite_schema(&all_scraped, &settings.categories); let rewrite_schema = build_rewrite_schema(&all_scraped, &settings.categories);
let llm_start = std::time::Instant::now();
let final_results = provider let final_results = provider
.generate_rewrite_pass(&model_writing, &rewrite_system, &rewrite_user, &rewrite_schema) .generate_rewrite_pass(&model_writing, &rewrite_system, &rewrite_user, &rewrite_schema)
.await?; .await?;
let llm_duration = llm_start.elapsed().as_millis() as u64;
log_llm_call(&state.pool, user_id, job_id, "rewrite", &model_writing,
&rewrite_system, &rewrite_user, &final_results, llm_duration).await;
emit_progress(tx, "finalizing", "Finalisation...", 90); emit_progress(tx, "finalizing", "Finalisation...", 90);
let mut final_sections = build_final_sections(&final_results, &settings.categories)?; let mut final_sections = build_final_sections(&final_results, &settings.categories)?;
@ -999,6 +1019,27 @@ async fn trace_article(
db::article_history::insert_entry(pool, &entry).await.ok(); db::article_history::insert_entry(pool, &entry).await.ok();
} }
/// Log an LLM call with full prompt, response, and timing.
async fn log_llm_call(
pool: &sqlx::PgPool,
user_id: Uuid,
job_id: Uuid,
call_type: &str,
model: &str,
system_prompt: &str,
user_prompt: &str,
response: &serde_json::Value,
duration_ms: u64,
) {
let response_str = serde_json::to_string_pretty(response).unwrap_or_default();
db::llm_call_log::insert(
pool, user_id, job_id, call_type, model,
system_prompt, user_prompt, &response_str, duration_ms as i32,
)
.await
.ok(); // Don't fail synthesis if logging fails
}
/// Look up or create a per-user rate limiter stored in AppState. /// Look up or create a per-user rate limiter stored in AppState.
/// ///
/// Returns `None` if the user has no rate limit overrides, in which case the /// Returns `None` if the user has no rate limit overrides, in which case the

Loading…
Cancel
Save