Skip to content

Commit 22c80ac

Browse files
Alexey Panfilovclaude
andcommitted
feat(usage): usage_log schema + OpenRouter capture + router hook (Stage A.1)
First of three stages splitting the admin-UI umbrella task into Usage+Cost infrastructure (A.1), remaining-provider capture (A.2), and Usage/Cost admin sections (A.3). What lands here: * internal/llm/usage.go - UsageLog struct (one row per LLM call — agentic loops produce N rows sharing the same user_message_id) - UsageStore interface with PutUsage + UpdateAssistantMessageID - Usage struct attached to llm.Response, populated by providers that report token counts; zero-value otherwise - TurnMeta + WithTurnMeta/TurnMetaFrom context helpers for threading chat_id / user_message_id / role-hint from agent down to router without changing every provider's Chat signature - ClassifyErrorClass bucketing for dashboards (rate_limit / 5xx / 4xx / network / timeout / other) * Schema in usage_log (SQLite migration + Postgres CREATE IF NOT EXISTS) - id, ts, provider, model_id, role, chat_id - prompt_tokens, completion_tokens, cached_prompt_tokens, reasoning_tokens (prompt caching + thinking overhead accounted from the start, per API reference) - latency_ms, success, error_class, request_id, tool_call_count - user_message_id, assistant_message_id (nullable FKs to messages.id) - indexes on (ts, model_id), (chat_id, ts), (user_message_id) * Store implementations — PutUsage + UpdateAssistantMessageID for both SQLite and Postgres backends, wired through main.go via type assertion to llm.UsageStore (works with either backend the bot is configured to use). * openai_compat.go — parse OpenRouter usage block including prompt_tokens_details.cached_tokens (Anthropic caching via bridge / OpenAI prompt caching) and completion_tokens_details.reasoning_tokens (thinking models). Also captures the provider's request id for cross-referencing with their dashboard when debugging a call. * Router.Chat records a UsageLog row after every provider call (primary AND each fallback hop), best-effort with a 3s timeout on a background ctx so usage logging never blocks or fails a user request. Error class is auto-classified; turn meta is pulled from ctx when present. Scope covered: OpenRouter traffic (~90% of real requests) is now logged end-to-end with full token breakdown. Other providers (gemini / claude_bridge / ollama / local) still land rows but with zero tokens until their response parsers are updated — that's Stage A.2. Tests added: - ClassifyErrorClass bucket mapping (8 cases) - TurnMeta round-trip through context - rawChatResponse parses usage block + cached + reasoning + request_id - SQLite round-trip: insert with all fields, backfill assistant_message_id, verify NULL handling for background tasks Co-Authored-By: Claude Sonnet 4.6 <noreply@anthropic.com>
1 parent ca3a3ce commit 22c80ac

9 files changed

Lines changed: 529 additions & 1 deletion

File tree

cmd/agent/main.go

Lines changed: 5 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -197,6 +197,11 @@ func main() {
197197
if err := router.LoadPersistedOverrides(); err != nil {
198198
logger.Warn("failed to load routing overrides", "err", err)
199199
}
200+
// Wire usage log sink (best-effort: router tolerates nil store).
201+
if us, ok := s.(llm.UsageStore); ok {
202+
router.SetUsageStore(us)
203+
logger.Info("usage logging enabled")
204+
}
200205
// Apply persisted per-slot OpenRouter model overrides (e.g. admin UI picked
201206
// a different model last session). Pull caps from the store.
202207
if orOverrides := router.TakePendingOpenRouterOverrides(); len(orOverrides) > 0 {

internal/llm/openai_compat.go

Lines changed: 30 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -196,18 +196,35 @@ type rawToolFunctionDef struct {
196196
}
197197

198198
type rawChatResponse struct {
199+
ID string `json:"id"` // provider request id (OpenRouter: "gen-...")
199200
Choices []struct {
200201
Message struct {
201202
Content string `json:"content"`
202203
ToolCalls []rawToolCall `json:"tool_calls"`
203204
} `json:"message"`
204205
} `json:"choices"`
206+
Usage *rawUsage `json:"usage"`
205207
Error *struct {
206208
Message string `json:"message"`
207209
Type string `json:"type"`
208210
} `json:"error"`
209211
}
210212

213+
// rawUsage covers OpenAI-compatible usage fields plus the nested *_details
214+
// blocks that OpenRouter / Anthropic / OpenAI populate for prompt caching
215+
// and reasoning tokens.
216+
type rawUsage struct {
217+
PromptTokens int `json:"prompt_tokens"`
218+
CompletionTokens int `json:"completion_tokens"`
219+
TotalTokens int `json:"total_tokens"`
220+
PromptTokensDetails *struct {
221+
CachedTokens int `json:"cached_tokens"`
222+
} `json:"prompt_tokens_details"`
223+
CompletionTokensDetails *struct {
224+
ReasoningTokens int `json:"reasoning_tokens"`
225+
} `json:"completion_tokens_details"`
226+
}
227+
211228
func (p *openAICompatProvider) Chat(ctx context.Context, messages []Message, systemPrompt string, tools []Tool) (Response, error) {
212229
model, vision := p.snapshot()
213230
rawMsgs := buildMessages(messages, systemPrompt, vision)
@@ -272,6 +289,19 @@ func (p *openAICompatProvider) Chat(ctx context.Context, messages []Message, sys
272289
Arguments: tc.Function.Arguments,
273290
})
274291
}
292+
if u := chatResp.Usage; u != nil {
293+
result.Usage = Usage{
294+
PromptTokens: u.PromptTokens,
295+
CompletionTokens: u.CompletionTokens,
296+
RequestID: chatResp.ID,
297+
}
298+
if u.PromptTokensDetails != nil {
299+
result.Usage.CachedPromptTokens = u.PromptTokensDetails.CachedTokens
300+
}
301+
if u.CompletionTokensDetails != nil {
302+
result.Usage.ReasoningTokens = u.CompletionTokensDetails.ReasoningTokens
303+
}
304+
}
275305
return result, nil
276306
}
277307

internal/llm/provider.go

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -54,6 +54,7 @@ type ToolCall struct {
5454
type Response struct {
5555
Content string
5656
ToolCalls []ToolCall
57+
Usage Usage // populated by providers that report token counts; zero-value otherwise
5758
}
5859

5960
type Provider interface {

internal/llm/router.go

Lines changed: 69 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -69,6 +69,7 @@ type Router struct {
6969
persistPath string // legacy: file for routing overrides. Read once on first start
7070
// for migration, then the binary writes to the settings store.
7171
settings SettingsStore // primary persistence; DB-backed
72+
usage UsageStore // optional; when set, Router records UsageLog after every call
7273
lastRouted string // display name of last provider (for UI)
7374
lastRoutedKey string // map key of last provider (for tool continuation)
7475
// Set by LoadPersistedOverrides; main.go drains via TakePendingOpenRouterOverrides
@@ -79,6 +80,14 @@ type Router struct {
7980
logger *slog.Logger
8081
}
8182

83+
// SetUsageStore wires the UsageLog sink. Calls before Chat() is invoked take
84+
// effect on the next request; Chat() reads the field under r.mu.
85+
func (r *Router) SetUsageStore(u UsageStore) {
86+
r.mu.Lock()
87+
r.usage = u
88+
r.mu.Unlock()
89+
}
90+
8291
func NewRouter(providers map[string]Provider, cfg RouterConfig) *Router {
8392
return &Router{
8493
providers: providers,
@@ -332,12 +341,16 @@ func (r *Router) SetClassifierMinLen(n int) {
332341

333342
func (r *Router) Chat(ctx context.Context, messages []Message, systemPrompt string, tools []Tool) (Response, error) {
334343
provider := r.pick(ctx, messages)
344+
primaryKey := r.keyFor(provider)
335345
r.mu.Lock()
336346
r.lastRouted = provider.Name()
337-
r.lastRoutedKey = r.keyFor(provider)
347+
r.lastRoutedKey = primaryKey
338348
r.mu.Unlock()
339349

350+
start := time.Now()
340351
resp, err := provider.Chat(ctx, messages, systemPrompt, tools)
352+
r.recordUsage(ctx, provider, primaryKey, resp, err, time.Since(start))
353+
341354
if err != nil && isUnavailable(err) {
342355
// Build fallback chain: override → default → fallback.
343356
// Skip providers already tried or equal to current.
@@ -354,7 +367,9 @@ func (r *Router) Chat(ctx context.Context, messages []Message, systemPrompt stri
354367
if r.OnFallback != nil {
355368
r.OnFallback(provider.Name(), next.Name())
356369
}
370+
fbStart := time.Now()
357371
resp, err = next.Chat(ctx, messages, systemPrompt, tools)
372+
r.recordUsage(ctx, next, "fallback", resp, err, time.Since(fbStart))
358373
if err == nil || !isUnavailable(err) {
359374
break
360375
}
@@ -364,6 +379,59 @@ func (r *Router) Chat(ctx context.Context, messages []Message, systemPrompt stri
364379
return resp, err
365380
}
366381

382+
// recordUsage persists a UsageLog row for one LLM call. Runs best-effort —
383+
// errors are logged but never fail the request. Extracts turn meta from ctx
384+
// when present; falls back to 0s when absent.
385+
func (r *Router) recordUsage(ctx context.Context, p Provider, role string, resp Response, callErr error, latency time.Duration) {
386+
r.mu.RLock()
387+
store := r.usage
388+
r.mu.RUnlock()
389+
if store == nil {
390+
return
391+
}
392+
meta, _ := TurnMetaFrom(ctx)
393+
if meta.RoleHint != "" {
394+
role = meta.RoleHint
395+
}
396+
provKind, modelID := splitProviderName(p.Name())
397+
log := UsageLog{
398+
Provider: provKind,
399+
ModelID: modelID,
400+
Role: role,
401+
ChatID: meta.ChatID,
402+
PromptTokens: resp.Usage.PromptTokens,
403+
CompletionTokens: resp.Usage.CompletionTokens,
404+
CachedPromptTokens: resp.Usage.CachedPromptTokens,
405+
ReasoningTokens: resp.Usage.ReasoningTokens,
406+
LatencyMs: int(latency / time.Millisecond),
407+
Success: callErr == nil,
408+
ErrorClass: ClassifyErrorClass(callErr),
409+
RequestID: resp.Usage.RequestID,
410+
ToolCallCount: len(resp.ToolCalls),
411+
}
412+
if meta.UserMessageID != 0 {
413+
id := meta.UserMessageID
414+
log.UserMessageID = &id
415+
}
416+
// Best-effort write with short timeout — usage logging must never block or
417+
// fail a user request.
418+
writeCtx, cancel := context.WithTimeout(context.Background(), 3*time.Second)
419+
defer cancel()
420+
if _, err := store.PutUsage(writeCtx, log); err != nil {
421+
r.logger.Warn("usage log write failed", "err", err, "provider", provKind, "model", modelID)
422+
}
423+
}
424+
425+
// splitProviderName breaks a "provider/model" Name() into its parts. For
426+
// providers whose Name() does not contain a slash, provider = full name and
427+
// model = "".
428+
func splitProviderName(name string) (provider, model string) {
429+
if i := strings.IndexByte(name, '/'); i >= 0 {
430+
return name[:i], name[i+1:]
431+
}
432+
return name, ""
433+
}
434+
367435
// ChatStream returns a streaming channel if the current provider supports it.
368436
// Falls back to wrapping a synchronous Chat() in a single-chunk channel.
369437
func (r *Router) ChatStream(ctx context.Context, messages []Message, systemPrompt string, tools []Tool) (<-chan StreamChunk, error) {

internal/llm/usage.go

Lines changed: 137 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,137 @@
1+
package llm
2+
3+
import (
4+
"context"
5+
"time"
6+
)
7+
8+
// UsageLog is a billing-grained record of a single LLM call. One record per
9+
// call, independent of the messages table — an agentic loop with N tool
10+
// iterations produces N records, all sharing the same UserMessageID.
11+
//
12+
// Schema lives in SQLite + Postgres migrations under usage_log.
13+
type UsageLog struct {
14+
ID int64
15+
Ts time.Time
16+
Provider string // "openrouter" / "gemini" / "claude_bridge" / "ollama" / "local"
17+
ModelID string // provider-specific model identifier at call time
18+
Role string // routing role chosen ("simple" / "default" / "complex" / "multimodal" / "compaction" / "classifier" / "fallback" / "override")
19+
ChatID int64
20+
PromptTokens int
21+
CompletionTokens int
22+
CachedPromptTokens int // subset of PromptTokens that hit provider's prompt cache (Anthropic/OpenAI)
23+
ReasoningTokens int // for thinking-enabled models: tokens spent on internal reasoning (billed as completion but semantically distinct)
24+
LatencyMs int
25+
Success bool
26+
ErrorClass string // "" / "rate_limit" / "5xx" / "network" / "timeout" / "other"
27+
RequestID string // provider's request id (e.g. OpenRouter gen-xxxxx) — useful for cross-referencing with provider dashboards
28+
ToolCallCount int // number of tool_calls in the response
29+
UserMessageID *int64 // FK to messages.id; NULL for background tasks (compaction, scheduled jobs)
30+
AssistantMessageID *int64 // FK to messages.id; NULL except on the final successful call of a turn
31+
}
32+
33+
// UsageStore persists UsageLog records and exposes aggregation queries used
34+
// by the admin UI (implemented in Stage A.3).
35+
type UsageStore interface {
36+
PutUsage(ctx context.Context, u UsageLog) (int64, error)
37+
UpdateAssistantMessageID(ctx context.Context, usageID, msgID int64) error
38+
}
39+
40+
// Usage is a per-response token breakdown attached to Response. Providers
41+
// populate it when their API reports counts; zero-value otherwise. Router
42+
// copies these fields into UsageLog.
43+
type Usage struct {
44+
PromptTokens int
45+
CompletionTokens int
46+
CachedPromptTokens int
47+
ReasoningTokens int
48+
RequestID string
49+
}
50+
51+
// TurnMeta carries the conversation-layer identity (chat, user message id,
52+
// role) across layers so Router.Chat can tag UsageLog records without every
53+
// caller having to thread the data through function signatures.
54+
//
55+
// When absent, usage is still logged but with ChatID=0 / UserMessageID=nil.
56+
type TurnMeta struct {
57+
ChatID int64
58+
UserMessageID int64 // 0 = not applicable (compaction, scheduled jobs)
59+
// RoleHint overrides the role that Router would normally record. Used for
60+
// classifier calls (bypass Router.pick, role="classifier") and compaction
61+
// (role="compaction"). Empty = let Router decide.
62+
RoleHint string
63+
}
64+
65+
type turnMetaKey struct{}
66+
67+
// WithTurnMeta returns a context carrying the supplied TurnMeta. Router's
68+
// usage logger reads this via TurnMetaFrom.
69+
func WithTurnMeta(ctx context.Context, m TurnMeta) context.Context {
70+
return context.WithValue(ctx, turnMetaKey{}, m)
71+
}
72+
73+
// TurnMetaFrom retrieves the TurnMeta put into ctx by WithTurnMeta.
74+
func TurnMetaFrom(ctx context.Context) (TurnMeta, bool) {
75+
m, ok := ctx.Value(turnMetaKey{}).(TurnMeta)
76+
return m, ok
77+
}
78+
79+
// ClassifyErrorClass maps an error into a short bucket suitable for usage_log.
80+
// Unknown errors land in "other" so dashboards aren't polluted by one-off
81+
// messages. Returns "" when err is nil.
82+
func ClassifyErrorClass(err error) string {
83+
if err == nil {
84+
return ""
85+
}
86+
var apiErr *APIError
87+
if ok := asAPIError(err, &apiErr); ok {
88+
switch {
89+
case apiErr.StatusCode == 429:
90+
return "rate_limit"
91+
case apiErr.StatusCode >= 500:
92+
return "5xx"
93+
case apiErr.StatusCode >= 400:
94+
return "4xx"
95+
}
96+
}
97+
msg := err.Error()
98+
switch {
99+
case contains(msg, "context deadline exceeded"):
100+
return "timeout"
101+
case contains(msg, "connection refused"), contains(msg, "no such host"), contains(msg, "i/o timeout"), contains(msg, "connection reset"):
102+
return "network"
103+
}
104+
return "other"
105+
}
106+
107+
// small helpers kept here to avoid an extra import of errors/strings in cold
108+
// paths of tests.
109+
func asAPIError(err error, target **APIError) bool {
110+
for e := err; e != nil; {
111+
if a, ok := e.(*APIError); ok {
112+
*target = a
113+
return true
114+
}
115+
type wrapped interface{ Unwrap() error }
116+
if w, ok := e.(wrapped); ok {
117+
e = w.Unwrap()
118+
continue
119+
}
120+
return false
121+
}
122+
return false
123+
}
124+
125+
func contains(s, sub string) bool {
126+
return len(sub) > 0 && len(s) >= len(sub) && indexOf(s, sub) >= 0
127+
}
128+
129+
func indexOf(s, sub string) int {
130+
n, m := len(s), len(sub)
131+
for i := 0; i+m <= n; i++ {
132+
if s[i:i+m] == sub {
133+
return i
134+
}
135+
}
136+
return -1
137+
}

0 commit comments

Comments
 (0)