From 73c720e9effde25385ca09185c62f04337cb818c Mon Sep 17 00:00:00 2001 From: xavix-yo Date: Sun, 26 Jul 2026 19:31:49 +0100 Subject: [PATCH] llm: restore request logging lost in the agent-loop migration MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit The LLM-requests page has been empty since 24ee5b8: deleting `session/handler/llm_call.rs` dropped both halves of the request log. The kernel builds the `ModelRequest` itself and sets `log: None`, so the `LoggingModel` decorator — wrapped once per model by `LlmManager` — wrote every metadata row with a NULL `user_id`, while the page (and the detail endpoint) filter on it. Nothing wrote `llm_request_payloads` at all any more, so the payload viewer had nothing to show either. Correlation cannot come from `LlmManager`: it builds one shared client per model and does not know whose traffic it serves. It now comes from the `ModelSelector`, the one component that knows both the model and the owner: `SkaldSelector::with_log(RequestLogTarget)` wraps the model it hands out, so metadata lands in `llm_requests` attributed to the user and the payload lands in that user's own encrypted DB, keyed by `request_id`. Session and frame are read off the request's `conversation`/`frame`, which makes kernel rounds, sub-agent frames and compaction summaries all attributed with no extra plumbing (`ModelRequest::log` stays unused). The compactor's summariser call is attributed too, which it never was: `try_compact`/`force_compact` now take the owner (its selector is built per compaction, so it can carry the target). Three tests in `llm::logging` lock this down — the owner/session/frame columns, the error row with the provider's rejected body, and the metadata-only path when no owner pool is available. Co-Authored-By: Claude Opus 5 --- CLAUDE.md | 2 +- crates/skald-core/src/compactor.rs | 28 +- crates/skald-core/src/db/llm_requests/mod.rs | 6 +- crates/skald-core/src/llm/logging.rs | 265 ++++++++++++++++-- crates/skald-core/src/llm/manager.rs | 27 +- .../skald-core/src/loop_adapters/catalog.rs | 9 +- .../skald-core/src/loop_adapters/runtime.rs | 23 +- .../skald-core/src/loop_adapters/selector.rs | 36 ++- crates/skald-core/src/session/handler/mod.rs | 6 +- 9 files changed, 342 insertions(+), 60 deletions(-) diff --git a/CLAUDE.md b/CLAUDE.md index 8a405fc..25a2b45 100644 --- a/CLAUDE.md +++ b/CLAUDE.md @@ -92,7 +92,7 @@ Two rules keep the boundary real, and both are enforced by the compiler: | `crates/skald-core/src/clarification/` | `ClarificationManager`: background-session question/answer | | `crates/skald-core/src/elicitation/` | `ElicitationManager` + bridge: MCP server-initiated input (`elicitation/create`), surfaced in the Inbox; secrets never logged/persisted | | `crates/skald-core/src/inbox.rs` | `Inbox`: unified façade for pending approvals + clarifications + elicitations (wraps ApprovalManager, ClarificationManager, ElicitationManager). The managers already emit the `*Requested`/`*Resolved` lifecycle events on the per-user bus; `ws.rs` forwards them to every connected client of that user regardless of `source`, so the web UI updates live (see `sidebar.js` row) | -| `crates/skald-core/src/llm/` | LLM client abstraction (OpenAI-compat, Anthropic, Ollama…). OpenAI-compatible provider *types* are runtime data, not code: `providers/declared.rs` loads `providers.yaml` at boot (see Config); only non-OpenAI-compatible or bespoke providers (anthropic, ollama, openai, openrouter) stay native. **Retriability** (`llm_call.rs::is_retriable_llm_error`) keys on the real HTTP status via `llm_client::http_status` (a structured `LlmError { status }` from the client, else a `reqwest::Error` in the chain), **not** a substring of the message — a model id/token count containing "404"/"401" no longer mis-classifies; 401/403/404/422 don't retry, 400/429/5xx/network do | +| `crates/skald-core/src/llm/` | LLM client abstraction (OpenAI-compat, Anthropic, Ollama…). OpenAI-compatible provider *types* are runtime data, not code: `providers/declared.rs` loads `providers.yaml` at boot (see Config); only non-OpenAI-compatible or bespoke providers (anthropic, ollama, openai, openrouter) stay native. **Retriability** (`Model::is_retriable`, `agent-loop`) keys on the real HTTP status carried by `ModelError { status }`, **not** a substring of the message — a model id/token count containing "404"/"401" cannot mis-classify; 401/403/404/422 don't retry, 400/429/5xx/network do. **Request logging** is the `logging.rs::LoggingModel` decorator, attached by the *caller's* `ModelSelector` (`loop_adapters/selector.rs::SkaldSelector::with_log`) — never by `LlmManager`, which builds one shared client per model and cannot know whose traffic it serves. The decorator's `RequestLogTarget` carries the owner: metadata → `llm_requests` in the registry (`user_id`, the column the UI filters on), payload bodies/headers → `llm_request_payloads` in that user's own encrypted DB, keyed by `request_id`; session + frame come from the request's own `conversation`/`frame`, so kernel rounds, sub-agent frames and compaction summaries are all attributed with no extra plumbing (`ModelRequest::log` is unused here) | | `crates/skald-core/src/transcribe/` | Transcription providers | | `crates/skald-core/src/image_generate/` | Image generation providers | | `crates/skald-core/src/memory/` | Agent memory tools | diff --git a/crates/skald-core/src/compactor.rs b/crates/skald-core/src/compactor.rs index 7c2a3ce..2aeca65 100644 --- a/crates/skald-core/src/compactor.rs +++ b/crates/skald-core/src/compactor.rs @@ -34,7 +34,6 @@ use std::sync::Arc; use agent_loop::compaction::{CompactionMode, should_compact}; use agent_loop::manager::LoopManager; use agent_loop::model::ModelHint; -use serde_json::json; use sqlx::SqlitePool; use tracing::{info, warn}; @@ -45,6 +44,7 @@ use crate::config::CompactionConfig; use crate::config_store::GlobalConfigManager; use crate::db::chat_history; use crate::llm::LlmManager; +use crate::llm::logging::RequestLogTarget; use crate::loop_adapters::history::SqliteHistory; use crate::loop_adapters::selector::SkaldSelector; @@ -112,7 +112,8 @@ impl ContextCompactor { pub async fn try_compact( &self, manager: &Arc, - pool: &SqlitePool, + pool: &Arc, + user_id: &str, session_id: i64, stack_id: i64, last_input_tokens: u32, @@ -136,7 +137,7 @@ impl ContextCompactor { "compactor: threshold exceeded, starting compaction" ); - self.do_compact(manager, session_id, stack_id, effective_tokens).await + self.do_compact(manager, pool, user_id, session_id, stack_id, effective_tokens).await } /// Force compaction regardless of the token threshold. @@ -146,7 +147,8 @@ impl ContextCompactor { pub async fn force_compact( &self, manager: &Arc, - pool: &SqlitePool, + pool: &Arc, + user_id: &str, session_id: i64, stack_id: i64, is_ephemeral: bool, @@ -162,7 +164,7 @@ impl ContextCompactor { "compactor: manual compaction triggered" ); - self.do_compact(manager, session_id, stack_id, effective_tokens).await + self.do_compact(manager, pool, user_id, session_id, stack_id, effective_tokens).await } /// Runs the library's compaction on the frame with Skald's model policy, @@ -171,9 +173,12 @@ impl ContextCompactor { /// Model: the instance-wide Settings pick (`compaction_model`) wins; empty, /// unset, or naming a model that no longer exists all degrade to AUTO /// selection by `compaction.strength` from config.yml. + #[allow(clippy::too_many_arguments)] async fn do_compact( &self, manager: &Arc, + pool: &Arc, + user_id: &str, session_id: i64, stack_id: i64, effective_tokens: u32, @@ -184,13 +189,14 @@ impl ContextCompactor { let outcome = manager .new_compaction(conv, agent_loop::ids::FrameId(stack_id)) .mode(CompactionMode::Auto { keep_tail: self.config.keep_recent }) - // Strength is Skald's, captured here (D14): a pin bypasses it. - .selector(Arc::new(SkaldSelector::new( - Arc::clone(&self.llm_manager), - self.config.strength, - ))) + // Strength is Skald's, captured here (D14): a pin bypasses it. The + // owner rides along so the summariser's call shows up in the + // requests log like any other (session/frame come from the request). + .selector(Arc::new( + SkaldSelector::new(Arc::clone(&self.llm_manager), self.config.strength) + .with_log(RequestLogTarget::user(user_id, Arc::clone(pool))), + )) .model(hint) - .log(json!({ "session_id": session_id, "stack_id": stack_id })) .run() .await?; diff --git a/crates/skald-core/src/db/llm_requests/mod.rs b/crates/skald-core/src/db/llm_requests/mod.rs index 527f684..fe5bc60 100644 --- a/crates/skald-core/src/db/llm_requests/mod.rs +++ b/crates/skald-core/src/db/llm_requests/mod.rs @@ -1,7 +1,9 @@ //! DB operations for the `llm_requests` table (metadata only). //! -//! Every `chat_with_tools` call is logged here by the -//! [`crate::llm::logging::LoggingModel`] decorator. +//! Every model call is logged here by the +//! [`crate::llm::logging::LoggingModel`] decorator, which the caller's +//! `ModelSelector` attaches to the model it hands out (that is where the owner +//! of the traffic is known — `user_id` is what the UI filters on). //! Payloads (request/response bodies + headers) live in `llm_request_payloads` //! in the owner bucket (`{userid}.db`), correlated by `request_id`. //! Rows are retained for `llm.request_log.retention_days` days (default 14). diff --git a/crates/skald-core/src/llm/logging.rs b/crates/skald-core/src/llm/logging.rs index 67126cf..e8e8a64 100644 --- a/crates/skald-core/src/llm/logging.rs +++ b/crates/skald-core/src/llm/logging.rs @@ -1,15 +1,26 @@ //! Transparent logging decorator for any [`agent_loop::model::Model`]. //! -//! [`LoggingModel`] intercepts every `complete` call, measures the duration, -//! and persists a **metadata-only** row to `llm_requests` in `system.db` -//! (fire-and-forget). Per-request correlation (session/stack/user id) travels -//! in [`ModelRequest::log`], set by the caller; the payload (request/response -//! bodies) is returned to the caller inside [`ModelResponse::raw`] / -//! [`ModelError::raw`] so it can be written to the user's own database. +//! [`LoggingModel`] intercepts every `complete` call, measures the duration and +//! persists, fire-and-forget: //! -//! The split keeps conversation content (payloads) behind the user key while -//! metadata (cost, tokens, timing) stays in the admin-readable registry. -//! (Successor of `chatbot::logging::LoggingChatbotClient`, blueprint D13.) +//! * a **metadata-only** row in `llm_requests` (`system.db`) — cost, tokens, +//! timing, plus the correlation the UI filters on (`user_id`, `session_id`, +//! `stack_id`); +//! * the **payload** (request/response bodies + headers) in +//! `llm_request_payloads` in the caller's own database, keyed by the same +//! `request_id`. +//! +//! The split keeps conversation content behind the user key while metadata +//! stays in the admin-readable registry (§5.1). +//! +//! **Correlation is the decorator's, not the request's.** The owner +//! ([`RequestLogTarget`]) is captured when the model is handed out — the +//! `ModelSelector` builds one decorator per selection, and it is the only place +//! in the process that knows *whose* traffic this is. Session and frame come +//! from the request itself (`conversation` / `frame`), so every caller — a +//! round of the kernel loop, a sub-agent frame, a compaction summary — is +//! attributed with no extra plumbing. `ModelRequest::log` is therefore unused +//! by this host. use std::sync::Arc; use std::time::Instant; @@ -19,19 +30,63 @@ use sqlx::SqlitePool; use tokio::sync::mpsc; use tracing::warn; -use agent_loop::model::{Model, ModelError, ModelRequest, ModelResponse, StreamDelta}; +use agent_loop::model::{Model, ModelError, ModelRequest, ModelResponse, RawMeta, StreamDelta}; -use crate::db::llm_requests; +use crate::db::{llm_request_payloads, llm_requests}; +use crate::loop_adapters::history::SqliteHistory; + +/// Who the logged traffic belongs to. +#[derive(Clone, Default)] +pub struct RequestLogTarget { + /// Owner of the call — the `user_id` column of the metadata row, and what + /// the LLM-requests page filters on. + pub user_id: Option, + /// The owner's own (SQLCipher) pool: destination of the payload rows. + /// `None` disables payload logging, keeping metadata only. + pub payloads: Option>, +} + +impl RequestLogTarget { + /// A user's traffic: metadata attributed to them, payloads in their pool. + pub fn user(user_id: impl Into, pool: Arc) -> Self { + Self { user_id: Some(user_id.into()), payloads: Some(pool) } + } +} pub struct LoggingModel { inner: Arc, - pool: Arc, + /// `system.db` — the registry the metadata row lands in. + registry: Arc, model_name: String, + target: RequestLogTarget, } impl LoggingModel { - pub fn new(inner: Arc, pool: Arc, model_name: impl Into) -> Self { - Self { inner, pool, model_name: model_name.into() } + pub fn new( + inner: Arc, + registry: Arc, + model_name: impl Into, + target: RequestLogTarget, + ) -> Self { + Self { inner, registry, model_name: model_name.into(), target } + } + + /// Persists the request/response bodies in the owner's own database. + /// Fire-and-forget: a failed write must never break the turn. + fn spawn_payload(&self, request_id: &str, raw: &RawMeta) { + let Some(pool) = self.target.payloads.clone() else { return }; + let row = llm_request_payloads::PayloadRow { + request_id: request_id.to_string(), + request_json: raw.request_body.as_ref().map(|v| v.to_string()).unwrap_or_default(), + request_headers: raw.request_headers.as_ref().map(|v| v.to_string()), + response_json: raw.response_body.as_ref().map(|v| v.to_string()), + response_headers: raw.response_headers.as_ref().map(|v| v.to_string()), + }; + tokio::spawn(async move { + if let Err(e) = llm_request_payloads::insert(&pool, row).await { + warn!(error = %e, "llm_request_payloads: failed to insert"); + } + }); } } @@ -46,14 +101,13 @@ impl Model for LoggingModel { let result = self.inner.complete(req, deltas).await; let duration_ms = start.elapsed().as_millis() as i64; - // Per-request correlation set by the caller (llm_call / compactor). - let log = req.log.clone().unwrap_or_default(); - let session_id = log["session_id"].as_i64(); - let stack_id = log["stack_id"].as_i64(); - let user_id = log["user_id"].as_str().map(str::to_string); + // Correlation: the owner is ours, the conversation/frame are the call's. + let session_id = SqliteHistory::session_id(&req.conversation).ok(); + let stack_id = Some(req.frame.0); + let user_id = self.target.user_id.clone(); let request_id = Some(req.request_id.clone()); let model_name = self.model_name.clone(); - let pool = Arc::clone(&self.pool); + let pool = Arc::clone(&self.registry); match &result { Ok(resp) => { @@ -64,6 +118,9 @@ impl Model for LoggingModel { usage.cache_read.map(|n| n as i64), usage.cache_write.map(|n| n as i64), ); + if let Some(raw) = resp.raw() { + self.spawn_payload(&req.request_id, raw); + } tokio::spawn(async move { if let Err(e) = llm_requests::insert(&pool, llm_requests::LlmRequestRow { request_id, @@ -83,6 +140,11 @@ impl Model for LoggingModel { }); } Err(e) => { + // Only an HTTP failure carries a body (a provider 400 is exactly + // what the debug page is for); network/parse errors carry none. + if let Some(raw) = e.raw.as_ref() { + self.spawn_payload(&req.request_id, raw); + } let error_text = e.to_string(); tokio::spawn(async move { if let Err(log_err) = llm_requests::insert(&pool, llm_requests::LlmRequestRow { @@ -111,3 +173,166 @@ impl Model for LoggingModel { self.inner.is_retriable(err) } } + +#[cfg(test)] +mod tests { + use super::*; + use agent_loop::ids::{ConversationId, FrameId}; + use agent_loop::model::Usage; + use agent_loop::testing::{FakeModel, Step}; + use serde_json::{Value, json}; + + fn temp_db_path(tag: &str) -> String { + let mut p = std::env::temp_dir(); + let nanos = std::time::SystemTime::now() + .duration_since(std::time::UNIX_EPOCH).unwrap().as_nanos(); + p.push(format!("skald-test-{tag}-{}-{nanos}.db", std::process::id())); + p.to_string_lossy().into_owned() + } + + fn cleanup(path: &str) { + for suffix in ["", "-wal", "-shm"] { + let _ = std::fs::remove_file(format!("{path}{suffix}")); + } + } + + fn raw() -> RawMeta { + RawMeta { + request_headers: Some(json!({ "authorization": "REDACTED" })), + request_body: Some(json!({ "model": "m", "messages": [] })), + response_headers: Some(json!({ "content-type": "application/json" })), + response_body: Some(json!({ "choices": [] })), + } + } + + fn request(request_id: &str, session_id: i64, stack_id: i64) -> ModelRequest { + ModelRequest { + messages: Vec::new(), + tools: Vec::new(), + model: "m".into(), + max_tokens: None, + temperature: None, + request_id: request_id.into(), + conversation: ConversationId::new(format!("session:{session_id}")), + frame: FrameId(stack_id), + extras: Value::Null, + log: None, + } + } + + /// The rows are written fire-and-forget from a spawned task. + async fn wait_for(pool: &SqlitePool, sql: &'static str) -> i64 { + for _ in 0..100 { + let n = sqlx::query_scalar::<_, i64>(sql).fetch_one(pool).await.unwrap(); + if n > 0 { + return n; + } + tokio::time::sleep(std::time::Duration::from_millis(20)).await; + } + panic!("no row appeared for: {sql}"); + } + + /// The regression that made the LLM-requests page empty after the + /// agent-loop migration: a row written with no `user_id` (the page filters + /// on it) and no payload. + #[tokio::test] + async fn logs_metadata_with_owner_and_payload() { + let path = temp_db_path("llmlog-ok"); + let pool = Arc::new(crate::db::init_system_pool(&path).await.unwrap()); + + let mut resp = ModelResponse::message("hi"); + *resp.usage_mut() = Usage { + input_tokens: Some(11), + output_tokens: Some(7), + ..Usage::default() + }; + let ModelResponse::Message { content, reasoning, usage, .. } = resp else { unreachable!() }; + let scripted = ModelResponse::Message { content, reasoning, usage, raw: Some(raw()) }; + + let inner = Arc::new(FakeModel::new("m", vec![Step { result: Ok(scripted), deltas: Vec::new(), pending: false }])); + let model = LoggingModel::new( + inner, + Arc::clone(&pool), + "gpt-test", + RequestLogTarget::user("u-1", Arc::clone(&pool)), + ); + + model.complete(&request("req-1", 42, 7), None).await.unwrap(); + + wait_for(&pool, "SELECT COUNT(*) FROM llm_requests").await; + let (user_id, session_id, stack_id, model_name, input, output): (Option, Option, Option, String, Option, Option) = + sqlx::query_as("SELECT user_id, session_id, stack_id, model_name, input_tokens, output_tokens + FROM llm_requests WHERE request_id = 'req-1'") + .fetch_one(&*pool).await.unwrap(); + assert_eq!(user_id.as_deref(), Some("u-1"), "the page filters on user_id"); + assert_eq!(session_id, Some(42)); + assert_eq!(stack_id, Some(7)); + assert_eq!(model_name, "gpt-test"); + assert_eq!((input, output), (Some(11), Some(7))); + + wait_for(&pool, "SELECT COUNT(*) FROM llm_request_payloads").await; + let body: String = sqlx::query_scalar( + "SELECT request_json FROM llm_request_payloads WHERE request_id = 'req-1'") + .fetch_one(&*pool).await.unwrap(); + assert!(body.contains("\"messages\""), "payload not persisted: {body}"); + + pool.close().await; + cleanup(&path); + } + + /// A failed call is logged too, with the provider's rejected body attached. + #[tokio::test] + async fn logs_error_row_and_error_payload() { + let path = temp_db_path("llmlog-err"); + let pool = Arc::new(crate::db::init_system_pool(&path).await.unwrap()); + + let err = ModelError::new(Some(400), "bad request").with_raw(raw()); + let inner = Arc::new(FakeModel::new("m", vec![Step { result: Err(err), deltas: Vec::new(), pending: false }])); + let model = LoggingModel::new( + inner, + Arc::clone(&pool), + "gpt-test", + RequestLogTarget::user("u-2", Arc::clone(&pool)), + ); + + assert!(model.complete(&request("req-2", 5, 9), None).await.is_err()); + + wait_for(&pool, "SELECT COUNT(*) FROM llm_requests").await; + let (user_id, error_text): (Option, Option) = + sqlx::query_as("SELECT user_id, error_text FROM llm_requests WHERE request_id = 'req-2'") + .fetch_one(&*pool).await.unwrap(); + assert_eq!(user_id.as_deref(), Some("u-2")); + assert!(error_text.unwrap_or_default().contains("bad request")); + + wait_for(&pool, "SELECT COUNT(*) FROM llm_request_payloads").await; + + pool.close().await; + cleanup(&path); + } + + /// No target pool ⇒ metadata only (payloads are the owner's, and an owner + /// with a locked database must not silently lose the metadata row). + #[tokio::test] + async fn without_payload_pool_only_metadata_is_written() { + let path = temp_db_path("llmlog-meta"); + let pool = Arc::new(crate::db::init_system_pool(&path).await.unwrap()); + + let inner = Arc::new(FakeModel::new("m", vec![Step::message("hi")])); + let model = LoggingModel::new( + inner, + Arc::clone(&pool), + "gpt-test", + RequestLogTarget { user_id: Some("u-3".into()), payloads: None }, + ); + + model.complete(&request("req-3", 1, 2), None).await.unwrap(); + + wait_for(&pool, "SELECT COUNT(*) FROM llm_requests").await; + let payloads: i64 = sqlx::query_scalar("SELECT COUNT(*) FROM llm_request_payloads") + .fetch_one(&*pool).await.unwrap(); + assert_eq!(payloads, 0); + + pool.close().await; + cleanup(&path); + } +} diff --git a/crates/skald-core/src/llm/manager.rs b/crates/skald-core/src/llm/manager.rs index cb63755..e606a45 100644 --- a/crates/skald-core/src/llm/manager.rs +++ b/crates/skald-core/src/llm/manager.rs @@ -8,11 +8,9 @@ use sqlx::SqlitePool; use tokio::sync::RwLock; use tracing::{info, warn}; -use agent_loop::model::Model; use core_api::provider::LlmStrength; use crate::provider::{ApiProvider, ProviderRegistry, ReasoningMode}; -use super::logging::LoggingModel; use super::providers::RemoteLlmModelInfo; use super::{ClientStatus, LlmEntry, LlmModelInfo, LlmModelRecord, LlmProviderInfo, LlmProviderRecord}; use super::db; @@ -69,7 +67,9 @@ pub struct LlmManager { catalog: RwLock>, /// Per-model metadata cache, keyed by model display name. TTL = 1h. model_meta_cache: RwLock>, - /// When `true`, every LLM entry is wrapped with [`LoggingChatbotClient`]. + /// `llm.requests_log.enabled` — when `true`, a selected model is wrapped + /// with [`crate::llm::logging::LoggingModel`] by the caller's selector + /// (which is what knows *whose* traffic it is). See [`Self::log_pool`]. log_enabled: bool, } @@ -172,6 +172,13 @@ impl LlmManager { provider.llm_model_info(&record, model_id).await.ok().flatten() } + /// The registry pool the request log lands in, or `None` when logging is + /// disabled (`llm.requests_log.enabled: false`). A selector wraps the model + /// it hands out only when this is `Some`. + pub fn log_pool(&self) -> Option> { + self.log_enabled.then(|| Arc::clone(&self.pool)) + } + pub async fn get(&self, name: &str) -> Option> { self.state.read().await.models.get(name).map(|s| s.entry.clone()) } @@ -457,9 +464,7 @@ impl LlmManager { } }; - let log_pool = self.log_enabled.then(|| Arc::clone(&self.pool)); - - let entry = match build_entry(&self.registry, &provider, &model, model.id, log_pool) { + let entry = match build_entry(&self.registry, &provider, &model, model.id) { Ok(e) => Arc::new(e), Err(e) => { warn!(model = %model.name, error = %e, "failed to build LLM entry, skipping"); @@ -501,22 +506,18 @@ fn build_entry( provider: &LlmProviderRecord, model: &LlmModelRecord, model_db_id: i64, - log_pool: Option>, ) -> Result { let built = registry.get(&provider.provider) .ok_or_else(|| anyhow::anyhow!("unknown provider type '{}'", provider.provider))? .build_llm(provider, model) .ok_or_else(|| anyhow::anyhow!("provider '{}' does not support LLM", provider.provider))??; - let inner = built.client; + // The bare client: request logging is a per-caller decorator applied by the + // `ModelSelector` (it is the only place that knows the owner), not here. + let client = built.client; let prompt_cache = built.prompt_cache; let extra = model.extra_params.clone(); - let client: Arc = match log_pool { - Some(pool) => Arc::new(LoggingModel::new(inner, pool, &model.name)), - None => inner, - }; - Ok(LlmEntry { client, model: model.model_id.clone(), diff --git a/crates/skald-core/src/loop_adapters/catalog.rs b/crates/skald-core/src/loop_adapters/catalog.rs index d3c94d2..fdcb710 100644 --- a/crates/skald-core/src/loop_adapters/catalog.rs +++ b/crates/skald-core/src/loop_adapters/catalog.rs @@ -24,6 +24,7 @@ use sqlx::SqlitePool; use crate::approval::ApprovalManager; use crate::clarification::ClarificationManager; use crate::llm::LlmManager; +use crate::llm::logging::RequestLogTarget; use crate::loop_adapters::activation::SkaldToolActivator; use crate::loop_adapters::builtins::{SkaldAskUserTool, SkaldHumanChannel}; use crate::loop_adapters::history::SqliteHistory; @@ -109,8 +110,12 @@ impl AgentCatalog for SkaldAgentCatalog { let meta = crate::agents::load_task_meta(id).map_err(|e| anyhow::anyhow!("{e}"))?; // The child's own strength drives its selector (D14) — never the - // parent's resolved client. - let selector = Arc::new(SkaldSelector::new(self.llm_manager.clone(), meta.strength)); + // parent's resolved client. Its traffic is logged under the same owner + // (the child's frame id already distinguishes it in the log). + let selector = Arc::new( + SkaldSelector::new(self.llm_manager.clone(), meta.strength) + .with_log(RequestLogTarget::user(self.user_id.clone(), self.pool.clone())), + ); let model = meta.client.as_deref().map(ModelHint::name); // The child's system context: its own prompt, no per-turn extras. diff --git a/crates/skald-core/src/loop_adapters/runtime.rs b/crates/skald-core/src/loop_adapters/runtime.rs index 80fefa3..1d6c627 100644 --- a/crates/skald-core/src/loop_adapters/runtime.rs +++ b/crates/skald-core/src/loop_adapters/runtime.rs @@ -30,6 +30,7 @@ use crate::approval::ApprovalManager; use crate::clarification::ClarificationManager; use crate::config::DatetimeConfig; use crate::llm::LlmManager; +use crate::llm::logging::RequestLogTarget; use crate::loop_adapters::activation::{SkaldActivationSource, SkaldToolActivator}; use crate::loop_adapters::async_task::CronExecutor; use crate::loop_adapters::builtins::{ @@ -132,9 +133,12 @@ impl UserLoopRuntime { })); // The default selector has no strength requirement; every turn overrides - // it with the agent's own (D14). - let default_selector: Arc = - Arc::new(SkaldSelector::new(llm_manager.clone(), None)); + // it with the agent's own (D14). It carries the owner's log target, so a + // call served by it (recovery, compaction) is still attributed. + let default_selector: Arc = Arc::new( + SkaldSelector::new(llm_manager.clone(), None) + .with_log(RequestLogTarget::user(user_id.clone(), pool.clone())), + ); let manager = Arc::new( LoopManager::builder() @@ -208,6 +212,12 @@ impl UserLoopRuntime { &self.store } + /// Where this user's LLM traffic is logged: metadata in the registry + /// (attributed to them), payloads in their own encrypted pool. + pub fn log_target(&self) -> RequestLogTarget { + RequestLogTarget::user(self.user_id.clone(), self.pool.clone()) + } + /// The conversation id of a session — the store's encoding. pub fn conversation(session_id: i64) -> ConversationId { SqliteHistory::conversation(session_id) @@ -259,10 +269,11 @@ impl UserLoopRuntime { extensions.insert(Arc::new(CallerUserId(self.user_id.clone()))); extensions.insert(scope.clone()); - // ── Selector: this agent's strength (D14) ── + // ── Selector: this agent's strength (D14) + the owner's request log ── let strength = crate::agents::load_meta(&frame_agent).ok().and_then(|m| m.strength); - let selector: Arc = - Arc::new(SkaldSelector::new(self.llm_manager.clone(), strength)); + let selector: Arc = Arc::new( + SkaldSelector::new(self.llm_manager.clone(), strength).with_log(self.log_target()), + ); // The session's root frame; the store reuses the provisioned row. let frame = self diff --git a/crates/skald-core/src/loop_adapters/selector.rs b/crates/skald-core/src/loop_adapters/selector.rs index 328d92f..cab927d 100644 --- a/crates/skald-core/src/loop_adapters/selector.rs +++ b/crates/skald-core/src/loop_adapters/selector.rs @@ -8,10 +8,11 @@ use std::sync::Arc; use agent_loop::activation::ToolRendering; use agent_loop::async_trait; -use agent_loop::model::{ModelHandle, ModelHint, ModelInfo, ModelSelector}; +use agent_loop::model::{Model, ModelHandle, ModelHint, ModelInfo, ModelSelector}; use agent_loop::ids::ModelId; use serde_json::Value; +use crate::llm::logging::{LoggingModel, RequestLogTarget}; use crate::llm::{DtlMode, LlmEntry, LlmManager, LlmStrength}; /// Maps Skald's per-model DTL mode to the crate's wire protocol (D15). @@ -37,14 +38,42 @@ pub fn model_info_of(entry: &LlmEntry) -> ModelInfo { /// The selector handed to the loop manager for one turn: the manager's /// strength tiering + health + priority, behind the crate's seam. +/// +/// It is also where **request logging** is attached: the selector is the only +/// component that knows both the model and the owner of the call, so it wraps +/// the model it hands out in a [`LoggingModel`] bound to that owner (see +/// [`Self::with_log`]). Without it the metadata row would land with a NULL +/// `user_id` and no payload — invisible in the LLM-requests page. pub struct SkaldSelector { manager: Arc, strength: Option, + log: Option, } impl SkaldSelector { pub fn new(manager: Arc, strength: Option) -> Self { - Self { manager, strength } + Self { manager, strength, log: None } + } + + /// Attributes every call served by this selector to `target`. Honoured only + /// when instance-wide request logging is on (`llm.requests_log.enabled`). + pub fn with_log(mut self, target: RequestLogTarget) -> Self { + self.log = Some(target); + self + } + + /// Wraps a resolved client in the logging decorator when both a target and + /// the registry pool are available; otherwise hands the bare client over. + fn instrument(&self, name: &str, entry: &LlmEntry) -> Arc { + match (&self.log, self.manager.log_pool()) { + (Some(target), Some(registry)) => Arc::new(LoggingModel::new( + entry.client.clone(), + registry, + name, + target.clone(), + )), + _ => entry.client.clone(), + } } } @@ -60,9 +89,10 @@ impl ModelSelector for SkaldSelector { let excluded: Vec<&str> = exclude.iter().map(String::as_str).collect(); self.manager.select_excluding(&excluded, self.strength).await? }; + let model = self.instrument(&name, &entry); Ok(ModelHandle { id: name, - model: entry.client.clone(), + model, info: model_info_of(&entry), }) } diff --git a/crates/skald-core/src/session/handler/mod.rs b/crates/skald-core/src/session/handler/mod.rs index 2ac9efd..d62a910 100644 --- a/crates/skald-core/src/session/handler/mod.rs +++ b/crates/skald-core/src/session/handler/mod.rs @@ -452,7 +452,8 @@ impl ChatSessionHandler { match self.compactor { Some(ref compactor) => { compactor.force_compact( - self.loop_runtime.manager(), pool, self.session_id, stack.id, self.is_ephemeral, + self.loop_runtime.manager(), pool, &self.user_id, + self.session_id, stack.id, self.is_ephemeral, ).await } None => Ok(false), @@ -555,7 +556,8 @@ impl ChatSessionHandler { if let Some(ref compactor) = self.compactor { let last_tokens = self.last_input_tokens.load(Ordering::Relaxed); match compactor.try_compact( - self.loop_runtime.manager(), pool, self.session_id, stack.id, last_tokens, self.is_ephemeral, + self.loop_runtime.manager(), pool, &self.user_id, + self.session_id, stack.id, last_tokens, self.is_ephemeral, ).await { Ok(true) => info!(session_id = self.session_id, stack_id = stack.id, "handle_message: context compacted"), Ok(false) => {}