From 5212adab2234ed5b4bd4f1412873a31726dca745 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?An=C4=B1l=20G=C3=BClero=C4=9Flu?= Date: Tue, 18 Aug 2026 16:54:29 +0300 Subject: [PATCH] Promote finishReason/reasoningTokens to first-class trace + Model Hub fields MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit They used to ride inside each event's `metadata` JSON blob, invisible to projections, queries and the UI. Both are now real columns/fields across every write path (external HTTP + OTLP ingest, the internal agent sink, and the Model Hub gateway), every read path (session/event APIs, the tracing UI, the Model Hub logs UI), and the usage_daily rollup. reasoningTokens is always a SUBSET of outputTokens — never billed or summed on top of it. A shared src/lib/shared/finishReason.ts normalizes and classifies provider values (stop/length/tool_calls/...) consistently across server and client code. Old rows fall back to their metadata location until scripts/backfill-trace-fields.ts is run, which also adds the updateAgentTracingEvent DB primitive needed to migrate them in place. Co-Authored-By: Claude Opus 5 (1M context) --- docs/api/tracing.md | 9 + docs/guide/observability/data-model.md | 10 + docs/public/openapi.yaml | 16 + package.json | 1 + scripts/backfill-trace-fields.ts | 430 ++++++++++++++++++ .../tracing-accumulation-parity.test.ts | 114 +++++ src/__tests__/unit/agent-tracing.test.ts | 185 ++++++++ src/__tests__/unit/inference-service.test.ts | 99 ++++ .../unit/internal-trace-metadata.test.ts | 173 +++++-- src/__tests__/unit/openai-adapter.test.ts | 128 ++++++ .../unit/otlp-semconv-mapping.test.ts | 83 ++++ src/app/dashboard/models/[id]/page.tsx | 52 +++ .../tracing/sessions/[sessionId]/page.tsx | 102 ++++- src/lib/database/mongodb/tracing.mixin.ts | 56 +++ src/lib/database/mongodb/usage.mixin.ts | 1 + src/lib/database/provider/contract.ts | 14 + src/lib/database/provider/types.base.ts | 30 ++ src/lib/database/sqlite/base.ts | 13 + src/lib/database/sqlite/model.mixin.ts | 8 +- src/lib/database/sqlite/schema.ts | 7 + src/lib/database/sqlite/tracing.mixin.ts | 59 ++- src/lib/database/sqlite/usage.mixin.ts | 7 +- src/lib/i18n/messages/en.ts | 5 + src/lib/i18n/messages/tr.ts | 14 + src/lib/services/agentTracing.ts | 57 +++ src/lib/services/agents/agentService.ts | 102 +++-- src/lib/services/models/inferenceService.ts | 7 + src/lib/services/models/openaiAdapter.ts | 37 ++ src/lib/services/models/usageLogger.ts | 16 + src/lib/services/otlpMapper.ts | 49 ++ src/lib/services/usage/usageEvents.ts | 4 + src/lib/services/usage/usageRollup.ts | Bin 7486 -> 7860 bytes src/lib/shared/finishReason.ts | 68 +++ src/server/api/plugins/client-tracing.ts | 125 ++++- src/server/api/plugins/tracing.ts | 3 + .../api/routes/client/v1/traces/route.ts | 16 + 36 files changed, 1992 insertions(+), 108 deletions(-) create mode 100644 scripts/backfill-trace-fields.ts create mode 100644 src/lib/shared/finishReason.ts diff --git a/docs/api/tracing.md b/docs/api/tracing.md index 754f7deb..49eb5ebb 100644 --- a/docs/api/tracing.md +++ b/docs/api/tracing.md @@ -323,6 +323,15 @@ Two fields depend on what the producer recorded: | `parentSpanId` | Event | Parent span identifier (for hierarchy) | | `source` | Session | Ingestion source: `custom` or `otlp` | +## Token & Finish Reason Fields + +| Field | Scope | Description | +|------|-------|-------------| +| `reasoningTokens` | Event | Reasoning/thinking tokens the model spent before its answer (e.g. OpenAI's `completion_tokens_details.reasoning_tokens`). A **subset** of `outputTokens` — never billed on top of it. | +| `finishReason` | Event | Normalized (trim + lowercase) raw provider stop reason — `stop`, `length`, `tool_calls`, etc. | +| `totalReasoningTokens` | Session | Running total of the session's event `reasoningTokens`. Already counted within `totalOutputTokens` — never add it again in cost math. | +| `truncatedEvents` | Session | Count of events whose `finishReason` signalled a token/length cutoff (`length`, `max_tokens`, …) rather than the model stopping on its own terms. | + ## Event Types Console aggregates per type, so producers should use these names rather than diff --git a/docs/guide/observability/data-model.md b/docs/guide/observability/data-model.md index 6b1cf240..1d3d0f6e 100644 --- a/docs/guide/observability/data-model.md +++ b/docs/guide/observability/data-model.md @@ -35,6 +35,8 @@ tying them together. | `startedAt` / `endedAt` | ISO 8601 | | | `durationMs` | number | | | `summary` | totals | `totalInputTokens`, `totalOutputTokens`, `totalCachedInputTokens`, `totalDurationMs`, `eventCounts` | +| `totalReasoningTokens` | number | Running total of the session's event `reasoningTokens`. Already counted within `totalOutputTokens` — see [Tokens](#tokens) — never add it again in cost math. | +| `truncatedEvents` | number | Count of events whose `finishReason` signalled a token/length cutoff (`length`, `max_tokens`, …) rather than the model stopping on its own terms. | | `config` | object | Free-form run configuration, shown on the session header. | | `errors` | array | A non-empty list marks the session failed. | @@ -74,6 +76,8 @@ Console aggregates per type, so use these rather than inventing names: | `error` | string or object | Attached to a failed step. | | `model` | string | **The provider's model id** (`gpt-4.1-mini`), not a nickname — see [Cost](#cost-and-double-counting). | | `inputTokens` / `outputTokens` / `cachedInputTokens` / `totalTokens` | number | See [Tokens](#tokens). | +| `reasoningTokens` | number | Reasoning/thinking tokens the model spent before its answer (e.g. OpenAI's `completion_tokens_details.reasoning_tokens`). A **subset** of `outputTokens` — see [Tokens](#tokens) — never billed on top of it. | +| `finishReason` | string | Normalized (trim + lowercase) raw provider stop reason — `stop`, `length`, `tool_calls`, etc. Feeds the session's `truncatedEvents` count. | | `toolName` / `toolExecutionId` | string | `toolExecutionId` correlates the run with the model's tool-call id. | | `toolDefinitions` | array | The tool menu offered on this call. See below. | | `actor` | `{scope, name}` | `scope` is `agent`, `model`, `tool`, `retriever` or `user`; drives the actor column. | @@ -150,6 +154,12 @@ inputTokens = input_tokens + cache_read_input_tokens + cache_creation_inpu cachedInputTokens = cache_read_input_tokens ``` +`reasoningTokens` is also a **subset** — of `outputTokens`, not `inputTokens` — +covering the model's internal reasoning/thinking tokens. It is never added on +top of `outputTokens` or `totalTokens` in cost math; it exists so the +reasoning/answer split is visible without double-billing it. The session's +`totalReasoningTokens` is the running sum of the field across its events. + ::: warning Absent is not zero When a framework reports no usage — a streaming call without usage opt-in, a cancelled run — the fields are **omitted**. A zero would silently under-report diff --git a/docs/public/openapi.yaml b/docs/public/openapi.yaml index 2d2f017f..d3518a6a 100644 --- a/docs/public/openapi.yaml +++ b/docs/public/openapi.yaml @@ -19786,6 +19786,14 @@ components: totalTokens: type: integer nullable: true + reasoningTokens: + type: integer + nullable: true + description: Reasoning/thinking tokens spent by this event's model call. A subset of outputTokens — never billed, or summed into totalTokens, on top of it. + finishReason: + type: string + nullable: true + description: "Raw provider finish reason for this event's model call, e.g. stop, length, tool_calls." durationMs: type: integer description: Event duration in milliseconds. @@ -20022,6 +20030,14 @@ components: totalCachedInputTokens: type: integer nullable: true + totalReasoningTokens: + type: integer + nullable: true + description: Sum of reasoningTokens across the session's events. A subset of totalOutputTokens — never billed, or summed into a token total, on top of it. + truncatedEvents: + type: integer + nullable: true + description: "Count of events whose finishReason indicates a token/length cutoff (e.g. length, max_tokens) rather than a normal stop." totalBytesIn: type: integer nullable: true diff --git a/package.json b/package.json index f7ea7acb..61c52bad 100644 --- a/package.json +++ b/package.json @@ -22,6 +22,7 @@ "seed:beta-codes": "node --import tsx scripts/seed-beta-codes.ts", "backfill:usage-daily": "node --import tsx scripts/backfill-usage-daily.ts", "backfill:trace-usage": "node --import tsx scripts/backfill-trace-usage.ts", + "backfill:trace-fields": "node --import tsx scripts/backfill-trace-fields.ts", "docs:dev": "vitepress dev docs", "docs:build": "vitepress build docs", "docs:preview": "vitepress preview docs" diff --git a/scripts/backfill-trace-fields.ts b/scripts/backfill-trace-fields.ts new file mode 100644 index 00000000..e81cf3e5 --- /dev/null +++ b/scripts/backfill-trace-fields.ts @@ -0,0 +1,430 @@ +/** + * Backfill `finishReason` / `reasoningTokens` from legacy `metadata` JSON + * into their first-class columns on already-stored tracing data. + * + * `IAgentTracingEvent.finishReason` / `.reasoningTokens` used to live only + * inside each event's free-form `metadata` blob (under a handful of + * provider-specific key spellings). They are now persisted columns + * (`agent_tracing_events.finishReason` / `.reasoningTokens`), populated by + * ingest going forward. Events written BEFORE that change still carry the + * value only in `metadata` — this script moves it into the column and + * strips the now-redundant metadata key(s), then recomputes the owning + * session's `totalReasoningTokens` / `truncatedEvents` roll-ups from the + * corrected events. + * + * Recognized legacy metadata keys (checked in this order, first match + * wins): `finishReason`, `finish_reason`, `stop_reason`, `finishReasons` + * (array or comma-separated string — first entry is used). The value is run + * through `normalizeFinishReason` before being persisted, same as ingest. + * `metadata.reasoningTokens` is migrated only when it is a finite number > 0 + * (a stored 0/negative/non-numeric value is left alone — nothing meaningful + * to move). + * + * Tracing events are otherwise write-once — ingest creates them and nothing + * else mutates them — so per-event writes here go through the narrow, + * migration-only `DatabaseProvider.updateAgentTracingEvent` primitive, which + * accepts only `finishReason` / `reasoningTokens` / `metadata`. Session-level + * `totalReasoningTokens` / `truncatedEvents` roll-ups are recomputed through + * the existing `updateAgentTracingSession`. + * + * IDEMPOTENT: an event is only ever touched when its column is still empty + * AND a legacy metadata key still carries a value — once migrated (or once + * there was nothing to migrate), re-running finds nothing to do. Session + * totals are recomputed (not incremented), so re-running is a no-op once + * correct. + * + * Usage: + * npm run backfill:trace-fields # all tenants + * npm run backfill:trace-fields -- --tenant kamilco1 + * npm run backfill:trace-fields -- --from 2026-01-01 --to 2026-06-30 + * npm run backfill:trace-fields -- --dry-run # report only + * npm run backfill:trace-fields -- --tenant acme --sleep-ms 250 # Cosmos-friendly + */ +import { loadEnvConfig } from '@next/env'; + +// Config is read at import time — load env BEFORE any '@/'-aliased import. +loadEnvConfig(process.cwd(), process.env.NODE_ENV !== 'production'); + +import { isTruncatedFinishReason, normalizeFinishReason } from '../src/lib/shared/finishReason'; +import type { IAgentTracingEvent, IAgentTracingSession } from '../src/lib/database'; + +const SESSION_PAGE_SIZE = 100; +const EVENT_FETCH_CONCURRENCY = 2; + +/** Retry transient Cosmos/Mongo errors (killed cursors, hiccups) with backoff. */ +async function withRetry(label: string, fn: () => Promise): Promise { + let lastError: unknown; + for (let attempt = 1; attempt <= 4; attempt += 1) { + try { + return await fn(); + } catch (error) { + lastError = error; + console.warn(` retry ${attempt}/4 after error in ${label}: ${error instanceof Error ? error.message : error}`); + await new Promise((resolve) => setTimeout(resolve, attempt * 1500)); + } + } + throw lastError; +} + +interface CliArgs { + from?: string; + to?: string; + tenant?: string; + dryRun: boolean; + sleepMs: number; +} + +const DAY_RE = /^\d{4}-\d{2}-\d{2}$/; + +function parseArgs(argv: string[]): CliArgs { + const args: CliArgs = { dryRun: false, sleepMs: 0 }; + for (let i = 0; i < argv.length; i += 1) { + const arg = argv[i]; + if (arg === '--from' || arg === '--to') { + const value = argv[i + 1] ?? ''; + if (!DAY_RE.test(value)) throw new Error(`${arg} expects a UTC day: YYYY-MM-DD`); + if (arg === '--from') args.from = value; + else args.to = value; + i += 1; + } else if (arg === '--tenant') { + args.tenant = argv[i + 1]; + if (!args.tenant) throw new Error('--tenant expects a tenant slug or dbName'); + i += 1; + } else if (arg === '--sleep-ms') { + args.sleepMs = Number.parseInt(argv[i + 1] ?? '', 10); + if (!Number.isFinite(args.sleepMs) || args.sleepMs < 0) { + throw new Error('--sleep-ms expects a non-negative integer'); + } + i += 1; + } else if (arg === '--dry-run') { + args.dryRun = true; + } else if (arg === '--help' || arg === '-h') { + printHelp(); + process.exit(0); + } else { + throw new Error(`Unknown option: ${arg}`); + } + } + return args; +} + +function printHelp(): void { + console.log(`Backfill finishReason/reasoningTokens from tracing event metadata into their columns. + +Usage: + npm run backfill:trace-fields -- [options] + +Options: + --tenant Only this tenant (default: all tenants) + --from Only sessions started on/after this UTC day + --to Only sessions started on/before this UTC day + --sleep-ms Pause between session pages (Cosmos-friendly) + --dry-run Report what would change; write nothing + --help Show this help +`); +} + +function sleep(ms: number): Promise { + return ms > 0 ? new Promise((resolve) => setTimeout(resolve, ms)) : Promise.resolve(); +} + +// Legacy metadata key spellings, checked in this priority order. +const FINISH_REASON_KEYS = ['finishReason', 'finish_reason', 'stop_reason', 'finishReasons'] as const; +const REASONING_TOKENS_KEY = 'reasoningTokens'; + +function firstStringFromFinishReasons(raw: unknown): string | undefined { + if (Array.isArray(raw)) { + const first = raw.find((v) => typeof v === 'string' && v.trim().length > 0); + return typeof first === 'string' ? first : undefined; + } + if (typeof raw === 'string' && raw.trim().length > 0) { + return raw.split(',')[0]?.trim(); + } + return undefined; +} + +interface EventPatch { + finishReason?: string; + reasoningTokens?: number; + metadata: Record; + removedKeys: string[]; +} + +/** + * Computes the column values an event's metadata implies, if its columns + * are still empty. Returns `null` when there is nothing to migrate. + */ +function computeEventPatch(event: IAgentTracingEvent): EventPatch | null { + const metadata = event.metadata ?? {}; + const nextMetadata: Record = { ...metadata }; + const removedKeys: string[] = []; + let finishReason: string | undefined; + let reasoningTokens: number | undefined; + + if (!event.finishReason) { + for (const key of FINISH_REASON_KEYS) { + if (!(key in metadata)) continue; + const raw = metadata[key]; + const candidate = key === 'finishReasons' ? firstStringFromFinishReasons(raw) + : (typeof raw === 'string' ? raw : undefined); + const normalized = normalizeFinishReason(candidate); + if (normalized) { + finishReason = normalized; + break; + } + } + if (finishReason) { + for (const key of FINISH_REASON_KEYS) { + if (key in nextMetadata) { + delete nextMetadata[key]; + removedKeys.push(key); + } + } + } + } + + if (event.reasoningTokens === undefined && REASONING_TOKENS_KEY in metadata) { + const num = Number(metadata[REASONING_TOKENS_KEY]); + if (Number.isFinite(num) && num > 0) { + reasoningTokens = num; + delete nextMetadata[REASONING_TOKENS_KEY]; + removedKeys.push(REASONING_TOKENS_KEY); + } + } + + if (finishReason === undefined && reasoningTokens === undefined) return null; + return { finishReason, reasoningTokens, metadata: nextMetadata, removedKeys }; +} + +/** The value a session-totals recompute should use for this event, whether + * or not the column write for a pending patch actually happened. */ +function effectiveFields(event: IAgentTracingEvent, patch: EventPatch | null): { + finishReason?: string; + reasoningTokens: number; +} { + const finishReason = event.finishReason ?? patch?.finishReason; + const reasoningTokensRaw = event.reasoningTokens ?? patch?.reasoningTokens ?? 0; + const reasoningTokens = Number.isFinite(reasoningTokensRaw) && reasoningTokensRaw > 0 ? reasoningTokensRaw : 0; + return { finishReason, reasoningTokens }; +} + +interface TenantStats { + sessionsScanned: number; + eventsScanned: number; + finishReasonFound: number; + finishReasonWritten: number; + reasoningTokensFound: number; + reasoningTokensWritten: number; + sessionsRecomputed: number; + failedSessions: number; +} + +function emptyStats(): TenantStats { + return { + sessionsScanned: 0, + eventsScanned: 0, + finishReasonFound: 0, + finishReasonWritten: 0, + reasoningTokensFound: 0, + reasoningTokensWritten: 0, + sessionsRecomputed: 0, + failedSessions: 0, + }; +} + +async function main(): Promise { + const args = parseArgs(process.argv.slice(2)); + + const { getDatabase, disconnectDatabase } = await import('../src/lib/database'); + const db = await getDatabase(); + + try { + let tenants = await db.listTenants(); + if (args.tenant) { + tenants = tenants.filter( + (tenant) => tenant.slug === args.tenant || tenant.dbName === args.tenant, + ); + if (tenants.length === 0) { + console.error(`No tenant matched --tenant ${args.tenant}`); + return 1; + } + } + + console.log( + `Backfilling trace fields (finishReason/reasoningTokens) for ${tenants.length} tenant(s), ` + + `range ${args.from ?? '(beginning)'} .. ${args.to ?? '(now)'}` + + `${args.dryRun ? ' [dry-run]' : ''}\n`, + ); + + const grandStats = emptyStats(); + + for (const tenant of tenants) { + const label = `${tenant.slug} (${tenant.dbName})`; + console.log(`── Tenant ${label}`); + + const run = async () => { + const stats = emptyStats(); + let skip = 0; + + for (;;) { + const { sessions } = await withRetry(`sessions(skip=${skip})`, () => + db.listAgentTracingSessions({ + limit: SESSION_PAGE_SIZE, + skip, + from: args.from, + to: args.to, + projection: { + sessionId: 1, + projectId: 1, + agentName: 1, + startedAt: 1, + totalReasoningTokens: 1, + truncatedEvents: 1, + }, + }), + ); + if (sessions.length === 0) break; + skip += sessions.length; + + for (let i = 0; i < sessions.length; i += EVENT_FETCH_CONCURRENCY) { + await Promise.all( + sessions.slice(i, i + EVENT_FETCH_CONCURRENCY).map((session) => + processSession(session, { + db, + dryRun: args.dryRun, + stats, + }).catch((error) => { + stats.failedSessions += 1; + console.warn( + ` ! skipping session ${session.sessionId} (${error instanceof Error ? error.message : error})`, + ); + }), + ), + ); + } + + await sleep(args.sleepMs); + + if (stats.sessionsScanned % 1000 < SESSION_PAGE_SIZE) { + console.log(` … ${stats.sessionsScanned} sessions scanned (${stats.eventsScanned} events read)`); + } + } + + console.log( + ` sessions ${stats.sessionsScanned}${stats.failedSessions > 0 ? ` (${stats.failedSessions} skipped-unreadable)` : ''}, ` + + `events ${stats.eventsScanned}`, + ); + console.log( + ` finishReason: ${stats.finishReasonFound} found in metadata, ` + + `${stats.finishReasonWritten} written to column`, + ); + console.log( + ` reasoningTokens: ${stats.reasoningTokensFound} found in metadata, ` + + `${stats.reasoningTokensWritten} written to column`, + ); + console.log( + ` sessions recomputed (totalReasoningTokens/truncatedEvents): ${stats.sessionsRecomputed}` + + `${args.dryRun ? ' (dry-run: 0 by definition)' : ''}`, + ); + + grandStats.sessionsScanned += stats.sessionsScanned; + grandStats.eventsScanned += stats.eventsScanned; + grandStats.finishReasonFound += stats.finishReasonFound; + grandStats.finishReasonWritten += stats.finishReasonWritten; + grandStats.reasoningTokensFound += stats.reasoningTokensFound; + grandStats.reasoningTokensWritten += stats.reasoningTokensWritten; + grandStats.sessionsRecomputed += stats.sessionsRecomputed; + grandStats.failedSessions += stats.failedSessions; + }; + + if (typeof db.runWithTenant === 'function') { + await db.runWithTenant(tenant.dbName, run); + } else { + await db.switchToTenant(tenant.dbName); + await run(); + } + console.log(''); + } + + console.log( + `Done. ${grandStats.finishReasonWritten} finishReason + ${grandStats.reasoningTokensWritten} reasoningTokens ` + + `column write(s), ${grandStats.sessionsRecomputed} session(s) recomputed` + + `${args.dryRun ? ' (dry-run: 0 writes by definition)' : ''}.`, + ); + return 0; + } finally { + await disconnectDatabase().catch(() => undefined); + } +} + +async function processSession( + session: Pick, + ctx: { + db: Awaited>; + dryRun: boolean; + stats: TenantStats; + }, +): Promise { + const { db, dryRun, stats } = ctx; + stats.sessionsScanned += 1; + + const events = await withRetry(`events(${session.sessionId})`, () => + db.listAgentTracingEvents(session.sessionId, session.projectId), + ); + + let totalReasoningTokens = 0; + let truncatedEvents = 0; + let sessionChanged = false; + + for (const event of events) { + stats.eventsScanned += 1; + const patch = computeEventPatch(event); + + if (patch) { + if (patch.finishReason !== undefined) stats.finishReasonFound += 1; + if (patch.reasoningTokens !== undefined) stats.reasoningTokensFound += 1; + sessionChanged = true; + + if (!dryRun) { + const eventId = event.id ?? String(event._id); + const data: Partial> = { + metadata: patch.metadata, + }; + if (patch.finishReason !== undefined) data.finishReason = patch.finishReason; + if (patch.reasoningTokens !== undefined) data.reasoningTokens = patch.reasoningTokens; + await db.updateAgentTracingEvent(session.sessionId, eventId, data, session.projectId); + if (patch.finishReason !== undefined) stats.finishReasonWritten += 1; + if (patch.reasoningTokens !== undefined) stats.reasoningTokensWritten += 1; + } + } + + const { finishReason, reasoningTokens } = effectiveFields(event, patch); + totalReasoningTokens += reasoningTokens; + if (isTruncatedFinishReason(normalizeFinishReason(finishReason))) truncatedEvents += 1; + } + + const totalsChanged = + (session.totalReasoningTokens ?? 0) !== totalReasoningTokens + || (session.truncatedEvents ?? 0) !== truncatedEvents; + + // Recompute only sessions whose events actually needed migrating, or whose + // stored roll-ups already disagree with what their events imply — not + // every session in the tenant (those are already correct from ingest). + if ((sessionChanged || totalsChanged) && !dryRun) { + await db.updateAgentTracingSession( + session.sessionId, + { totalReasoningTokens, truncatedEvents }, + session.projectId, + ); + stats.sessionsRecomputed += 1; + } else if ((sessionChanged || totalsChanged) && dryRun) { + stats.sessionsRecomputed += 1; + } +} + +main() + .then((code) => process.exit(code)) + .catch((error) => { + console.error(error); + process.exit(1); + }); diff --git a/src/__tests__/integration/tracing-accumulation-parity.test.ts b/src/__tests__/integration/tracing-accumulation-parity.test.ts index 225ffb94..4c39ef9e 100644 --- a/src/__tests__/integration/tracing-accumulation-parity.test.ts +++ b/src/__tests__/integration/tracing-accumulation-parity.test.ts @@ -74,10 +74,12 @@ describeForEachProvider('Agent tracing session accumulation', (getDb) => { await db.applyAgentTracingSessionEvent(seed.sessionId, { inputTokens: 60, outputTokens: 40, cachedInputTokens: 10, durationMs: 700, + reasoningTokens: 15, finishReason: 'stop', eventType: 'ai_call', modelsUsed: ['gpt-5.4'], }, seed.projectId); await db.applyAgentTracingSessionEvent(seed.sessionId, { inputTokens: 200, outputTokens: 100, cachedInputTokens: 0, durationMs: 500, + reasoningTokens: 25, finishReason: 'length', eventType: 'ai_call', modelsUsed: ['gpt-5.4'], toolsUsed: ['search'], }, seed.projectId); @@ -85,12 +87,42 @@ describeForEachProvider('Agent tracing session accumulation', (getDb) => { expect(session?.totalInputTokens).toBe(260); expect(session?.totalOutputTokens).toBe(140); expect(session?.totalCachedInputTokens).toBe(10); + expect(session?.totalReasoningTokens).toBe(40); + expect(session?.truncatedEvents).toBe(1); expect(session?.totalEvents).toBe(2); expect(session?.eventCounts).toEqual({ ai_call: 2 }); expect(session?.modelsUsed).toEqual(['gpt-5.4']); expect(session?.toolsUsed).toEqual(['search']); }); + it('accumulates reasoningTokens and truncatedEvents identically across multiple event cycles', async () => { + const db = getDb(); + // eslint-disable-next-line @typescript-eslint/no-explicit-any + await db.createAgentTracingSession(seedDoc(seed) as any); + + // Mixes normal completions (stop/tool_calls) with token-limit cutoffs + // (length/max_tokens) — only the latter should bump truncatedEvents, and + // reasoningTokens must keep accumulating even on events that reported none. + const cycles: Array<{ reasoningTokens?: number; finishReason?: string }> = [ + { reasoningTokens: 20, finishReason: 'stop' }, + { reasoningTokens: 30, finishReason: 'length' }, + { reasoningTokens: 10, finishReason: 'max_tokens' }, + { finishReason: 'tool_calls' }, + { reasoningTokens: 5 }, // no finishReason reported this cycle + ]; + + for (const cycle of cycles) { + await db.applyAgentTracingSessionEvent(seed.sessionId, { + inputTokens: 100, outputTokens: 50, eventType: 'ai_call', ...cycle, + }, seed.projectId); + } + + const session = await db.findAgentTracingSessionById(seed.sessionId, seed.projectId); + expect(session?.totalReasoningTokens).toBe(65); + expect(session?.truncatedEvents).toBe(2); + expect(session?.totalEvents).toBe(5); + }); + it('keeps the summary equal to the denormalized columns', async () => { const db = getDb(); // eslint-disable-next-line @typescript-eslint/no-explicit-any @@ -173,3 +205,85 @@ describeForEachProvider('Agent tracing session accumulation', (getDb) => { expect(session?.totalOutputTokens).toBe(40); }); }); + +describeForEachProvider('Agent tracing event update (migration primitive)', (getDb) => { + let seed: SessionSeed; + + beforeEach(async () => { + const unique = `${Date.now()}-${Math.random().toString(36).slice(2, 8)}`; + const db = getDb(); + const slug = `tracing-evt-${unique}`; + const dbName = `tenant_${slug}`; + const tenant = await db.createTenant({ + companyName: 'Tracing Event', + slug, + dbName, + licenseType: 'FREE', + ownerId: 'pending', + }); + await db.switchToTenant(dbName); + seed = { sessionId: `sess-${unique}`, projectId: `proj-${unique}`, tenantId: String(tenant._id) }; + }); + + it('moves legacy metadata values into the columns and strips the consumed keys', async () => { + const db = getDb(); + const eventId = `evt-${seed.sessionId}`; + + await db.createAgentTracingEvent({ + sessionId: seed.sessionId, + tenantId: seed.tenantId, + projectId: seed.projectId, + id: eventId, + type: 'ai_call', + metadata: { finishReason: 'stop', reasoningTokens: 42, keep: 'me' }, + }); + + const updated = await db.updateAgentTracingEvent( + seed.sessionId, + eventId, + { finishReason: 'stop', reasoningTokens: 42, metadata: { keep: 'me' } }, + seed.projectId, + ); + + expect(updated?.finishReason).toBe('stop'); + expect(updated?.reasoningTokens).toBe(42); + expect(updated?.metadata).toEqual({ keep: 'me' }); + + // Read back through the normal find path — must match what the update + // call itself returned, on both providers. + const reread = await db.findAgentTracingEventById(seed.sessionId, eventId, seed.projectId); + expect(reread?.finishReason).toBe('stop'); + expect(reread?.reasoningTokens).toBe(42); + expect(reread?.metadata).toEqual({ keep: 'me' }); + }); + + it('returns null when the sessionId or eventId does not match', async () => { + const db = getDb(); + const eventId = `evt-${seed.sessionId}`; + + await db.createAgentTracingEvent({ + sessionId: seed.sessionId, + tenantId: seed.tenantId, + projectId: seed.projectId, + id: eventId, + type: 'ai_call', + metadata: {}, + }); + + const wrongSession = await db.updateAgentTracingEvent( + `${seed.sessionId}-does-not-exist`, + eventId, + { finishReason: 'stop' }, + seed.projectId, + ); + expect(wrongSession).toBeNull(); + + const wrongEvent = await db.updateAgentTracingEvent( + seed.sessionId, + 'evt-does-not-exist', + { finishReason: 'stop' }, + seed.projectId, + ); + expect(wrongEvent).toBeNull(); + }); +}); diff --git a/src/__tests__/unit/agent-tracing.test.ts b/src/__tests__/unit/agent-tracing.test.ts index 9d2e64a8..2c388f40 100644 --- a/src/__tests__/unit/agent-tracing.test.ts +++ b/src/__tests__/unit/agent-tracing.test.ts @@ -392,6 +392,191 @@ describe('AgentTracingService.getSessionDetail', () => { }); }); +// ── finishReason / reasoningTokens (Phase 3 read path) ────────────────────── + +describe('AgentTracingService — finishReason / reasoningTokens exposure', () => { + let db: ReturnType; + + beforeEach(() => { + vi.clearAllMocks(); + db = createMockDb(); + (getDatabase as ReturnType).mockResolvedValue(db); + }); + + it('exposes first-class finishReason/reasoningTokens on the event DETAIL mapper', async () => { + db.findAgentTracingSessionById.mockResolvedValue(makeSession()); + db.listAgentTracingEvents.mockResolvedValue([ + { + sessionId: SESSION_ID, + tenantId: TENANT_ID, + sequence: 1, + type: 'ai_call', + timestamp: new Date(), + finishReason: 'length', + reasoningTokens: 42, + }, + ]); + + const result = await AgentTracingService.getSessionDetail(TENANT_DB, PROJECT_ID, SESSION_ID); + const event = result!.events[0] as Record; + + expect(event.finishReason).toBe('length'); + expect(event.reasoningTokens).toBe(42); + }); + + it('exposes first-class finishReason/reasoningTokens on the event SUMMARY mapper', async () => { + db.findAgentTracingSessionById.mockResolvedValue(makeSession()); + db.listAgentTracingEvents.mockResolvedValue([ + { + _id: 'event-1', + sessionId: SESSION_ID, + tenantId: TENANT_ID, + sequence: 1, + type: 'ai_call', + timestamp: new Date(), + finishReason: 'stop', + reasoningTokens: 7, + }, + ]); + + const result = await AgentTracingService.getSessionDetail( + TENANT_DB, + PROJECT_ID, + SESSION_ID, + { includeEventContent: false }, + ); + const event = result!.events[0] as Record; + + expect(event.finishReason).toBe('stop'); + expect(event.reasoningTokens).toBe(7); + }); + + it('falls back to legacy metadata.finishReason/metadata.reasoningTokens for pre-migration rows (detail)', async () => { + db.findAgentTracingSessionById.mockResolvedValue(makeSession()); + db.listAgentTracingEvents.mockResolvedValue([ + { + sessionId: SESSION_ID, + tenantId: TENANT_ID, + sequence: 1, + type: 'ai_call', + timestamp: new Date(), + // No first-class finishReason/reasoningTokens columns — legacy row. + metadata: { finishReason: 'STOP ', reasoningTokens: 13 }, + }, + ]); + + const result = await AgentTracingService.getSessionDetail(TENANT_DB, PROJECT_ID, SESSION_ID); + const event = result!.events[0] as Record; + + // Normalized (trim + lowercase) so old un-normalized rows compare equal + // to new ones. + expect(event.finishReason).toBe('stop'); + expect(event.reasoningTokens).toBe(13); + }); + + it('falls back to legacy metadata for pre-migration rows (summary)', async () => { + db.findAgentTracingSessionById.mockResolvedValue(makeSession()); + db.listAgentTracingEvents.mockResolvedValue([ + { + _id: 'event-1', + sessionId: SESSION_ID, + tenantId: TENANT_ID, + sequence: 1, + type: 'ai_call', + timestamp: new Date(), + metadata: { finishReason: 'Length', reasoningTokens: 9 }, + }, + ]); + + const result = await AgentTracingService.getSessionDetail( + TENANT_DB, + PROJECT_ID, + SESSION_ID, + { includeEventContent: false }, + ); + const event = result!.events[0] as Record; + + expect(event.finishReason).toBe('length'); + expect(event.reasoningTokens).toBe(9); + }); + + it('prefers the first-class field over legacy metadata when both are present', async () => { + db.findAgentTracingSessionById.mockResolvedValue(makeSession()); + db.listAgentTracingEvents.mockResolvedValue([ + { + sessionId: SESSION_ID, + tenantId: TENANT_ID, + sequence: 1, + type: 'ai_call', + timestamp: new Date(), + finishReason: 'tool_calls', + reasoningTokens: 5, + metadata: { finishReason: 'stop', reasoningTokens: 999 }, + }, + ]); + + const result = await AgentTracingService.getSessionDetail(TENANT_DB, PROJECT_ID, SESSION_ID); + const event = result!.events[0] as Record; + + expect(event.finishReason).toBe('tool_calls'); + expect(event.reasoningTokens).toBe(5); + }); + + it('leaves finishReason/reasoningTokens undefined when neither source has a value', async () => { + db.findAgentTracingSessionById.mockResolvedValue(makeSession()); + db.listAgentTracingEvents.mockResolvedValue([ + { + sessionId: SESSION_ID, + tenantId: TENANT_ID, + sequence: 1, + type: 'ai_call', + timestamp: new Date(), + }, + ]); + + const result = await AgentTracingService.getSessionDetail(TENANT_DB, PROJECT_ID, SESSION_ID); + const event = result!.events[0] as Record; + + expect(event.finishReason).toBeUndefined(); + expect(event.reasoningTokens).toBeUndefined(); + }); + + it('surfaces session-level totalReasoningTokens/truncatedEvents in getSessionDetail', async () => { + db.findAgentTracingSessionById.mockResolvedValue( + makeSession({ totalReasoningTokens: 123, truncatedEvents: 2 }), + ); + db.listAgentTracingEvents.mockResolvedValue([]); + + const result = await AgentTracingService.getSessionDetail(TENANT_DB, PROJECT_ID, SESSION_ID); + + expect(result!.session.totalReasoningTokens).toBe(123); + expect(result!.session.truncatedEvents).toBe(2); + }); + + it('surfaces session-level totalReasoningTokens/truncatedEvents in listSessions', async () => { + db.listAgentTracingSessions.mockResolvedValue({ + sessions: [makeSession({ totalReasoningTokens: 8, truncatedEvents: 1 })], + total: 1, + }); + + const result = await AgentTracingService.listSessions(TENANT_DB, PROJECT_ID); + + expect(result.sessions[0].totalReasoningTokens).toBe(8); + expect(result.sessions[0].truncatedEvents).toBe(1); + }); + + it('passes the truncated=true filter through to db.listAgentTracingSessions', async () => { + db.listAgentTracingSessions.mockResolvedValue({ sessions: [], total: 0 }); + + await AgentTracingService.listSessions(TENANT_DB, PROJECT_ID, { truncated: true }); + + expect(db.listAgentTracingSessions).toHaveBeenCalledWith( + expect.objectContaining({ truncated: true }), + PROJECT_ID, + ); + }); +}); + // ── getDashboardOverview ───────────────────────────────────────────────────── describe('AgentTracingService.getDashboardOverview', () => { diff --git a/src/__tests__/unit/inference-service.test.ts b/src/__tests__/unit/inference-service.test.ts index 10cf08ed..4021e41f 100644 --- a/src/__tests__/unit/inference-service.test.ts +++ b/src/__tests__/unit/inference-service.test.ts @@ -202,6 +202,47 @@ describe('handleChatCompletion', () => { ); }); + it('forwards finishReason and reasoningTokens to logModelUsage without perturbing totalTokens', async () => { + // reasoningTokens is a SUBSET of outputTokens — it must reach logModelUsage + // as its own field, and totalTokens must stay exactly what summarizeUsage + // reported (inputTokens + outputTokens), never inflated by reasoningTokens. + const model = makeLlmModel(); + const chatRuntime = makeChatRuntime({ + content: 'Hi!', + tool_calls: [], + response_metadata: { finish_reason: 'stop' }, + }); + (getModelByKey as ReturnType).mockResolvedValue(model); + (buildModelRuntime as ReturnType).mockResolvedValue({ + runtime: chatRuntime, + }); + (summarizeUsage as ReturnType).mockReturnValue({ + inputTokens: 10, + outputTokens: 20, + totalTokens: 30, + reasoningTokens: 8, + }); + + await handleChatCompletion({ + ...BASE_PARAMS, + body: { messages: [{ role: 'user', content: 'Hello' }] }, + }); + + expect(logModelUsage).toHaveBeenCalledWith( + 'tenant_acme', + model, + expect.objectContaining({ + finishReason: 'stop', + usage: expect.objectContaining({ + inputTokens: 10, + outputTokens: 20, + totalTokens: 30, + reasoningTokens: 8, + }), + }), + ); + }); + it('passes canonical OpenAI vision content to the provider runnable', async () => { (getModelByKey as ReturnType).mockResolvedValue(makeLlmModel()); const chatModel = { @@ -411,6 +452,64 @@ describe('handleChatCompletion', () => { }); }); + it('logs the terminal finish_reason and reasoningTokens from the final stream usage frame, without perturbing totalTokens', async () => { + // reasoningTokens is a SUBSET of completion_tokens (outputTokens) — it must + // reach logModelUsage as its own field, and totalTokens must stay exactly + // what the final usage frame reported, never inflated by reasoningTokens. + (getModelByKey as ReturnType).mockResolvedValue(makeLlmModel()); + const asyncIterator = (async function* () { + yield { content: 'Hello' }; + })(); + (buildModelRuntime as ReturnType).mockResolvedValue({ + runtime: { + createChatModel: vi.fn().mockResolvedValue({ + invoke: vi.fn(), + stream: vi.fn().mockResolvedValue(asyncIterator), + }), + }, + }); + (toOpenAIStreamChunk as ReturnType).mockReturnValue({ + id: 'chatcmpl-1', + object: 'chat.completion.chunk', + choices: [{ index: 0, delta: { content: 'Hello' }, finish_reason: 'length' }], + usage: { + prompt_tokens: 5, + completion_tokens: 12, + cached_tokens: 0, + total_tokens: 17, + completion_tokens_details: { reasoning_tokens: 9 }, + }, + }); + + const result = await handleChatCompletion({ + ...BASE_PARAMS, + body: { + messages: [], + stream_options: { include_usage: true }, + }, + stream: true, + }); + // Draining the stream runs the fire-and-forget logging call synchronously + // within the stream's `start()`, so it has landed by the time we check. + await new Response(result.stream).text(); + + expect(logModelUsage).toHaveBeenCalledWith( + 'tenant_acme', + expect.anything(), + expect.objectContaining({ + route: 'chat.completions', + status: 'success', + finishReason: 'length', + usage: expect.objectContaining({ + inputTokens: 5, + outputTokens: 12, + totalTokens: 17, + reasoningTokens: 9, + }), + }), + ); + }); + it('never puts usage on a delta when include_usage was not requested', async () => { // OpenAI only emits `usage` when the caller asks for it, and then only on a // trailing choices-less frame. We were attaching it to whichever content diff --git a/src/__tests__/unit/internal-trace-metadata.test.ts b/src/__tests__/unit/internal-trace-metadata.test.ts index f1720463..e513a97f 100644 --- a/src/__tests__/unit/internal-trace-metadata.test.ts +++ b/src/__tests__/unit/internal-trace-metadata.test.ts @@ -8,63 +8,158 @@ * other unless something pins them together — which is exactly what happened * to `finishReason` / `reasoningTokens` when agent-sdk 0.9.3 introduced them. * - * They have no column of their own and ride in `metadata`. These tests assert - * both paths fold them identically, so a session that mixes sources renders - * the same either way. + * They are now first-class columns rather than `metadata` passengers, and each + * path has its own extractor: `extractTraceDiagnostics` (HTTP) and + * `extractInternalTraceDiagnostics` (internal sink). These tests pin the two + * together, so a session that mixes sources renders the same either way. + * + * The HTTP extractor accepts strictly more shapes, because only external SDKs + * send the odd ones (Anthropic's `stop_reason`, the OTel exporter's plural + * `finishReasons`, raw OpenAI usage bags). Those cases are asserted on the HTTP + * side alone and are called out as such. */ import { describe, it, expect } from 'vitest'; -import { buildInternalEventMetadata } from '@/lib/services/agents/agentService'; -type Event = Parameters[0]; +import { extractTraceDiagnostics } from '@/server/api/plugins/client-tracing'; +import { extractInternalTraceDiagnostics } from '@/lib/services/agents/agentService'; + +type AnyEvent = Record; -function event(overrides: Record): Event { - return { type: 'ai_call', ...overrides } as unknown as Event; +/** Run one logical event through BOTH extractors. */ +function both(event: AnyEvent) { + return { + http: extractTraceDiagnostics(event as Parameters[0]), + internal: extractInternalTraceDiagnostics( + event as Parameters[0], + ), + }; } -describe('buildInternalEventMetadata', () => { - it('lifts finishReason off the SDK event into metadata', () => { - expect(buildInternalEventMetadata(event({ finishReason: 'length' }))) - .toEqual({ finishReason: 'length' }); +describe('trace diagnostics extraction — shared shapes', () => { + it('reads the SDK top-level fields identically on both paths', () => { + const { http, internal } = both({ + type: 'ai_call', + finishReason: 'length', + reasoningTokens: 1024, + }); + + expect(http).toEqual({ finishReason: 'length', reasoningTokens: 1024 }); + expect(internal).toEqual(http); + }); + + it('falls back to metadata.finishReason on both paths', () => { + const { http, internal } = both({ + type: 'ai_call', + metadata: { finishReason: 'tool_calls' }, + }); + + expect(http.finishReason).toBe('tool_calls'); + expect(internal.finishReason).toBe('tool_calls'); + }); + + it('falls back to metadata.stop_reason on both paths (Claude Agent SDK vocabulary)', () => { + const { http, internal } = both({ + type: 'ai_call', + metadata: { stop_reason: 'max_tokens' }, + }); + + expect(http.finishReason).toBe('max_tokens'); + expect(internal.finishReason).toBe('max_tokens'); + }); + + it('normalizes casing and whitespace the same way', () => { + const { http, internal } = both({ type: 'ai_call', finishReason: ' LENGTH ' }); + + expect(http.finishReason).toBe('length'); + expect(internal.finishReason).toBe('length'); + }); + + it('drops a finish reason that is not a plausible token', () => { + const { http, internal } = both({ + type: 'ai_call', + finishReason: 'stopped because the user cancelled the request mid-stream, see logs', + }); + + expect(http.finishReason).toBeUndefined(); + expect(internal.finishReason).toBeUndefined(); }); - it('lifts reasoningTokens off the SDK event into metadata', () => { - expect(buildInternalEventMetadata(event({ reasoningTokens: 512 }))) - .toEqual({ reasoningTokens: 512 }); + it('reads reasoning tokens from the usage bag on both paths', () => { + const flat = both({ type: 'ai_call', usage: { reasoningTokens: 512 } }); + expect(flat.http.reasoningTokens).toBe(512); + expect(flat.internal.reasoningTokens).toBe(512); + + const snake = both({ type: 'ai_call', usage: { reasoning_tokens: 512 } }); + expect(snake.http.reasoningTokens).toBe(512); + expect(snake.internal.reasoningTokens).toBe(512); }); - it('reads reasoning tokens out of a usage bag, in either spelling', () => { - expect(buildInternalEventMetadata(event({ usage: { reasoningTokens: 128 } }))) - .toEqual({ reasoningTokens: 128 }); - expect(buildInternalEventMetadata(event({ usage: { reasoning_tokens: 256 } }))) - .toEqual({ reasoningTokens: 256 }); + it('treats a zero or negative reasoning count as "not reported"', () => { + for (const value of [0, -5]) { + const { http, internal } = both({ type: 'ai_call', reasoningTokens: value }); + expect(http.reasoningTokens).toBeUndefined(); + expect(internal.reasoningTokens).toBeUndefined(); + } }); - it('keeps whatever metadata the event already carried', () => { - const metadata = buildInternalEventMetadata( - event({ metadata: { toolDetails: { name: 'search' } }, finishReason: 'stop' }), - ); - expect(metadata).toEqual({ toolDetails: { name: 'search' }, finishReason: 'stop' }); + it('ignores a non-numeric reasoning count instead of persisting NaN', () => { + const { http, internal } = both({ type: 'ai_call', reasoningTokens: 'lots' }); + + expect(http.reasoningTokens).toBeUndefined(); + expect(internal.reasoningTokens).toBeUndefined(); + }); + + it('returns nothing for an event that carries neither field', () => { + const { http, internal } = both({ type: 'tool_call', toolName: 'search' }); + + expect(http).toEqual({ finishReason: undefined, reasoningTokens: undefined }); + expect(internal).toEqual(http); + }); + + it('prefers the top-level field over the metadata fallback on both paths', () => { + const { http, internal } = both({ + type: 'ai_call', + finishReason: 'stop', + reasoningTokens: 10, + metadata: { finishReason: 'length', reasoningTokens: 999 }, + }); + + expect(http).toEqual({ finishReason: 'stop', reasoningTokens: 10 }); + expect(internal).toEqual(http); + }); +}); + +describe('trace diagnostics extraction — HTTP-only producer shapes', () => { + it('takes the first entry of the OTel exporter\'s plural finishReasons array', () => { + expect( + extractTraceDiagnostics({ + metadata: { finishReasons: ['content_filter', 'stop'] }, + } as Parameters[0]).finishReason, + ).toBe('content_filter'); }); - it('does not overwrite a finishReason already in metadata with nothing', () => { - expect(buildInternalEventMetadata(event({ metadata: { finishReason: 'stop' } }))) - .toEqual({ finishReason: 'stop' }); + it('takes the first entry when finishReasons arrives comma-joined', () => { + expect( + extractTraceDiagnostics({ + metadata: { finishReasons: 'length,stop' }, + } as Parameters[0]).finishReason, + ).toBe('length'); }); - it('omits both fields when the model reported neither', () => { - // Absent must stay absent: "no reasoning tokens" and "the provider said - // nothing" are different facts, and a zero would erase the difference. - expect(buildInternalEventMetadata(event({}))).toEqual({}); - expect(buildInternalEventMetadata(event({ reasoningTokens: 0 }))).toEqual({}); - expect(buildInternalEventMetadata(event({ finishReason: ' ' }))).toEqual({}); + it('reads reasoning tokens out of a raw OpenAI usage bag', () => { + expect( + extractTraceDiagnostics({ + usage: { completion_tokens_details: { reasoning_tokens: 320 } }, + } as Parameters[0]).reasoningTokens, + ).toBe(320); }); - it('does not copy the event object it was handed', () => { - // The caller reuses the event to build the rest of the document; mutating - // its metadata in place would leak the fold into unrelated fields. - const source = event({ metadata: { a: 1 }, finishReason: 'length' }); - buildInternalEventMetadata(source); - expect((source as unknown as { metadata: Record }).metadata).toEqual({ a: 1 }); + it('reads reasoning tokens out of a Responses-API usage bag', () => { + expect( + extractTraceDiagnostics({ + usage: { output_tokens_details: { reasoning_tokens: 64 } }, + } as Parameters[0]).reasoningTokens, + ).toBe(64); }); }); diff --git a/src/__tests__/unit/openai-adapter.test.ts b/src/__tests__/unit/openai-adapter.test.ts index 4e051606..8906e07c 100644 --- a/src/__tests__/unit/openai-adapter.test.ts +++ b/src/__tests__/unit/openai-adapter.test.ts @@ -13,6 +13,7 @@ import { toOpenAIStreamChunk, summarizeUsage, buildErrorResponse, + extractFinishReason, } from '@/lib/services/models/openaiAdapter'; // ── toLangChainMessages ─────────────────────────────────────────────────────── @@ -530,10 +531,137 @@ describe('summarizeUsage', () => { totalTokens: 1444, promptTokensDetails: { cache_read: 12, cached_tokens: 12 }, completionTokensDetails: { reasoning: 512, reasoning_tokens: 512 }, + reasoningTokens: 512, }); }); }); +// ── summarizeUsage: reasoningTokens ────────────────────────────────────────── +// reasoningTokens is a SUBSET of outputTokens — it must never be folded into +// totalTokens or affect any cost arithmetic downstream. + +describe('summarizeUsage reasoningTokens', () => { + it('extracts reasoningTokens from completion_tokens_details.reasoning_tokens', () => { + const msg = new AIMessage({ + content: '', + response_metadata: { + usage: { + prompt_tokens: 10, + completion_tokens: 20, + total_tokens: 30, + completion_tokens_details: { reasoning_tokens: 8 }, + }, + }, + }); + const usage = summarizeUsage(msg); + expect(usage.reasoningTokens).toBe(8); + }); + + it('extracts reasoningTokens from the `reasoning` alias (output_token_details.reasoning)', () => { + const msg = new AIMessage({ + content: '', + usage_metadata: { + input_tokens: 10, + output_tokens: 20, + total_tokens: 30, + output_token_details: { reasoning: 6 }, + }, + }); + const usage = summarizeUsage(msg); + expect(usage.reasoningTokens).toBe(6); + }); + + it('extracts reasoningTokens from output_tokens_details.reasoning_tokens (Responses API shape)', () => { + const msg = new AIMessage({ + content: '', + response_metadata: { + usage: { + prompt_tokens: 10, + completion_tokens: 20, + total_tokens: 30, + output_tokens_details: { reasoning_tokens: 4 }, + }, + }, + }); + const usage = summarizeUsage(msg); + expect(usage.reasoningTokens).toBe(4); + }); + + it('omits reasoningTokens when not present', () => { + const msg = makeAIMessage('x', { promptTokens: 5, completionTokens: 3 }); + const usage = summarizeUsage(msg); + expect(usage.reasoningTokens).toBeUndefined(); + }); + + it('omits reasoningTokens when reported as 0 (not > 0)', () => { + const msg = new AIMessage({ + content: '', + response_metadata: { + usage: { + prompt_tokens: 10, + completion_tokens: 20, + total_tokens: 30, + completion_tokens_details: { reasoning_tokens: 0 }, + }, + }, + }); + const usage = summarizeUsage(msg); + expect(usage.reasoningTokens).toBeUndefined(); + }); + + it('never folds reasoningTokens into totalTokens or outputTokens', () => { + const msg = new AIMessage({ + content: '', + response_metadata: { + usage: { + prompt_tokens: 10, + completion_tokens: 20, + total_tokens: 30, + completion_tokens_details: { reasoning_tokens: 8 }, + }, + }, + }); + const usage = summarizeUsage(msg); + // reasoning_tokens (8) is a subset of completion_tokens (20), not an + // addend — outputTokens/totalTokens must reflect only the raw counts. + expect(usage.outputTokens).toBe(20); + expect(usage.totalTokens).toBe(30); + }); +}); + +// ── extractFinishReason ─────────────────────────────────────────────────────── + +describe('extractFinishReason', () => { + it('reads and normalizes response_metadata.finish_reason', () => { + const msg = new AIMessage({ + content: 'x', + response_metadata: { finish_reason: 'STOP' }, + }); + expect(extractFinishReason(msg)).toBe('stop'); + }); + + it('falls back to response_metadata.finishReason', () => { + const msg = new AIMessage({ + content: 'x', + response_metadata: { finishReason: 'length' }, + }); + expect(extractFinishReason(msg)).toBe('length'); + }); + + it('returns undefined when no finish reason is present', () => { + const msg = new AIMessage({ content: 'x' }); + expect(extractFinishReason(msg)).toBeUndefined(); + }); + + it('returns undefined for a non-string finish_reason', () => { + const msg = new AIMessage({ + content: 'x', + response_metadata: { finish_reason: 42 }, + }); + expect(extractFinishReason(msg)).toBeUndefined(); + }); +}); + // ── buildErrorResponse ──────────────────────────────────────────────────────── describe('buildErrorResponse', () => { diff --git a/src/__tests__/unit/otlp-semconv-mapping.test.ts b/src/__tests__/unit/otlp-semconv-mapping.test.ts index 42b959a8..43a22ea4 100644 --- a/src/__tests__/unit/otlp-semconv-mapping.test.ts +++ b/src/__tests__/unit/otlp-semconv-mapping.test.ts @@ -294,3 +294,86 @@ describe('convention edge cases', () => { expect(event.cachedInputTokens).toBeUndefined(); }); }); + +describe('reasoningTokens across conventions', () => { + it('reads cognipeer.tokens.reasoning', () => { + const { event } = mapChild([int('cognipeer.tokens.reasoning', 512)]); + expect(event.reasoningTokens).toBe(512); + }); + + it('reads llm.token_count.completion_details.reasoning (OpenInference)', () => { + const { event } = mapChild([int('llm.token_count.completion_details.reasoning', 256)]); + expect(event.reasoningTokens).toBe(256); + }); + + it('reads gen_ai.usage.reasoning_tokens (OTel GenAI semconv)', () => { + const { event } = mapChild([int('gen_ai.usage.reasoning_tokens', 128)]); + expect(event.reasoningTokens).toBe(128); + }); + + it('reads gen_ai.usage.output_tokens_details.reasoning_tokens', () => { + const { event } = mapChild([int('gen_ai.usage.output_tokens_details.reasoning_tokens', 64)]); + expect(event.reasoningTokens).toBe(64); + }); + + it('prefers cognipeer.tokens.reasoning over every other convention', () => { + const { event } = mapChild([ + int('cognipeer.tokens.reasoning', 10), + int('llm.token_count.completion_details.reasoning', 20), + int('gen_ai.usage.reasoning_tokens', 30), + int('gen_ai.usage.output_tokens_details.reasoning_tokens', 40), + ]); + expect(event.reasoningTokens).toBe(10); + }); + + it('leaves reasoningTokens absent when nothing reported it', () => { + const { event } = mapChild([str('openinference.span.kind', 'CHAIN')]); + expect(event.reasoningTokens).toBeUndefined(); + }); +}); + +describe('finishReason across conventions', () => { + it('reads cognipeer.finish_reason', () => { + const { event } = mapChild([str('cognipeer.finish_reason', 'stop')]); + expect(event.finishReason).toBe('stop'); + }); + + it('reads gen_ai.response.finish_reasons as a JSON array, taking the first element', () => { + const { event } = mapChild([str('gen_ai.response.finish_reasons', '["length","stop"]')]); + expect(event.finishReason).toBe('length'); + }); + + it('reads gen_ai.response.finish_reasons as a comma-joined string', () => { + const { event } = mapChild([str('gen_ai.response.finish_reasons', 'tool_calls,stop')]); + expect(event.finishReason).toBe('tool_calls'); + }); + + it('reads gen_ai.response.finish_reasons as a plain single string', () => { + const { event } = mapChild([str('gen_ai.response.finish_reasons', 'stop')]); + expect(event.finishReason).toBe('stop'); + }); + + it('reads llm.response.finish_reason (OpenInference)', () => { + const { event } = mapChild([str('llm.response.finish_reason', 'max_tokens')]); + expect(event.finishReason).toBe('max_tokens'); + }); + + it('prefers cognipeer.finish_reason over every other convention', () => { + const { event } = mapChild([ + str('cognipeer.finish_reason', 'stop'), + str('gen_ai.response.finish_reasons', '["length"]'), + str('llm.response.finish_reason', 'content_filter'), + ]); + expect(event.finishReason).toBe('stop'); + }); + + it('normalizes casing/whitespace the same way the shared helper does', () => { + const { event } = mapChild([str('cognipeer.finish_reason', ' STOP ')]); + expect(event.finishReason).toBe('stop'); + }); + + it('leaves finishReason absent when nothing reported it', () => { + const { event } = mapChild([str('openinference.span.kind', 'CHAIN')]); + expect(event.finishReason).toBeUndefined(); + }); +}); diff --git a/src/app/dashboard/models/[id]/page.tsx b/src/app/dashboard/models/[id]/page.tsx index bce47f73..1427bcbf 100644 --- a/src/app/dashboard/models/[id]/page.tsx +++ b/src/app/dashboard/models/[id]/page.tsx @@ -64,6 +64,7 @@ import { defaultDashboardDateFilter, } from '@/lib/utils/dashboardDateFilter'; import { calcCacheHitRate, formatPercent } from '@/lib/utils/tracingUtils'; +import { isAbnormalFinishReason } from '@/lib/shared/finishReason'; import type { IDynamicRoutingConfig } from '@/lib/database'; interface ModelPricing { @@ -171,6 +172,9 @@ interface UsageLogDto { outputTokens: number; cachedInputTokens?: number; totalTokens: number; + // Subset of outputTokens, never additive — see the table/modal rendering below. + reasoningTokens?: number; + finishReason?: string; errorMessage?: string; toolCalls?: number; cacheHit?: boolean; @@ -878,6 +882,30 @@ export default function ModelDetailPage() { total: selectedLog.totalTokens.toLocaleString(), })} + {selectedLog.reasoningTokens ? ( + // Separate line rather than a tokenBreakdown placeholder: reasoning + // tokens are already counted inside outputTokens above, so adding a + // slot to that message would make readers double them. + + {t('logs.modal.reasoningTokens', { + count: selectedLog.reasoningTokens.toLocaleString(), + })} + + ) : null} + + {t('logs.modal.finishReason')}:{' '} + {selectedLog.finishReason ? ( + + {selectedLog.finishReason} + + ) : ( + {t('logs.finishReasonNone')} + )} + {selectedLog.errorMessage ? ( {t('logs.modal.error')}:{' '} @@ -2087,6 +2115,7 @@ function LogsTab({ {tLogs('logs.timestamp')} {tLogs('logs.route')} {tLogs('logs.status')} + {tLogs('logs.finishReason')} {tLogs('logs.latency')} {tLogs('logs.tokens')} Request ID @@ -2113,6 +2142,19 @@ function LogsTab({ ) : null} + + {l.finishReason ? ( + + {l.finishReason} + + ) : ( + {tLogs('logs.finishReasonNone')} + )} + {l.totalTokens.toLocaleString()} + {l.reasoningTokens ? ( + // Reasoning tokens are a subset of outputTokens (never billed or + // summed separately), so this renders as a muted annotation under + // the total rather than a value that would inflate it. +
+ {tLogs('logs.reasoningTokens', { + count: l.reasoningTokens.toLocaleString(), + })} +
+ ) : null} {l.requestId ?? '—'} diff --git a/src/app/dashboard/tracing/sessions/[sessionId]/page.tsx b/src/app/dashboard/tracing/sessions/[sessionId]/page.tsx index bd5d46ca..bb63414f 100644 --- a/src/app/dashboard/tracing/sessions/[sessionId]/page.tsx +++ b/src/app/dashboard/tracing/sessions/[sessionId]/page.tsx @@ -54,6 +54,7 @@ import { } from '@/lib/utils/tracingUtils'; import { useDocsDrawer } from '@/components/docs/DocsDrawerContext'; import JsonTreeViewer from '@/components/common/JsonTreeViewer'; +import { isAbnormalFinishReason, isTruncatedFinishReason, normalizeFinishReason } from '@/lib/shared/finishReason'; dayjs.extend(relativeTime); @@ -141,6 +142,10 @@ interface SessionDetailResponse { totalCachedInputTokens?: number; totalBytesIn?: number; totalBytesOut?: number; + /** Sum of `reasoningTokens` across events — a SUBSET of totalOutputTokens, never added to it. */ + totalReasoningTokens?: number; + /** Count of events whose finish reason indicates a token/length cutoff. */ + truncatedEvents?: number; summary?: { totalInputTokens?: number; totalOutputTokens?: number; @@ -171,6 +176,10 @@ interface SessionDetailResponse { outputTokens?: number; totalTokens?: number; cachedInputTokens?: number; + /** SUBSET of outputTokens (not additive) — model "thinking" spend on this call. */ + reasoningTokens?: number; + /** Raw provider stop reason; use `eventFinishReason()` for the legacy-metadata fallback. */ + finishReason?: string; requestBytes?: number; responseBytes?: number; traceId?: string; @@ -191,6 +200,21 @@ interface EventDetailResponse { type TracingEvent = SessionDetailResponse['events'][number]; +// ─── Finish reason / reasoning token read helpers ────────────── +// Rows written before the agent-sdk migration still carry these values +// inside `metadata` rather than as first-class fields — every read site in +// this file goes through these two so a legacy row and a migrated row +// render identically. + +function eventFinishReason(event: TracingEvent): string | undefined { + return normalizeFinishReason(event.finishReason ?? event.metadata?.finishReason); +} + +function eventReasoningTokens(event: TracingEvent): number | undefined { + const raw = event.reasoningTokens ?? event.metadata?.reasoningTokens; + return typeof raw === 'number' && Number.isFinite(raw) && raw > 0 ? raw : undefined; +} + // ─── Event type → color mapping ──────────────────────────────── function eventTypeColor(type?: string): string { @@ -463,6 +487,23 @@ function ToolMenuBadge({ names, count }: { names?: string[]; count?: number }) { ); } +/** + * Compact truncation marker for timeline rows — a length/output-ceiling stop + * is the usual cause of a cut-off or unparseable answer, but a timeline row + * has no room for the full reason text the detail panel shows. + */ +function TruncatedMarker({ event }: { event: TracingEvent }) { + const finishReason = eventFinishReason(event); + if (!isTruncatedFinishReason(finishReason)) return null; + return ( + + + TRUNCATED + + + ); +} + function SpanTreeItem({ node, depth, @@ -512,6 +553,7 @@ function SpanTreeItem({ {event.label ? humanize(event.label) : humanize(event.type) || 'Event'} + {event.status && ( {event.status} @@ -593,6 +635,17 @@ function EventInfoRows({ event }: { event: TracingEvent }) { value: {event.actorName}, }); } + // Abnormal reasons already get an orange badge in the header — this row + // is for the common case (`stop`, `tool_calls`, …) so the value is still + // visible here without switching to the badge-free normal path. + const finishReason = eventFinishReason(event); + if (finishReason && !isAbnormalFinishReason(finishReason)) { + rows.push({ + key: 'finishReason', + label: 'Finish Reason', + value: {finishReason}, + }); + } return ( @@ -609,13 +662,23 @@ function EventInfoRows({ event }: { event: TracingEvent }) { // ─── Token / bytes stats ─────────────────────────────────────── function EventTokenStats({ event }: { event: TracingEvent }) { - const hasTokens = event.inputTokens != null || event.outputTokens != null || event.cachedInputTokens != null; + const reasoningTokens = eventReasoningTokens(event); + const hasTokens = event.inputTokens != null || event.outputTokens != null || event.cachedInputTokens != null || reasoningTokens != null; const hasBytes = event.requestBytes != null || event.responseBytes != null; if (!hasTokens && !hasBytes) return null; const items: Array<{ label: string; value: number; sub?: string }> = []; if (event.inputTokens != null) items.push({ label: 'Input', value: event.inputTokens }); if (event.outputTokens != null) items.push({ label: 'Output', value: event.outputTokens }); + if (reasoningTokens != null) { + items.push({ + label: 'Reasoning', + value: reasoningTokens, + // Reasoning tokens are a SUBSET of output, not a fourth bucket — + // the share makes that containment visible at a glance. + sub: event.outputTokens ? `${formatPercent(reasoningTokens / event.outputTokens)} of output` : undefined, + }); + } if (event.cachedInputTokens != null && event.cachedInputTokens > 0) { items.push({ label: 'Cached', @@ -817,9 +880,6 @@ function RawJsonView({ event }: { event: TracingEvent }) { // ─── Event detail panel ──────────────────────────────────────── -/** Finish reasons that mean the model ended its answer on its own terms. */ -const NORMAL_FINISH_REASONS = new Set(['stop', 'tool_calls', 'end_turn', 'function_call']); - function EventDetailPanel({ event }: { event: TracingEvent }) { const hasSections = event.sections && event.sections.length > 0; const hasMetadata = event.metadata && Object.keys(event.metadata).length > 0; @@ -827,8 +887,8 @@ function EventDetailPanel({ event }: { event: TracingEvent }) { // unparseable answer, so it is surfaced next to the status rather than // being left for whoever thinks to open the metadata tab. A normal stop is // the default and would just be noise on every single event. - const finishReason = typeof event.metadata?.finishReason === 'string' ? event.metadata.finishReason : undefined; - const abnormalFinish = finishReason && !NORMAL_FINISH_REASONS.has(finishReason) ? finishReason : undefined; + const finishReason = eventFinishReason(event); + const abnormalFinish = isAbnormalFinishReason(finishReason) ? finishReason : undefined; return ( @@ -845,7 +905,7 @@ function EventDetailPanel({ event }: { event: TracingEvent }) { )} {abnormalFinish && ( {formatToolName(event.toolName)} )} + {event.model && ( {event.model} )} @@ -1050,6 +1111,8 @@ export default function SessionDetailPage({ params }: { params: Promise<{ sessio input: summary?.totalInputTokens ?? detail?.session?.totalInputTokens ?? 0, output: summary?.totalOutputTokens ?? detail?.session?.totalOutputTokens ?? 0, cached: summary?.totalCachedInputTokens ?? detail?.session?.totalCachedInputTokens ?? 0, + reasoning: detail?.session?.totalReasoningTokens ?? 0, + truncatedEvents: detail?.session?.truncatedEvents ?? 0, }; }, [detail]); @@ -1318,7 +1381,7 @@ export default function SessionDetailPage({ params }: { params: Promise<{ sessio )} {/* Token cards */} - + 0 ? 4 : 3 }} spacing="xs"> Input {formatNumber(tokenStats.input)} @@ -1327,6 +1390,15 @@ export default function SessionDetailPage({ params }: { params: Promise<{ sessio Output {formatNumber(tokenStats.output)} + {tokenStats.reasoning > 0 && ( + + Reasoning + {formatNumber(tokenStats.reasoning)} + + {tokenStats.output > 0 ? `${formatPercent(tokenStats.reasoning / tokenStats.output)} of output` : 'Subset of output'} + + + )} Cache {formatNumber(tokenStats.cached)} @@ -1336,6 +1408,20 @@ export default function SessionDetailPage({ params }: { params: Promise<{ sessio + {/* Truncated calls — same badge language as the per-event abnormal-finish badge in EventDetailPanel */} + {tokenStats.truncatedEvents > 0 && ( + + + TRUNCATED {tokenStats.truncatedEvents} + + + )} + {/* Errors */} {session.errors && session.errors.length > 0 && ( diff --git a/src/lib/database/mongodb/tracing.mixin.ts b/src/lib/database/mongodb/tracing.mixin.ts index 89bec0f1..e6473e8e 100644 --- a/src/lib/database/mongodb/tracing.mixin.ts +++ b/src/lib/database/mongodb/tracing.mixin.ts @@ -13,6 +13,7 @@ import type { } from '../provider.interface'; import type { Constructor } from './types'; import { MongoDBProviderBase, COLLECTIONS, logger } from './base'; +import { isTruncatedFinishReason, normalizeFinishReason } from '@/lib/shared/finishReason'; export function TracingMixin>(Base: TBase) { return class TracingOps extends Base { @@ -753,11 +754,18 @@ export function TracingMixin>(Bas } : asObject('eventCounts'); + // An abnormal-but-not-truncated finishReason (e.g. a content filter) isn't + // counted here — truncatedEvents specifically tracks token/length cutoffs, + // the usual explanation for a truncated or unparseable answer. + const isTruncated = isTruncatedFinishReason(normalizeFinishReason(delta.finishReason)); + const totals = { totalEvents: plus('totalEvents', 1), totalInputTokens: plus('totalInputTokens', delta.inputTokens), totalOutputTokens: plus('totalOutputTokens', delta.outputTokens), totalCachedInputTokens: plus('totalCachedInputTokens', delta.cachedInputTokens), + totalReasoningTokens: plus('totalReasoningTokens', delta.reasoningTokens), + truncatedEvents: plus('truncatedEvents', isTruncated ? 1 : 0), }; await collection.updateOne(filter, [ @@ -938,6 +946,11 @@ export function TracingMixin>(Bas query[`metadata.${metadataKey}`] = metadataValue; } + // "Only sessions with truncatedEvents > 0" filter. + if (filters?.truncated === true) { + query.truncatedEvents = { $gt: 0 }; + } + const limit = Math.max(0, parseInt(String(filters?.limit ?? '50'), 10) || 0); const skip = Math.max(0, parseInt(String(filters?.skip ?? '0'), 10) || 0); const includeTotal = filters?.includeTotal !== false; @@ -1357,6 +1370,49 @@ export function TracingMixin>(Bas }; } + async updateAgentTracingEvent( + sessionId: string, + eventId: string, + data: Partial>, + projectId?: string, + ): Promise { + const db = this.getTenantDb(); + const scoped = projectId ? { sessionId, projectId } : { sessionId }; + const query: Record = { + ...scoped, + $or: [{ id: eventId }], + }; + + if (/^[a-f0-9]{24}$/i.test(eventId)) { + query.$or = [...(query.$or as Array>), { _id: new ObjectId(eventId) }]; + } + + const updateData: Partial = {}; + if (data.finishReason !== undefined) updateData.finishReason = data.finishReason; + if (data.reasoningTokens !== undefined) updateData.reasoningTokens = data.reasoningTokens; + if (data.metadata !== undefined) updateData.metadata = data.metadata; + + const collection = db.collection(COLLECTIONS.agentTracingEvents); + + if (Object.keys(updateData).length === 0) { + const event = await collection.findOne(query); + return event ? { ...event, _id: event._id?.toString() } : null; + } + + const result = await collection.findOneAndUpdate( + query, + { $set: updateData }, + { returnDocument: 'after' }, + ); + + if (!result) return null; + + return { + ...result, + _id: result._id.toString(), + }; + } + async deleteAgentTracingEvents(sessionId: string, projectId?: string): Promise { const db = this.getTenantDb(); const result = await db diff --git a/src/lib/database/mongodb/usage.mixin.ts b/src/lib/database/mongodb/usage.mixin.ts index a14409c4..5ce80c17 100644 --- a/src/lib/database/mongodb/usage.mixin.ts +++ b/src/lib/database/mongodb/usage.mixin.ts @@ -17,6 +17,7 @@ const COUNTER_FIELDS = [ 'inputTokens', 'outputTokens', 'cachedInputTokens', + 'reasoningTokens', 'totalTokens', 'costUsd', 'latencyMsSum', diff --git a/src/lib/database/provider/contract.ts b/src/lib/database/provider/contract.ts index 585df7bc..5de50f9a 100644 --- a/src/lib/database/provider/contract.ts +++ b/src/lib/database/provider/contract.ts @@ -328,6 +328,20 @@ export interface DatabaseProvider extends EnterpriseDbMethods { eventId: string, projectId?: string, ): Promise; + /** + * Narrow, migration-only update for a single tracing event. + * + * Tracing events are otherwise write-once — ingest creates them and nothing + * mutates them — so this deliberately accepts only the fields a data + * migration needs, rather than a general `Partial` that + * would invite drift between the two providers. + */ + updateAgentTracingEvent( + sessionId: string, + eventId: string, + data: Partial>, + projectId?: string, + ): Promise; listAgentTracingEvents( sessionId: string, projectId?: string, diff --git a/src/lib/database/provider/types.base.ts b/src/lib/database/provider/types.base.ts index 6cce909a..4a040098 100644 --- a/src/lib/database/provider/types.base.ts +++ b/src/lib/database/provider/types.base.ts @@ -259,6 +259,12 @@ export interface IAgentTracingSession extends IUsageAttributionFields { totalInputTokens?: number; totalOutputTokens?: number; totalCachedInputTokens?: number; + /** Sum of `reasoningTokens` across the session's events — a subset of + * `totalOutputTokens`, never added on top of it. */ + totalReasoningTokens?: number; + /** Count of events whose `finishReason` is a truncation reason (see + * `isTruncatedFinishReason`), e.g. the model hit its token limit. */ + truncatedEvents?: number; totalBytesIn?: number; totalBytesOut?: number; totalRequestBytes?: number; @@ -276,6 +282,12 @@ export interface AgentTracingSessionEventDelta { inputTokens?: number; outputTokens?: number; cachedInputTokens?: number; + /** Subset of `outputTokens` (e.g. OpenAI `completion_tokens_details.reasoning_tokens`); + * never added into `totalTokens` or any cost arithmetic. */ + reasoningTokens?: number; + /** Normalized (trim + lowercase) provider finish reason for this event's + * model call, used to bump `truncatedEvents` when it indicates a cutoff. */ + finishReason?: string; durationMs?: number; /** Event type whose per-type counter should be bumped, e.g. `ai_call`. */ eventType?: string; @@ -393,6 +405,12 @@ export interface IAgentTracingEvent { outputTokens?: number; totalTokens?: number; cachedInputTokens?: number; + /** Subset of `outputTokens` (e.g. OpenAI `completion_tokens_details.reasoning_tokens`); + * never added into `totalTokens` or any cost arithmetic. */ + reasoningTokens?: number; + /** Normalized (trim + lowercase) raw provider finish reason, e.g. `stop`, + * `length`, `tool_calls`. See `src/lib/shared/finishReason.ts`. */ + finishReason?: string; bytesIn?: number; bytesOut?: number; requestBytes?: number; @@ -756,6 +774,12 @@ export interface IModelUsageLog extends IUsageAttributionFields { outputTokens: number; cachedInputTokens?: number; totalTokens: number; + /** Subset of `outputTokens` (e.g. OpenAI `completion_tokens_details.reasoning_tokens`); + * never added into `totalTokens` or any cost arithmetic. */ + reasoningTokens?: number; + /** Normalized (trim + lowercase) raw provider finish reason, e.g. `stop`, + * `length`, `tool_calls`. See `src/lib/shared/finishReason.ts`. */ + finishReason?: string; toolCalls?: number; cacheHit?: boolean; pricingSnapshot?: IModelPricing & IModelUsageCostSnapshot; @@ -808,6 +832,9 @@ export interface IUsageDaily { inputTokens: number; outputTokens: number; cachedInputTokens: number; + /** Subset of `outputTokens` (e.g. OpenAI `completion_tokens_details.reasoning_tokens`); + * never added into `totalTokens` or any cost arithmetic. */ + reasoningTokens: number; totalTokens: number; costUsd: number; latencyMsSum: number; @@ -839,6 +866,9 @@ export interface IUsageDailyIncrement { inputTokens?: number; outputTokens?: number; cachedInputTokens?: number; + /** Subset of `outputTokens`; never added into `totalTokens` or any cost + * arithmetic. Mirrors `IUsageDaily.reasoningTokens`. */ + reasoningTokens?: number; totalTokens?: number; costUsd?: number; latencyMsSum?: number; diff --git a/src/lib/database/sqlite/base.ts b/src/lib/database/sqlite/base.ts index b4ba06ca..c63b97d5 100644 --- a/src/lib/database/sqlite/base.ts +++ b/src/lib/database/sqlite/base.ts @@ -731,6 +731,19 @@ export class SQLiteProviderBase { // need it backfilled the same way agentModel/agentVersion were. this.ensureTableColumn(db, TABLES.agentTracingSessions, 'metadata', "metadata TEXT DEFAULT '{}'"); + // finishReason/reasoningTokens promoted from the events' `metadata` JSON + // blob to first-class columns, plus their session/log rollups. reasoningTokens + // is always a subset of outputTokens (OpenAI-style reasoning models) and must + // never be summed into totalTokens/cost. Ensure on boot for pre-existing + // tenant DB files, which predate these columns. + this.ensureTableColumn(db, TABLES.agentTracingEvents, 'finishReason', 'finishReason TEXT'); + this.ensureTableColumn(db, TABLES.agentTracingEvents, 'reasoningTokens', 'reasoningTokens INTEGER DEFAULT 0'); + this.ensureTableColumn(db, TABLES.agentTracingSessions, 'totalReasoningTokens', 'totalReasoningTokens INTEGER DEFAULT 0'); + this.ensureTableColumn(db, TABLES.agentTracingSessions, 'truncatedEvents', 'truncatedEvents INTEGER DEFAULT 0'); + this.ensureTableColumn(db, TABLES.modelUsageLogs, 'finishReason', 'finishReason TEXT'); + this.ensureTableColumn(db, TABLES.modelUsageLogs, 'reasoningTokens', 'reasoningTokens INTEGER DEFAULT 0'); + this.ensureTableColumn(db, TABLES.usageDaily, 'reasoningTokens', 'reasoningTokens INTEGER NOT NULL DEFAULT 0'); + // external_model_pricing.versions (effective-dated price history) was // added after the table shipped; ensure on boot for DBs created before. this.ensureTableColumn(db, TABLES.externalModelPricing, 'versions', 'versions TEXT'); diff --git a/src/lib/database/sqlite/model.mixin.ts b/src/lib/database/sqlite/model.mixin.ts index 2fbb3a9e..8e84a28c 100644 --- a/src/lib/database/sqlite/model.mixin.ts +++ b/src/lib/database/sqlite/model.mixin.ts @@ -140,11 +140,11 @@ export function ModelMixin>(Base: INSERT INTO ${TABLES.modelUsageLogs} (id, tenantId, projectId, modelKey, modelId, requestId, route, status, providerRequest, providerResponse, errorMessage, latencyMs, - inputTokens, outputTokens, cachedInputTokens, totalTokens, toolCalls, cacheHit, pricingSnapshot, routing, + inputTokens, outputTokens, cachedInputTokens, totalTokens, finishReason, reasoningTokens, toolCalls, cacheHit, pricingSnapshot, routing, userId, apiTokenId, actorType, createdAt) VALUES (@id, @tenantId, @projectId, @modelKey, @modelId, @requestId, @route, @status, @providerRequest, @providerResponse, @errorMessage, @latencyMs, - @inputTokens, @outputTokens, @cachedInputTokens, @totalTokens, @toolCalls, @cacheHit, @pricingSnapshot, @routing, + @inputTokens, @outputTokens, @cachedInputTokens, @totalTokens, @finishReason, @reasoningTokens, @toolCalls, @cacheHit, @pricingSnapshot, @routing, @userId, @apiTokenId, @actorType, @createdAt) `).run({ id, @@ -166,6 +166,8 @@ export function ModelMixin>(Base: outputTokens: log.outputTokens, cachedInputTokens: log.cachedInputTokens ?? 0, totalTokens: log.totalTokens, + finishReason: log.finishReason ?? null, + reasoningTokens: log.reasoningTokens ?? null, toolCalls: log.toolCalls ?? 0, cacheHit: this.toBoolInt(log.cacheHit), pricingSnapshot: log.pricingSnapshot ? this.toJson(log.pricingSnapshot) : null, @@ -367,6 +369,8 @@ export function ModelMixin>(Base: outputTokens: (r.outputTokens as number) ?? 0, cachedInputTokens: (r.cachedInputTokens as number) ?? 0, totalTokens: (r.totalTokens as number) ?? 0, + finishReason: (r.finishReason as string | null) ?? undefined, + reasoningTokens: r.reasoningTokens == null ? undefined : Number(r.reasoningTokens), toolCalls: (r.toolCalls as number) ?? 0, cacheHit: this.fromBoolInt(r.cacheHit), pricingSnapshot: r.pricingSnapshot ? this.parseJson(r.pricingSnapshot, undefined) : undefined, diff --git a/src/lib/database/sqlite/schema.ts b/src/lib/database/sqlite/schema.ts index 95685d4e..fefbaa85 100644 --- a/src/lib/database/sqlite/schema.ts +++ b/src/lib/database/sqlite/schema.ts @@ -472,6 +472,8 @@ export const TENANT_SCHEMA_SQL = ` totalInputTokens INTEGER DEFAULT 0, totalOutputTokens INTEGER DEFAULT 0, totalCachedInputTokens INTEGER DEFAULT 0, + totalReasoningTokens INTEGER DEFAULT 0, + truncatedEvents INTEGER DEFAULT 0, totalBytesIn INTEGER DEFAULT 0, totalBytesOut INTEGER DEFAULT 0, totalRequestBytes INTEGER DEFAULT 0, @@ -518,6 +520,8 @@ export const TENANT_SCHEMA_SQL = ` outputTokens INTEGER DEFAULT 0, totalTokens INTEGER DEFAULT 0, cachedInputTokens INTEGER DEFAULT 0, + finishReason TEXT, + reasoningTokens INTEGER DEFAULT 0, bytesIn INTEGER DEFAULT 0, bytesOut INTEGER DEFAULT 0, requestBytes INTEGER DEFAULT 0, @@ -573,6 +577,8 @@ export const TENANT_SCHEMA_SQL = ` outputTokens INTEGER NOT NULL DEFAULT 0, cachedInputTokens INTEGER DEFAULT 0, totalTokens INTEGER NOT NULL DEFAULT 0, + finishReason TEXT, + reasoningTokens INTEGER DEFAULT 0, toolCalls INTEGER DEFAULT 0, cacheHit INTEGER DEFAULT 0, pricingSnapshot TEXT, @@ -613,6 +619,7 @@ export const TENANT_SCHEMA_SQL = ` inputTokens INTEGER NOT NULL DEFAULT 0, outputTokens INTEGER NOT NULL DEFAULT 0, cachedInputTokens INTEGER NOT NULL DEFAULT 0, + reasoningTokens INTEGER NOT NULL DEFAULT 0, totalTokens INTEGER NOT NULL DEFAULT 0, costUsd REAL NOT NULL DEFAULT 0, latencyMsSum INTEGER NOT NULL DEFAULT 0, diff --git a/src/lib/database/sqlite/tracing.mixin.ts b/src/lib/database/sqlite/tracing.mixin.ts index 159ebc60..496f23fe 100644 --- a/src/lib/database/sqlite/tracing.mixin.ts +++ b/src/lib/database/sqlite/tracing.mixin.ts @@ -10,6 +10,7 @@ import type { } from '../provider.interface'; import type { Constructor, SqliteRow } from './types'; import { SQLiteProviderBase, TABLES } from './base'; +import { isTruncatedFinishReason, normalizeFinishReason } from '@/lib/shared/finishReason'; export function TracingMixin>(Base: TBase) { return class TracingOps extends Base { @@ -101,12 +102,12 @@ export function TracingMixin>(Base INSERT INTO ${TABLES.agentTracingSessions} (id, sessionId, traceId, rootSpanId, threadId, tenantId, projectId, source, agent, agentName, agentVersion, agentModel, metadata, config, summary, status, startedAt, endedAt, durationMs, errors, modelsUsed, toolsUsed, - eventCounts, totalEvents, totalInputTokens, totalOutputTokens, totalCachedInputTokens, + eventCounts, totalEvents, totalInputTokens, totalOutputTokens, totalCachedInputTokens, totalReasoningTokens, truncatedEvents, totalBytesIn, totalBytesOut, totalRequestBytes, totalResponseBytes, userId, apiTokenId, actorType, createdAt, updatedAt) VALUES (@id, @sessionId, @traceId, @rootSpanId, @threadId, @tenantId, @projectId, @source, @agent, @agentName, @agentVersion, @agentModel, @metadata, @config, @summary, @status, @startedAt, @endedAt, @durationMs, @errors, @modelsUsed, @toolsUsed, - @eventCounts, @totalEvents, @totalInputTokens, @totalOutputTokens, @totalCachedInputTokens, + @eventCounts, @totalEvents, @totalInputTokens, @totalOutputTokens, @totalCachedInputTokens, @totalReasoningTokens, @truncatedEvents, @totalBytesIn, @totalBytesOut, @totalRequestBytes, @totalResponseBytes, @userId, @apiTokenId, @actorType, @createdAt, @updatedAt) `).run({ @@ -137,6 +138,8 @@ export function TracingMixin>(Base totalInputTokens: session.totalInputTokens ?? 0, totalOutputTokens: session.totalOutputTokens ?? 0, totalCachedInputTokens: session.totalCachedInputTokens ?? 0, + totalReasoningTokens: session.totalReasoningTokens ?? 0, + truncatedEvents: session.truncatedEvents ?? 0, totalBytesIn: session.totalBytesIn ?? 0, totalBytesOut: session.totalBytesOut ?? 0, totalRequestBytes: session.totalRequestBytes ?? 0, @@ -221,12 +224,20 @@ export function TracingMixin>(Base const toNumber = (value: number | undefined) => typeof value === 'number' && Number.isFinite(value) ? value : 0; + // An abnormal-but-not-truncated finishReason (e.g. a content filter) isn't + // counted here — truncatedEvents specifically tracks token/length cutoffs, + // the usual explanation for a truncated or unparseable answer. + const normalizedFinishReason = normalizeFinishReason(delta.finishReason); + const truncated = isTruncatedFinishReason(normalizedFinishReason) ? 1 : 0; + const params: Record = { sessionId, updatedAt: this.now(), inputTokens: toNumber(delta.inputTokens), outputTokens: toNumber(delta.outputTokens), cachedInputTokens: toNumber(delta.cachedInputTokens), + reasoningTokens: toNumber(delta.reasoningTokens), + truncated, }; let where = 'sessionId = @sessionId'; if (projectId) { where += ' AND projectId = @projectId'; params.projectId = projectId; } @@ -238,7 +249,9 @@ export function TracingMixin>(Base totalEvents = COALESCE(totalEvents, 0) + 1, totalInputTokens = COALESCE(totalInputTokens, 0) + @inputTokens, totalOutputTokens = COALESCE(totalOutputTokens, 0) + @outputTokens, - totalCachedInputTokens = COALESCE(totalCachedInputTokens, 0) + @cachedInputTokens + totalCachedInputTokens = COALESCE(totalCachedInputTokens, 0) + @cachedInputTokens, + totalReasoningTokens = COALESCE(totalReasoningTokens, 0) + @reasoningTokens, + truncatedEvents = COALESCE(truncatedEvents, 0) + @truncated WHERE ${where}`, ).run(params); @@ -332,6 +345,8 @@ export function TracingMixin>(Base if (data.totalInputTokens !== undefined) { sets.push('totalInputTokens = @totalInputTokens'); params.totalInputTokens = data.totalInputTokens; } if (data.totalOutputTokens !== undefined) { sets.push('totalOutputTokens = @totalOutputTokens'); params.totalOutputTokens = data.totalOutputTokens; } if (data.totalCachedInputTokens !== undefined) { sets.push('totalCachedInputTokens = @totalCachedInputTokens'); params.totalCachedInputTokens = data.totalCachedInputTokens; } + if (data.totalReasoningTokens !== undefined) { sets.push('totalReasoningTokens = @totalReasoningTokens'); params.totalReasoningTokens = data.totalReasoningTokens; } + if (data.truncatedEvents !== undefined) { sets.push('truncatedEvents = @truncatedEvents'); params.truncatedEvents = data.truncatedEvents; } if (data.totalBytesIn !== undefined) { sets.push('totalBytesIn = @totalBytesIn'); params.totalBytesIn = data.totalBytesIn; } if (data.totalBytesOut !== undefined) { sets.push('totalBytesOut = @totalBytesOut'); params.totalBytesOut = data.totalBytesOut; } if (data.totalRequestBytes !== undefined) { sets.push('totalRequestBytes = @totalRequestBytes'); params.totalRequestBytes = data.totalRequestBytes; } @@ -397,6 +412,11 @@ export function TracingMixin>(Base params.metadataValue = metadataValue; } + // "Only sessions with truncatedEvents > 0" filter. + if (filters?.truncated === true) { + clauses.push('COALESCE(truncatedEvents, 0) > 0'); + } + const where = clauses.length > 0 ? `WHERE ${clauses.join(' AND ')}` : ''; const limitValue = Number.parseInt(String(filters?.limit ?? '50'), 10); const skipValue = Number.parseInt(String(filters?.skip ?? '0'), 10); @@ -719,11 +739,11 @@ export function TracingMixin>(Base INSERT INTO ${TABLES.agentTracingEvents} (id, sessionId, traceId, spanId, parentSpanId, tenantId, projectId, eventId, type, label, sequence, timestamp, status, actor, metadata, sections, modelNames, model, error, durationMs, actorName, actorRole, - toolName, toolExecutionId, inputTokens, outputTokens, totalTokens, cachedInputTokens, + toolName, toolExecutionId, inputTokens, outputTokens, totalTokens, cachedInputTokens, finishReason, reasoningTokens, bytesIn, bytesOut, requestBytes, responseBytes, createdAt) VALUES (@id, @sessionId, @traceId, @spanId, @parentSpanId, @tenantId, @projectId, @eventId, @type, @label, @sequence, @timestamp, @status, @actor, @metadata, @sections, @modelNames, @model, @error, @durationMs, @actorName, @actorRole, - @toolName, @toolExecutionId, @inputTokens, @outputTokens, @totalTokens, @cachedInputTokens, + @toolName, @toolExecutionId, @inputTokens, @outputTokens, @totalTokens, @cachedInputTokens, @finishReason, @reasoningTokens, @bytesIn, @bytesOut, @requestBytes, @responseBytes, @createdAt) `).run({ id, @@ -754,6 +774,8 @@ export function TracingMixin>(Base outputTokens: event.outputTokens ?? 0, totalTokens: event.totalTokens ?? 0, cachedInputTokens: event.cachedInputTokens ?? 0, + finishReason: event.finishReason ?? null, + reasoningTokens: event.reasoningTokens ?? null, bytesIn: event.bytesIn ?? 0, bytesOut: event.bytesOut ?? 0, requestBytes: event.requestBytes ?? 0, @@ -802,6 +824,29 @@ export function TracingMixin>(Base return row ? this.mapAgentTracingEventRow(row) : null; } + async updateAgentTracingEvent( + sessionId: string, + eventId: string, + data: Partial>, + projectId?: string, + ): Promise { + const db = this.getTenantDb(); + const sets: string[] = []; + const params: Record = { sessionId, eventId }; + let where = 'sessionId = @sessionId AND (eventId = @eventId OR id = @eventId)'; + if (projectId) { where += ' AND projectId = @projectId'; params.projectId = projectId; } + + if (data.finishReason !== undefined) { sets.push('finishReason = @finishReason'); params.finishReason = data.finishReason ?? null; } + if (data.reasoningTokens !== undefined) { sets.push('reasoningTokens = @reasoningTokens'); params.reasoningTokens = data.reasoningTokens ?? null; } + if (data.metadata !== undefined) { sets.push('metadata = @metadata'); params.metadata = this.toJson(data.metadata); } + + if (sets.length > 0) { + db.prepare(`UPDATE ${TABLES.agentTracingEvents} SET ${sets.join(', ')} WHERE ${where}`).run(params); + } + + return this.findAgentTracingEventById(sessionId, eventId, projectId); + } + async deleteAgentTracingEvents(sessionId: string, projectId?: string): Promise { const db = this.getTenantDb(); let sql = `DELETE FROM ${TABLES.agentTracingEvents} WHERE sessionId = @sessionId`; @@ -841,6 +886,8 @@ export function TracingMixin>(Base totalInputTokens: (r.totalInputTokens as number) ?? 0, totalOutputTokens: (r.totalOutputTokens as number) ?? 0, totalCachedInputTokens: (r.totalCachedInputTokens as number) ?? 0, + totalReasoningTokens: (r.totalReasoningTokens as number) ?? 0, + truncatedEvents: (r.truncatedEvents as number) ?? 0, totalBytesIn: (r.totalBytesIn as number) ?? 0, totalBytesOut: (r.totalBytesOut as number) ?? 0, totalRequestBytes: (r.totalRequestBytes as number) ?? 0, @@ -883,6 +930,8 @@ export function TracingMixin>(Base outputTokens: (r.outputTokens as number) ?? 0, totalTokens: (r.totalTokens as number) ?? 0, cachedInputTokens: (r.cachedInputTokens as number) ?? 0, + finishReason: (r.finishReason as string | null) ?? undefined, + reasoningTokens: r.reasoningTokens == null ? undefined : Number(r.reasoningTokens), bytesIn: (r.bytesIn as number) ?? 0, bytesOut: (r.bytesOut as number) ?? 0, requestBytes: (r.requestBytes as number) ?? 0, diff --git a/src/lib/database/sqlite/usage.mixin.ts b/src/lib/database/sqlite/usage.mixin.ts index 2419b93d..21f7920a 100644 --- a/src/lib/database/sqlite/usage.mixin.ts +++ b/src/lib/database/sqlite/usage.mixin.ts @@ -16,6 +16,7 @@ const COUNTER_FIELDS = [ 'inputTokens', 'outputTokens', 'cachedInputTokens', + 'reasoningTokens', 'totalTokens', 'costUsd', 'latencyMsSum', @@ -39,10 +40,10 @@ export function UsageRollupMixin>( const insert = db.prepare(` INSERT INTO ${TABLES.usageDaily} (id, tenantId, projectId, userId, apiTokenId, actorType, source, service, refKey, agentKey, metadataJson, metadataKey, day, dayDate, - requests, errors, inputTokens, outputTokens, cachedInputTokens, totalTokens, + requests, errors, inputTokens, outputTokens, cachedInputTokens, reasoningTokens, totalTokens, costUsd, latencyMsSum, latencyCount, units, updatedAt) VALUES (@id, @tenantId, @projectId, @userId, @apiTokenId, @actorType, @source, @service, @refKey, @agentKey, @metadataJson, @metadataKey, @day, @dayDate, - @requests, @errors, @inputTokens, @outputTokens, @cachedInputTokens, @totalTokens, + @requests, @errors, @inputTokens, @outputTokens, @cachedInputTokens, @reasoningTokens, @totalTokens, @costUsd, @latencyMsSum, @latencyCount, @units, @updatedAt) `); const update = db.prepare(` @@ -52,6 +53,7 @@ export function UsageRollupMixin>( inputTokens = inputTokens + @inputTokens, outputTokens = outputTokens + @outputTokens, cachedInputTokens = cachedInputTokens + @cachedInputTokens, + reasoningTokens = reasoningTokens + @reasoningTokens, totalTokens = totalTokens + @totalTokens, costUsd = costUsd + @costUsd, latencyMsSum = latencyMsSum + @latencyMsSum, @@ -213,6 +215,7 @@ export function UsageRollupMixin>( inputTokens: Number(row.inputTokens ?? 0), outputTokens: Number(row.outputTokens ?? 0), cachedInputTokens: Number(row.cachedInputTokens ?? 0), + reasoningTokens: Number(row.reasoningTokens ?? 0), totalTokens: Number(row.totalTokens ?? 0), costUsd: Number(row.costUsd ?? 0), latencyMsSum: Number(row.latencyMsSum ?? 0), diff --git a/src/lib/i18n/messages/en.ts b/src/lib/i18n/messages/en.ts index a3063d67..a248468c 100644 --- a/src/lib/i18n/messages/en.ts +++ b/src/lib/i18n/messages/en.ts @@ -1328,6 +1328,9 @@ export const en = { tokenSummary: 'In: {input} • Out: {output}', viewAndEdit: 'Need to adjust credentials? Jump to the edit page.', viewDetails: 'View request details', + finishReason: 'Finish', + finishReasonNone: '—', + reasoningTokens: '+{count} reasoning', modal: { title: 'Request Details', requestId: 'Request ID', @@ -1339,6 +1342,8 @@ export const en = { response: 'Response', noRequest: 'Request data not available.', noResponse: 'Response data not available.', + finishReason: 'Finish reason', + reasoningTokens: '{count} of the output tokens above were reasoning tokens.', }, }, settings: { diff --git a/src/lib/i18n/messages/tr.ts b/src/lib/i18n/messages/tr.ts index 1d410ff3..9bf2daa2 100644 --- a/src/lib/i18n/messages/tr.ts +++ b/src/lib/i18n/messages/tr.ts @@ -687,4 +687,18 @@ export const tr: typeof en = { piiFindings: 'PII bulguları', openDataset: 'Veri setini aç', }, + modelDetail: { + ...en.modelDetail, + logs: { + ...en.modelDetail.logs, + finishReason: 'Bitiş', + finishReasonNone: '—', + reasoningTokens: '+{count} akıl yürütme', + modal: { + ...en.modelDetail.logs.modal, + finishReason: 'Bitiş nedeni', + reasoningTokens: 'Yukarıdaki çıktı token’larının {count} tanesi akıl yürütme token’ıydı.', + }, + }, + }, }; diff --git a/src/lib/services/agentTracing.ts b/src/lib/services/agentTracing.ts index 92c19b3b..722bce61 100644 --- a/src/lib/services/agentTracing.ts +++ b/src/lib/services/agentTracing.ts @@ -14,6 +14,7 @@ import { import { calculateCost } from '@/lib/services/models/usageLogger'; import { resolveExternalPricingForDay } from '@/lib/services/modelPriceCatalog/externalPricing'; import { toUtcDay } from '@/lib/services/usage/usageBreakdown'; +import { normalizeFinishReason } from '@/lib/shared/finishReason'; import dayjs from 'dayjs'; const logger = createLogger('agent-tracing'); @@ -68,6 +69,9 @@ export interface TraceUsageEventLike { inputTokens?: number; outputTokens?: number; cachedInputTokens?: number; + /** Subset of `outputTokens` (e.g. OpenAI `completion_tokens_details.reasoning_tokens`); + * never added into `totalTokens` or any cost arithmetic. */ + reasoningTokens?: number; /** Model-call wall time — feeds the rollup's latency counters so latency * optimization works for direct-to-provider (on-prem) traffic too. */ durationMs?: number; @@ -78,6 +82,7 @@ interface ModelTokenTotals { inputTokens: number; outputTokens: number; cachedInputTokens: number; + reasoningTokens: number; calls: number; /** Sum of durationMs over the calls that reported one. */ durationMsSum: number; @@ -110,11 +115,14 @@ function sumTokensByModel(events: TraceUsageEventLike[]): Map 0) { totals.durationMsSum += event.durationMs; @@ -184,6 +193,10 @@ export async function recordTraceModelUsage(params: { 0, totals.cachedInputTokens - (prior?.cachedInputTokens ?? 0), ); + const reasoningTokens = Math.max( + 0, + totals.reasoningTokens - (prior?.reasoningTokens ?? 0), + ); const calls = Math.max(0, totals.calls - (prior?.calls ?? 0)); const durationMsSum = Math.max(0, totals.durationMsSum - (prior?.durationMsSum ?? 0)); const durationSamples = Math.max(0, totals.durationSamples - (prior?.durationSamples ?? 0)); @@ -211,6 +224,9 @@ export async function recordTraceModelUsage(params: { inputTokens, outputTokens, cachedInputTokens, + // reasoningTokens is a SUBSET of outputTokens — never add it into + // totalTokens or cost arithmetic (mirrors cachedInputTokens handling). + reasoningTokens, totalTokens: inputTokens + outputTokens + cachedInputTokens, costUsd, // Latency: aggregate model-call durations, weighted by sample count — @@ -298,9 +314,15 @@ const SESSION_LIST_PROJECTION = { totalInputTokens: 1, totalOutputTokens: 1, totalCachedInputTokens: 1, + totalReasoningTokens: 1, + truncatedEvents: 1, metadata: 1, } as const; +// A field missing from this projection is invisible in the timeline list on +// Mongo (which honors projections) while SQLite (which ignores them and +// always returns full rows) still returns it — a silent provider-dependent +// difference. finishReason/reasoningTokens are listed here for that reason. const SESSION_EVENT_SUMMARY_PROJECTION = { id: 1, sequence: 1, @@ -315,6 +337,8 @@ const SESSION_EVENT_SUMMARY_PROJECTION = { outputTokens: 1, totalTokens: 1, cachedInputTokens: 1, + reasoningTokens: 1, + finishReason: 1, spanId: 1, parentSpanId: 1, // Per-turn tool menu, names only: sections survive as {kind} shells except @@ -426,6 +450,28 @@ function getToolDefinitionNames( return { names: names.slice(0, SUMMARY_TOOL_NAME_CAP), count: names.length }; } +/** + * `finishReason`/`reasoningTokens` became first-class columns on + * `IAgentTracingEvent`; rows written before that migration only carry them + * inside `metadata`. Fall back to the legacy location so old and new rows + * compare equal — this fallback can be dropped once the backfill has run + * everywhere. + */ +function legacyEventFinishReason(event: IAgentTracingEvent): string | undefined { + const direct = normalizeFinishReason(event.finishReason); + if (direct) return direct; + return normalizeFinishReason( + typeof event.metadata?.finishReason === 'string' ? event.metadata.finishReason : undefined, + ); +} + +function legacyEventReasoningTokens(event: IAgentTracingEvent): number | undefined { + if (typeof event.reasoningTokens === 'number') return event.reasoningTokens; + return typeof event.metadata?.reasoningTokens === 'number' + ? event.metadata.reasoningTokens + : undefined; +} + function mapTracingEventSummary(event: IAgentTracingEvent) { const toolMenu = getToolDefinitionNames(event); return { @@ -442,6 +488,8 @@ function mapTracingEventSummary(event: IAgentTracingEvent) { outputTokens: event.outputTokens, totalTokens: event.totalTokens, cachedInputTokens: event.cachedInputTokens, + reasoningTokens: legacyEventReasoningTokens(event), + finishReason: legacyEventFinishReason(event), spanId: event.spanId, parentSpanId: event.parentSpanId, ...(toolMenu @@ -471,6 +519,8 @@ function mapTracingEventDetail(event: IAgentTracingEvent) { outputTokens: event.outputTokens, totalTokens: event.totalTokens, cachedInputTokens: event.cachedInputTokens, + reasoningTokens: legacyEventReasoningTokens(event), + finishReason: legacyEventFinishReason(event), requestBytes: event.requestBytes, responseBytes: event.responseBytes, traceId: event.traceId, @@ -832,6 +882,8 @@ export class AgentTracingService { skip?: string; metadataKey?: string; metadataValue?: string; + /** Only sessions with `truncatedEvents > 0`. */ + truncated?: boolean; }, ) { const db = await getDatabase(); @@ -848,6 +900,7 @@ export class AgentTracingService { skip: filters?.skip || '0', metadataKey: filters?.metadataKey, metadataValue: filters?.metadataValue, + truncated: filters?.truncated, }, projectId); return { @@ -864,6 +917,8 @@ export class AgentTracingService { totalInputTokens: s.totalInputTokens, totalOutputTokens: s.totalOutputTokens, totalCachedInputTokens: s.totalCachedInputTokens, + totalReasoningTokens: s.totalReasoningTokens, + truncatedEvents: s.truncatedEvents, metadata: s.metadata, })), total: result.total, @@ -914,6 +969,8 @@ export class AgentTracingService { totalInputTokens: session.totalInputTokens, totalOutputTokens: session.totalOutputTokens, totalCachedInputTokens: session.totalCachedInputTokens, + totalReasoningTokens: session.totalReasoningTokens, + truncatedEvents: session.truncatedEvents, totalBytesIn: session.totalBytesIn, totalBytesOut: session.totalBytesOut, summary: session.summary, diff --git a/src/lib/services/agents/agentService.ts b/src/lib/services/agents/agentService.ts index 9e81d3cf..afd770be 100644 --- a/src/lib/services/agents/agentService.ts +++ b/src/lib/services/agents/agentService.ts @@ -44,6 +44,7 @@ import { type AgentRuntimeContext, } from '@/lib/services/runtimeContext'; import { invokeExternalAgent } from './externalAgent'; +import { isTruncatedFinishReason, normalizeFinishReason } from '@/lib/shared/finishReason'; const logger = createLogger('agents'); @@ -450,15 +451,28 @@ async function createInternalTracingSink( const events = Array.isArray(session.events) ? session.events : []; - // Extract models and tools used + // Extract models and tools used, plus the diagnostic rollups + // (`totalReasoningTokens` / `truncatedEvents`) mirroring what + // `applyAgentTracingSessionEvent` would accumulate incrementally + // — this sink instead computes the whole session doc in one + // pass, so the sums are taken up front over `events`. const modelsUsed = new Set(); const toolsUsed = new Set(); + let totalReasoningTokens = 0; + let truncatedEvents = 0; for (const event of events) { if (event?.model) modelsUsed.add(event.model); if (event?.toolName) toolsUsed.add(event.toolName); if (event?.actor?.scope === 'tool' && event?.actor?.name) { toolsUsed.add(event.actor.name); } + const diagnostics = extractInternalTraceDiagnostics(event); + if (diagnostics.reasoningTokens !== undefined) { + totalReasoningTokens += diagnostics.reasoningTokens; + } + if (isTruncatedFinishReason(diagnostics.finishReason)) { + truncatedEvents += 1; + } } if (session?.agent?.model) modelsUsed.add(session.agent.model); @@ -489,6 +503,8 @@ async function createInternalTracingSink( totalInputTokens: session.summary?.totalInputTokens ?? 0, totalOutputTokens: session.summary?.totalOutputTokens ?? 0, totalCachedInputTokens: session.summary?.totalCachedInputTokens ?? 0, + totalReasoningTokens, + truncatedEvents, totalBytesIn: session.summary?.totalBytesIn ?? undefined, totalBytesOut: session.summary?.totalBytesOut ?? undefined, }; @@ -552,6 +568,14 @@ async function createInternalTracingSink( usage?.cacheReadInputTokens ?? usage?.cache_read_input_tokens, ); + const diagnostics = extractInternalTraceDiagnostics(event); + // Strip the keys `extractInternalTraceDiagnostics` already + // consumed so the same value never lands in both the + // column and the metadata blob. + const restMetadata = { ...(event.metadata ?? {}) } as Record; + delete restMetadata.finishReason; + delete restMetadata.stop_reason; + delete restMetadata.reasoningTokens; const eventDoc: Omit = { sessionId: session.sessionId, @@ -567,14 +591,14 @@ async function createInternalTracingSink( timestamp: event.timestamp ? new Date(event.timestamp) : new Date(), status: event.status ?? undefined, actor: event.actor ?? {}, - // `finishReason` / `reasoningTokens` are top-level SDK - // event fields with no column of their own, so they ride - // in metadata — exactly as the HTTP ingest folds them - // (client-tracing.ts buildEventMetadata). Without this - // an agent hosted BY the console would be the only - // source missing them, which is the worst place for a - // gap: it is the path we control end to end. - metadata: buildInternalEventMetadata(event), + // `finishReason` / `reasoningTokens` are real columns now + // (see `extractInternalTraceDiagnostics`), mirroring the + // HTTP ingest's sibling `extractTraceDiagnostics` + // (client-tracing.ts). Without this an agent hosted BY + // the console would be the only source missing them, + // which is the worst place for a gap: it is the path we + // control end to end. + metadata: restMetadata, sections, modelNames: event.modelNames ?? [], model: event.model ?? undefined, @@ -590,6 +614,8 @@ async function createInternalTracingSink( outputTokens, cachedInputTokens, totalTokens: event.totalTokens ?? undefined, + finishReason: diagnostics.finishReason, + reasoningTokens: diagnostics.reasoningTokens, bytesIn: event.bytesIn ?? undefined, bytesOut: event.bytesOut ?? undefined, requestBytes: event.requestBytes ?? undefined, @@ -611,30 +637,40 @@ async function createInternalTracingSink( }); } - /** - * Fold the SDK's top-level diagnostic fields into `metadata`, mirroring the - * HTTP ingest so both trace sources render identically. - * - * `finishReason` explains a truncated answer (`length` is the usual cause - * of unparseable JSON); `reasoningTokens` is a SUBSET of `outputTokens`, - * recorded for attribution and deliberately never added to the bill. - */ - export function buildInternalEventMetadata(event: InternalTraceEvent): Record { - const metadata: Record = { ...(event.metadata ?? {}) }; - const finishReason = event.finishReason ?? metadata.finishReason; - if (typeof finishReason === 'string' && finishReason.trim() !== '') { - metadata.finishReason = finishReason.trim(); - } - const reasoningTokens = toOptionalNumber( - event.reasoningTokens - ?? event.usage?.reasoningTokens - ?? event.usage?.reasoning_tokens, - ); - if (reasoningTokens !== undefined && reasoningTokens > 0) { - metadata.reasoningTokens = reasoningTokens; - } - return metadata; - } +/** + * Pull the SDK's top-level diagnostic fields off a raw trace event so they can + * be persisted as real `finishReason` / `reasoningTokens` columns instead of + * being buried in the `metadata` JSON blob. + * + * This is the internal-sink twin of the HTTP ingest's `extractTraceDiagnostics` + * (`src/server/api/plugins/client-tracing.ts`) — both paths write to the same + * `agentTracingEvents` table read by the same UI, so they must stay in + * lockstep: a value read from `finishReason` here but from `metadata` there + * (or vice versa) would make one trace source silently poorer than the other. + * + * `finishReason` explains a truncated answer (`length` is the usual cause of + * unparseable JSON); `reasoningTokens` is a SUBSET of `outputTokens`, recorded + * for attribution and deliberately never added to the bill. + */ +export function extractInternalTraceDiagnostics(event: InternalTraceEvent): { + finishReason?: string; + reasoningTokens?: number; +} { + const metadata = event.metadata ?? {}; + const finishReason = normalizeFinishReason( + event.finishReason ?? metadata.finishReason ?? metadata.stop_reason, + ); + const reasoningTokens = toOptionalNumber( + event.reasoningTokens + ?? event.usage?.reasoningTokens + ?? event.usage?.reasoning_tokens + ?? metadata.reasoningTokens, + ); + return { + finishReason, + reasoningTokens: reasoningTokens !== undefined && reasoningTokens > 0 ? reasoningTokens : undefined, + }; +} function toOptionalNumber(value: unknown): number | undefined { if (value === null || value === undefined || value === '') { diff --git a/src/lib/services/models/inferenceService.ts b/src/lib/services/models/inferenceService.ts index 1e83d1e9..42dfdacb 100644 --- a/src/lib/services/models/inferenceService.ts +++ b/src/lib/services/models/inferenceService.ts @@ -26,6 +26,7 @@ import { openAIStreamStopChunk, toOpenAIStreamChunk, summarizeUsage, + extractFinishReason, } from './openaiAdapter'; import { normalizeInferenceError, @@ -1284,6 +1285,9 @@ export async function handleChatCompletion(params: { outputTokens: payload.usage.completion_tokens, cachedInputTokens: payload.usage.cached_tokens, totalTokens: payload.usage.total_tokens, + // Subset of outputTokens — never folded into totalTokens/cost. + reasoningTokens: + payload.usage.completion_tokens_details?.reasoning_tokens, }; // `usage` is only allowed on the wire when the caller asked for // it with `stream_options.include_usage`, and then only on a @@ -1372,6 +1376,7 @@ export async function handleChatCompletion(params: { errorMessage: outputLimitError?.message, latencyMs, usage, + finishReason: terminalFinishReason, }), ); @@ -1417,6 +1422,7 @@ export async function handleChatCompletion(params: { errorMessage, latencyMs, usage: {}, + finishReason: terminalFinishReason, }), ); @@ -1479,6 +1485,7 @@ export async function handleChatCompletion(params: { latencyMs, usage, cacheHit: false, + finishReason: extractFinishReason(aiMessage), }), ); diff --git a/src/lib/services/models/openaiAdapter.ts b/src/lib/services/models/openaiAdapter.ts index 565bf83f..b2dd6b6b 100644 --- a/src/lib/services/models/openaiAdapter.ts +++ b/src/lib/services/models/openaiAdapter.ts @@ -8,6 +8,7 @@ import { ToolMessage, } from '@langchain/core/messages'; import crypto from 'crypto'; +import { normalizeFinishReason } from '@/lib/shared/finishReason'; type MessageContentPart = Record; @@ -45,6 +46,13 @@ interface UsageMetrics { totalTokens?: number; promptTokensDetails?: Record; completionTokensDetails?: Record; + /** + * Reasoning ("thinking") tokens billed as part of the completion. This is + * a SUBSET of `outputTokens`, never an addend — callers must not fold it + * into `totalTokens` or any cost calculation. Recorded for attribution + * only. + */ + reasoningTokens?: number; } interface OpenAIToolCall { @@ -274,6 +282,7 @@ function extractUsage(message: AIMessage | AIMessageChunk): UsageMetrics { 'completionTokensDetail', 'completion_tokens_detail', 'output_token_details', + 'output_tokens_details', ]); const normalizedPromptTokensDetails = promptTokensDetails @@ -295,6 +304,17 @@ function extractUsage(message: AIMessage | AIMessageChunk): UsageMetrics { const nestedCachedTokens = normalizedPromptTokensDetails?.cached_tokens; + // Reasoning tokens are a SUBSET of outputTokens (never an addend) — see + // the `reasoningTokens` doc comment on `UsageMetrics`. Only accept a + // finite, positive count; anything else is treated as "not reported". + const rawReasoningTokens = normalizedCompletionTokensDetails?.reasoning_tokens; + const reasoningTokens = + typeof rawReasoningTokens === 'number' && + Number.isFinite(rawReasoningTokens) && + rawReasoningTokens > 0 + ? rawReasoningTokens + : undefined; + return { inputTokens, outputTokens, @@ -302,9 +322,26 @@ function extractUsage(message: AIMessage | AIMessageChunk): UsageMetrics { totalTokens, promptTokensDetails: normalizedPromptTokensDetails, completionTokensDetails: normalizedCompletionTokensDetails, + reasoningTokens, }; } +/** + * Read the raw provider finish reason off a LangChain message's + * `response_metadata` (the same field `toOpenAIChatResponse` / + * `toOpenAIStreamChunk` read to populate the wire `finish_reason`) and + * normalize it via the shared `normalizeFinishReason` so persistence and + * the response payload agree on the same value. + */ +export function extractFinishReason(message: { + response_metadata?: unknown; +}): string | undefined { + const metadata = + (message.response_metadata as Record | undefined) || {}; + const raw = metadata['finish_reason'] ?? metadata['finishReason']; + return normalizeFinishReason(raw); +} + /** * Reasoning ("thinking") models emit their chain-of-thought separately from the * final answer. Over the OpenAI-compatible Chat Completions wire this arrives as diff --git a/src/lib/services/models/usageLogger.ts b/src/lib/services/models/usageLogger.ts index a8df6d76..2f70e3b3 100644 --- a/src/lib/services/models/usageLogger.ts +++ b/src/lib/services/models/usageLogger.ts @@ -7,6 +7,7 @@ import { redactLogPayload, redactLogString, } from '@/lib/services/logRedaction'; +import { normalizeFinishReason } from '@/lib/shared/finishReason'; const TOKENS_PER_MILLION = 1_000_000; const SECONDS_PER_THOUSAND = 1_000; @@ -27,6 +28,10 @@ export interface TokenUsage { inputCharacters?: number; pages?: number; images?: number; + /** Subset of `outputTokens` (e.g. OpenAI `completion_tokens_details.reasoning_tokens`). + * Recorded for attribution only — never added into `totalTokens` and never + * fed into `calculateCost` / any pricing arithmetic below. */ + reasoningTokens?: number; } function toRecord(value: unknown): Record { @@ -114,12 +119,20 @@ export async function logModelUsage( routing?: IModelUsageRouting; /** Explicit attribution for call sites outside the request ALS scope. */ attribution?: Partial; + /** Raw provider finish reason for this call (e.g. `stop`, `length`, + * `tool_calls`) — a property of the call, not of token usage. Normalized + * via `normalizeFinishReason` before persisting. */ + finishReason?: string; }, ) { const db = await getDatabase(); await db.switchToTenant(tenantDbName); const usage = payload.usage; + // reasoningTokens is a SUBSET of outputTokens (e.g. OpenAI + // `completion_tokens_details.reasoning_tokens`) — recorded below for + // attribution only. It must never be added into totalTokens and never + // flows into calculateCost / pricingSnapshot. const pricingSnapshot = { ...model.pricing, ...calculateCost(model.pricing, usage), @@ -149,6 +162,7 @@ export async function logModelUsage( inputTokens: usage.inputTokens ?? 0, outputTokens: usage.outputTokens ?? 0, cachedInputTokens: usage.cachedInputTokens ?? 0, + reasoningTokens: usage.reasoningTokens ?? 0, totalTokens, costUsd: pricingSnapshot.totalCost, units, @@ -177,10 +191,12 @@ export async function logModelUsage( inputTokens: usage.inputTokens ?? 0, outputTokens: usage.outputTokens ?? 0, cachedInputTokens: usage.cachedInputTokens ?? 0, + reasoningTokens: usage.reasoningTokens, totalTokens, toolCalls: usage.toolCalls ?? 0, cacheHit: payload.cacheHit, pricingSnapshot, routing: payload.routing, + finishReason: normalizeFinishReason(payload.finishReason), }); } diff --git a/src/lib/services/otlpMapper.ts b/src/lib/services/otlpMapper.ts index 66a248fa..e44dc042 100644 --- a/src/lib/services/otlpMapper.ts +++ b/src/lib/services/otlpMapper.ts @@ -13,6 +13,7 @@ import type { IAgentTracingSession, IAgentTracingEvent, } from '@/lib/database/provider/types.base'; +import { isTruncatedFinishReason, normalizeFinishReason } from '@/lib/shared/finishReason'; import { buildResponseFormatSection, normalizeSectionListResponseFormat, @@ -296,9 +297,47 @@ function getConventionTokens(attrs: OtlpKeyValue[] | undefined) { 'gen_ai.usage.cache_read.input_tokens', 'gen_ai.usage.cache_read_input_tokens', ]), + // Subset of outputTokens — excluded from cost/total arithmetic the same + // way cachedInputTokens is a subset of inputTokens, never added on top. + reasoningTokens: firstIntAttr(attrs, [ + 'cognipeer.tokens.reasoning', + 'llm.token_count.completion_details.reasoning', + 'gen_ai.usage.reasoning_tokens', + 'gen_ai.usage.output_tokens_details.reasoning_tokens', + ]), }; } +/** + * First element out of a plural finish-reasons attribute. OTel's + * `gen_ai.response.finish_reasons` is plural because a single span can carry + * multiple choices, and emitters disagree on the wire shape: some JSON-encode + * the array, some just comma-join it. + */ +function firstOfDelimitedOrJsonArray(value: string | undefined): string | undefined { + if (!value) return undefined; + const trimmed = value.trim(); + if (trimmed.startsWith('[')) { + try { + const parsed = JSON.parse(trimmed); + if (Array.isArray(parsed) && typeof parsed[0] === 'string') { + return parsed[0]; + } + } catch { + // Not valid JSON — fall through to comma-split handling below. + } + } + return trimmed.split(',')[0]?.trim(); +} + +/** Finish reason across all three conventions. */ +function getConventionFinishReason(attrs: OtlpKeyValue[] | undefined): string | undefined { + const raw = getStringAttr(attrs, 'cognipeer.finish_reason') + ?? firstOfDelimitedOrJsonArray(getStringAttr(attrs, 'gen_ai.response.finish_reasons')) + ?? getStringAttr(attrs, 'llm.response.finish_reason'); + return normalizeFinishReason(raw); +} + /** Conversation identifier — the closest thing OTel has to a thread id. */ /** Same charset/length the JSON/stream ingest sanitizer enforces * (see `sanitizeTracingMetadata` in `client-tracing.ts`). */ @@ -602,6 +641,8 @@ export function mapOtlpToInternalModels( let totalCachedInputTokens = getIntAttr(rootSpan.attributes, 'cognipeer.session.total_cached_input_tokens') ?? 0; let totalBytesIn = getIntAttr(rootSpan.attributes, 'cognipeer.session.total_bytes_in') ?? 0; let totalBytesOut = getIntAttr(rootSpan.attributes, 'cognipeer.session.total_bytes_out') ?? 0; + let totalReasoningTokens = getIntAttr(rootSpan.attributes, 'cognipeer.session.total_reasoning_tokens') ?? 0; + let truncatedEvents = getIntAttr(rootSpan.attributes, 'cognipeer.session.truncated_events') ?? 0; const modelsUsed = new Set(); const toolsUsed = new Set(); @@ -631,7 +672,9 @@ export function mapOtlpToInternalModels( outputTokens, totalTokens, cachedInputTokens, + reasoningTokens, } = getConventionTokens(span.attributes); + const finishReason = getConventionFinishReason(span.attributes); const requestBytes = getIntAttr(span.attributes, 'cognipeer.bytes.request'); const responseBytes = getIntAttr(span.attributes, 'cognipeer.bytes.response'); const toolExecutionId = getStringAttr(span.attributes, 'cognipeer.tool.execution_id'); @@ -648,6 +691,8 @@ export function mapOtlpToInternalModels( if (totalCachedInputTokens === 0 && cachedInputTokens) totalCachedInputTokens += cachedInputTokens; if (totalBytesIn === 0 && requestBytes) totalBytesIn += requestBytes; if (totalBytesOut === 0 && responseBytes) totalBytesOut += responseBytes; + if (totalReasoningTokens === 0 && reasoningTokens) totalReasoningTokens += reasoningTokens; + if (truncatedEvents === 0 && isTruncatedFinishReason(finishReason)) truncatedEvents += 1; if (model) modelsUsed.add(model); if (actorScope === 'tool' && toolName) toolsUsed.add(toolName); @@ -731,6 +776,8 @@ export function mapOtlpToInternalModels( outputTokens, totalTokens, cachedInputTokens, + reasoningTokens, + finishReason, requestBytes, responseBytes, error: eventError, @@ -782,6 +829,8 @@ export function mapOtlpToInternalModels( totalInputTokens, totalOutputTokens, totalCachedInputTokens, + totalReasoningTokens, + truncatedEvents, totalBytesIn, totalBytesOut, }); diff --git a/src/lib/services/usage/usageEvents.ts b/src/lib/services/usage/usageEvents.ts index 0475bc12..165fe9b7 100644 --- a/src/lib/services/usage/usageEvents.ts +++ b/src/lib/services/usage/usageEvents.ts @@ -104,6 +104,10 @@ export interface UsageEventInput { inputTokens?: number; outputTokens?: number; cachedInputTokens?: number; + /** Subset of `outputTokens` (e.g. OpenAI `completion_tokens_details.reasoning_tokens`); + * never added into `totalTokens` or `costUsd`. Threaded straight into the + * `usage_daily` rollup increment, mirroring `cachedInputTokens`. */ + reasoningTokens?: number; totalTokens?: number; costUsd?: number; /** Service-specific additive counters (pages, audioSeconds, results, ...). */ diff --git a/src/lib/services/usage/usageRollup.ts b/src/lib/services/usage/usageRollup.ts index 5908d3b7eacac5cc0121e7e01467d94b15fdd65e..3b1a344043e13323881619d8aee4859a22e90f0d 100644 GIT binary patch delta 312 zcmZwCv1$TA5C&kdi%NRa_@@acil!FCDus2F6oJ5cJDSCFCfv?l%J>fEK>}wjf}A9zo%#QdnQebF_&C%rQZioH@x0j8o0Yd-5BJ&BlR{>YOkXk`%YxYBYxNFe zty7m161O14CVnP6;xg00G*d9;lvaU2%_Om8;aCMKYLb&BDPr+D@fMLM!o-_7-Q~nj z`oqCW91_bVv9`LwO69d%UV1_XVGcz9t%gI~w$MftPGLPai~Z$e?fmk3*J$4SWy|g_ Nc>US9E*`GFD@R4jaM1t& delta 22 ecmdmDyU%LFKc3AJynIZXg$2C1H=mV$&IABvGYC8Y diff --git a/src/lib/shared/finishReason.ts b/src/lib/shared/finishReason.ts new file mode 100644 index 00000000..6333c8fc --- /dev/null +++ b/src/lib/shared/finishReason.ts @@ -0,0 +1,68 @@ +/** + * `finishReason` normalization — shared between server persistence code and + * React client components (dependency-free: no `@/lib/database`, no node + * builtins), so the exact same rules apply wherever a raw provider value is + * turned into the string we store/compare. + * + * We normalize casing/whitespace but never map provider synonyms onto each + * other (e.g. OpenAI's `length` vs Anthropic's `max_tokens` stay distinct) — + * that mapping is a display/analytics concern for a later phase, and + * collapsing it here would make the raw persisted value non-recoverable. + */ + +/** + * Trim + lowercase a raw provider finish reason and validate its shape. + * Returns `undefined` for anything that isn't a plausible finish-reason + * token (empty, non-string, or containing characters no known provider + * uses) rather than persisting garbage that would never match the constant + * sets below. + */ +export function normalizeFinishReason(value: unknown): string | undefined { + if (typeof value !== 'string') return undefined; + const normalized = value.trim().toLowerCase(); + if (!normalized) return undefined; + return /^[a-z0-9_.:-]{1,64}$/.test(normalized) ? normalized : undefined; +} + +/** Finish reasons that mean the model completed its turn on its own terms. */ +export const NORMAL_FINISH_REASONS: ReadonlySet = new Set([ + 'stop', + 'end_turn', + 'tool_calls', + 'function_call', + 'tool_use', + 'stop_sequence', + 'completed', +]); + +/** + * Finish reasons that mean generation was cut off by a token/length limit + * rather than the model choosing to stop — the usual explanation for a + * truncated or unparseable answer (e.g. a JSON response missing its closing + * brace), so these are tracked separately from other abnormal stops. + */ +export const TRUNCATION_FINISH_REASONS: ReadonlySet = new Set([ + 'length', + 'max_tokens', + 'model_length', + 'output_token_limit', + 'max_output_tokens', +]); + +/** + * True for any defined finish reason outside the "completed normally" set — + * i.e. worth surfacing to a caller auditing why a response looks off, + * whether that's a length cutoff, a content filter, or an error abort. + */ +export function isAbnormalFinishReason(value?: string): boolean { + return value !== undefined && !NORMAL_FINISH_REASONS.has(value); +} + +/** + * True when the finish reason specifically indicates a token/length cutoff — + * the subset of abnormal reasons most likely to explain a truncated or + * unparseable answer. + */ +export function isTruncatedFinishReason(value?: string): boolean { + return value !== undefined && TRUNCATION_FINISH_REASONS.has(value); +} diff --git a/src/server/api/plugins/client-tracing.ts b/src/server/api/plugins/client-tracing.ts index cce184db..bb2e0fab 100644 --- a/src/server/api/plugins/client-tracing.ts +++ b/src/server/api/plugins/client-tracing.ts @@ -25,6 +25,7 @@ import { normalizeSectionListToolDefinitions, TOOL_DEFINITIONS_SECTION_KIND, } from '@/lib/services/tracingToolDefinitions'; +import { isTruncatedFinishReason, normalizeFinishReason } from '@/lib/shared/finishReason'; import { getApiTokenContextForRequest, readJsonBody, @@ -47,6 +48,10 @@ type TracingUsage = { /** Subset of the output count — recorded, never re-billed. */ reasoningTokens?: number | null; reasoning_tokens?: number | null; + /** OpenAI/Azure raw usage shape: reasoning tokens nested under a details bag. */ + completion_tokens_details?: { reasoning_tokens?: number | null } | null; + /** OTel GenAI convention's mirror of the same nested shape. */ + output_tokens_details?: { reasoning_tokens?: number | null } | null; }; type TracingActorPayload = Record & { @@ -81,6 +86,13 @@ type TracingEventPayload = { label?: string | null; metadata?: Record & { finishReason?: string | null; + /** Python-style SDKs that only wrote the snake_case field. */ + finish_reason?: string | null; + /** Claude Agent SDK integration writes Anthropic's own vocabulary here. */ + stop_reason?: string | null; + /** OTel exporter's plural form — a JSON array or comma-joined string. */ + finishReasons?: string[] | string | null; + reasoningTokens?: number | null; modelName?: string | null; usage?: TracingUsage; }; @@ -204,6 +216,8 @@ function aggregateEvents(events: IAgentTracingEvent[]) { let totalDurationMs = 0; let totalInputTokens = 0; let totalOutputTokens = 0; + let totalReasoningTokens = 0; + let truncatedEvents = 0; for (const event of events) { if (typeof event.type === 'string') { @@ -224,6 +238,8 @@ function aggregateEvents(events: IAgentTracingEvent[]) { totalBytesIn += typeof event.requestBytes === 'number' ? event.requestBytes : 0; totalBytesOut += typeof event.responseBytes === 'number' ? event.responseBytes : 0; totalDurationMs += typeof event.durationMs === 'number' ? event.durationMs : 0; + totalReasoningTokens += typeof event.reasoningTokens === 'number' ? event.reasoningTokens : 0; + if (isTruncatedFinishReason(event.finishReason)) truncatedEvents += 1; if (event.status === 'error') { errors.push({ @@ -249,6 +265,8 @@ function aggregateEvents(events: IAgentTracingEvent[]) { totalEvents: events.length, totalInputTokens, totalOutputTokens, + totalReasoningTokens, + truncatedEvents, }; } @@ -450,30 +468,73 @@ function collectEventToolNames(event: TracingEventPayload): string[] { return Array.from(names); } +/** + * Pull `finishReason` / `reasoningTokens` off a raw ingest event — they are + * now first-class columns on `IAgentTracingEvent`, not metadata. Tolerant of + * every shape a real producer SDK sends, because the fallbacks below each + * correspond to one upstream integration that never populated the top-level + * field: + * - `event.metadata.finish_reason` — Python-style SDKs that only ever wrote + * the snake_case form; + * - `event.metadata.stop_reason` — the Claude Agent SDK integration, which + * writes Anthropic's own vocabulary rather than normalizing it first; + * - `event.metadata.finishReasons` (plural) — the OTel exporter, which + * ships a JSON array or comma-joined string because a single export can + * bundle multiple choices; the first element wins; + * - `event.usage.completion_tokens_details.reasoning_tokens` / + * `.output_tokens_details.reasoning_tokens` — raw OpenAI/Azure and OTel + * GenAI usage payloads passed through verbatim instead of being + * flattened by the sender. + */ +export function extractTraceDiagnostics(event: TracingEventPayload): { + finishReason?: string; + reasoningTokens?: number; +} { + const metadata = event.metadata; + const usage = event.usage; + + const rawFinishReasons = metadata?.finishReasons; + const firstOfFinishReasons = Array.isArray(rawFinishReasons) + ? rawFinishReasons[0] + : (typeof rawFinishReasons === 'string' ? rawFinishReasons.split(',')[0] : undefined); + + const finishReason = normalizeFinishReason( + event.finishReason + ?? metadata?.finishReason + ?? metadata?.finish_reason + ?? metadata?.stop_reason + ?? firstOfFinishReasons, + ); + + const rawReasoningTokens = event.reasoningTokens + ?? usage?.reasoningTokens + ?? usage?.reasoning_tokens + ?? usage?.completion_tokens_details?.reasoning_tokens + ?? usage?.output_tokens_details?.reasoning_tokens + ?? metadata?.reasoningTokens; + const reasoningTokens = Number(rawReasoningTokens); + + return { + finishReason, + reasoningTokens: Number.isFinite(reasoningTokens) && reasoningTokens > 0 ? reasoningTokens : undefined, + }; +} + function buildEventMetadata(event: TracingEventPayload, sections: Array>): Record { - const metadata = { ...(event.metadata || {}) }; + const metadata: Record = { ...(event.metadata || {}) }; + // finishReason / reasoningTokens are now first-class columns (see + // extractTraceDiagnostics above) — strip the keys this used to fold them + // from so the same value never gets persisted twice. + delete metadata.finishReason; + delete metadata.finish_reason; + delete metadata.stop_reason; + delete metadata.finishReasons; + delete metadata.reasoningTokens; + const toolDetails = getEventToolDetails(event, sections); if (toolDetails) { metadata.toolDetails = toolDetails; } - // Two fields that explain a bad answer and have nowhere else to live: - // • finishReason — `length` is the single most common cause of a truncated - // or unparseable structured response; without it that failure looks - // exactly like a model that simply answered badly; - // • reasoningTokens — a SUBSET of outputTokens, and on a reasoning model - // routinely most of the output bill while being invisible in the text. - // They ride in `metadata` rather than as columns: it is a JSON blob on both - // providers, so this needs no migration and cannot drift between cloud and - // on-prem. reasoningTokens is deliberately NOT fed to the cost pipeline — - // it is already inside outputTokens, and adding it would double-count. - const finishReason = event.finishReason ?? event.metadata?.finishReason; - if (typeof finishReason === 'string' && finishReason.trim() !== '') { - metadata.finishReason = finishReason.trim(); - } - const reasoningTokens = Number(event.reasoningTokens ?? event.usage?.reasoningTokens ?? event.usage?.reasoning_tokens); - if (Number.isFinite(reasoningTokens) && reasoningTokens > 0) { - metadata.reasoningTokens = reasoningTokens; - } return metadata; } @@ -693,6 +754,8 @@ export const clientTracingApiPlugin: FastifyPluginAsync = async (app) => { totalDurationMs: stats.totalDurationMs, totalInputTokens: stats.totalInputTokens, totalOutputTokens: stats.totalOutputTokens, + totalReasoningTokens: stats.totalReasoningTokens, + truncatedEvents: stats.truncatedEvents, }; const mergedSession = { ...session, @@ -716,6 +779,8 @@ export const clientTracingApiPlugin: FastifyPluginAsync = async (app) => { totalEvents: stats.totalEvents, totalInputTokens: stats.totalInputTokens, totalOutputTokens: stats.totalOutputTokens, + totalReasoningTokens: stats.totalReasoningTokens, + truncatedEvents: stats.truncatedEvents, traceId: existing?.traceId || session.traceId, }; @@ -812,6 +877,13 @@ export const clientTracingApiPlugin: FastifyPluginAsync = async (app) => { const modelsUsed = new Set(); const toolsUsed = new Set(); + // Rolled up here rather than read off `payload.summary`: the batch + // endpoint trusts the sender for the other totals, but no producer SDK + // reports these two yet, so a summary-only read would leave every + // batch-ingested session at zero while the per-event columns say + // otherwise. + let batchReasoningTokens = 0; + let batchTruncatedEvents = 0; events.forEach((event) => { if (event?.model) modelsUsed.add(event.model); if (event?.modelName) modelsUsed.add(event.modelName); @@ -819,6 +891,9 @@ export const clientTracingApiPlugin: FastifyPluginAsync = async (app) => { for (const toolName of collectEventToolNames(event)) { toolsUsed.add(toolName); } + const diagnostics = extractTraceDiagnostics(event); + batchReasoningTokens += diagnostics.reasoningTokens ?? 0; + if (isTruncatedFinishReason(diagnostics.finishReason)) batchTruncatedEvents += 1; }); if (payload?.agent?.model) { @@ -856,7 +931,11 @@ export const clientTracingApiPlugin: FastifyPluginAsync = async (app) => { totalEvents: events.length, totalInputTokens: getSummaryNumber(payload.summary, 'totalInputTokens') ?? 0, totalOutputTokens: getSummaryNumber(payload.summary, 'totalOutputTokens') ?? 0, + totalReasoningTokens: + getSummaryNumber(payload.summary, 'totalReasoningTokens') ?? batchReasoningTokens, traceId: typeof payload.traceId === 'string' ? payload.traceId : undefined, + truncatedEvents: + getSummaryNumber(payload.summary, 'truncatedEvents') ?? batchTruncatedEvents, }; const existing = await db.findAgentTracingSessionById(sessionId, ctx.projectId); @@ -934,6 +1013,7 @@ export const clientTracingApiPlugin: FastifyPluginAsync = async (app) => { const metadata = buildEventMetadata(event, sections); const toolDetails = getEventToolDetails(event, sections); const usage = getEventUsage(event); + const diagnostics = extractTraceDiagnostics(event); const inputTokens = event?.inputTokens ?? usage?.inputTokens ?? usage?.input_tokens ?? undefined; const outputTokens = @@ -955,6 +1035,7 @@ export const clientTracingApiPlugin: FastifyPluginAsync = async (app) => { cachedInputTokens, durationMs: event.durationMs ?? undefined, error: toErrorRecord(event.error), + finishReason: diagnostics.finishReason, id: event.id ?? undefined, inputTokens, label: event.label ?? undefined, @@ -964,6 +1045,7 @@ export const clientTracingApiPlugin: FastifyPluginAsync = async (app) => { outputTokens, parentSpanId: typeof event.parentSpanId === 'string' ? event.parentSpanId : undefined, projectId: ctx.projectId, + reasoningTokens: diagnostics.reasoningTokens, requestBytes: event.requestBytes ?? undefined, responseBytes: event.responseBytes ?? undefined, sections, @@ -1196,6 +1278,7 @@ export const clientTracingApiPlugin: FastifyPluginAsync = async (app) => { const metadata = buildEventMetadata(event, sections); const toolDetails = getEventToolDetails(event, sections); const usage = getEventUsage(event); + const diagnostics = extractTraceDiagnostics(event); const inputTokens = event?.inputTokens ?? usage?.inputTokens ?? usage?.input_tokens ?? undefined; const outputTokens = @@ -1223,6 +1306,7 @@ export const clientTracingApiPlugin: FastifyPluginAsync = async (app) => { cachedInputTokens, durationMs: event.durationMs ?? undefined, error: toErrorRecord(event.error), + finishReason: diagnostics.finishReason, id: event.id ?? undefined, inputTokens, label: event.label ?? undefined, @@ -1232,6 +1316,7 @@ export const clientTracingApiPlugin: FastifyPluginAsync = async (app) => { outputTokens, parentSpanId: typeof event.parentSpanId === 'string' ? event.parentSpanId : undefined, projectId: ctx.projectId, + reasoningTokens: diagnostics.reasoningTokens, requestBytes: event.requestBytes ?? undefined, responseBytes: event.responseBytes ?? undefined, sections, @@ -1265,9 +1350,11 @@ export const clientTracingApiPlugin: FastifyPluginAsync = async (app) => { cachedInputTokens, durationMs: event.durationMs ?? undefined, eventType: event.type ?? undefined, + finishReason: diagnostics.finishReason, inputTokens, modelsUsed: models, outputTokens, + reasoningTokens: diagnostics.reasoningTokens, toolsUsed: collectEventToolNames(event), }, ctx.projectId); }); diff --git a/src/server/api/plugins/tracing.ts b/src/server/api/plugins/tracing.ts index 4cffc72f..2faf334e 100644 --- a/src/server/api/plugins/tracing.ts +++ b/src/server/api/plugins/tracing.ts @@ -75,6 +75,9 @@ export const tracingApiPlugin: FastifyPluginAsync = async (app) => { skip: query.skip || '0', status: query.status, to: query.to, + // Only sessions with truncatedEvents > 0 (a truncated/cut-off model + // response somewhere in the session). + truncated: query.truncated === 'true' ? true : undefined, ...metadataFilter, }); diff --git a/src/server/api/routes/client/v1/traces/route.ts b/src/server/api/routes/client/v1/traces/route.ts index b6e5eefe..04be59c6 100644 --- a/src/server/api/routes/client/v1/traces/route.ts +++ b/src/server/api/routes/client/v1/traces/route.ts @@ -24,6 +24,7 @@ import { mapOtlpToInternalModels, type OtlpExportTraceServiceRequest, } from '@/lib/services/otlpMapper'; +import { isTruncatedFinishReason, normalizeFinishReason } from '@/lib/shared/finishReason'; const logger = createLogger('client-otlp-traces'); @@ -69,6 +70,9 @@ function aggregateEvents(events: IAgentTracingEvent[]) { let totalInputTokens = 0; let totalOutputTokens = 0; let totalCachedInputTokens = 0; + // Subset of totalOutputTokens — never added into totalTokens or cost math. + let totalReasoningTokens = 0; + let truncatedEvents = 0; let totalBytesIn = 0; let totalBytesOut = 0; let totalDurationMs = 0; @@ -86,6 +90,7 @@ function aggregateEvents(events: IAgentTracingEvent[]) { const inputTokens = typeof event.inputTokens === 'number' ? event.inputTokens : 0; const outputTokens = typeof event.outputTokens === 'number' ? event.outputTokens : 0; const cachedInputTokens = typeof event.cachedInputTokens === 'number' ? event.cachedInputTokens : 0; + const reasoningTokens = typeof event.reasoningTokens === 'number' ? event.reasoningTokens : 0; const requestBytes = typeof event.requestBytes === 'number' ? event.requestBytes : 0; const responseBytes = typeof event.responseBytes === 'number' ? event.responseBytes : 0; const durationMs = typeof event.durationMs === 'number' ? event.durationMs : 0; @@ -93,10 +98,15 @@ function aggregateEvents(events: IAgentTracingEvent[]) { totalInputTokens += inputTokens; totalOutputTokens += outputTokens; totalCachedInputTokens += cachedInputTokens; + totalReasoningTokens += reasoningTokens; totalBytesIn += requestBytes; totalBytesOut += responseBytes; totalDurationMs += durationMs; + if (isTruncatedFinishReason(normalizeFinishReason(event.finishReason))) { + truncatedEvents += 1; + } + const status = typeof event.status === 'string' ? event.status : undefined; if (status === 'error') { errors.push({ @@ -115,6 +125,8 @@ function aggregateEvents(events: IAgentTracingEvent[]) { totalInputTokens, totalOutputTokens, totalCachedInputTokens, + totalReasoningTokens, + truncatedEvents, totalBytesIn, totalBytesOut, totalDurationMs, @@ -341,6 +353,8 @@ const _POST = async (request: NextRequest) => { totalInputTokens: stats.totalInputTokens, totalOutputTokens: stats.totalOutputTokens, totalCachedInputTokens: stats.totalCachedInputTokens, + totalReasoningTokens: stats.totalReasoningTokens, + truncatedEvents: stats.truncatedEvents, totalBytesIn: stats.totalBytesIn, totalBytesOut: stats.totalBytesOut, eventCounts: stats.eventCounts, @@ -360,6 +374,8 @@ const _POST = async (request: NextRequest) => { totalInputTokens: stats.totalInputTokens, totalOutputTokens: stats.totalOutputTokens, totalCachedInputTokens: stats.totalCachedInputTokens, + totalReasoningTokens: stats.totalReasoningTokens, + truncatedEvents: stats.truncatedEvents, totalBytesIn: stats.totalBytesIn, totalBytesOut: stats.totalBytesOut, modelsUsed: stats.modelsUsed,