From e56c58c8f84121f03d9088965599b87320dc4287 Mon Sep 17 00:00:00 2001 From: Shawn Zhang Date: Sat, 19 Sep 2026 00:04:44 +0800 Subject: [PATCH 1/2] feat(metrics)!: drop session.id from metric labels, record LOC at session end MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Remove the `session.id` attribute from all 15 metric instruments. It was the dominant source of Prometheus series growth: every label combination is a separate time series and a histogram multiplies it by its bucket count (20 at the SDK's default boundaries), the SDK caps a metric at 2000 attribute sets and silently collapses the rest into `otel.metric.overflow`, and cumulative aggregation never evicts — so a long-lived process re-exports every session it has ever seen on every export, indefinitely. `session.id` is unchanged on spans and OTLP log events, where per-session drill-down belongs and high cardinality is acceptable. Replace the `lines_of_code.total` Gauge with a `session.lines_of_code.total` Histogram. A Gauge cannot carry a per-session dimension: with LastValue aggregation the SDK collapses every session into one attribute set and exports whichever session wrote last, so simply dropping `session.id` from the Gauge would have made it silently wrong. The histogram is recorded once when the session ends (`session.deleted`, or `session.error`), not on `session.idle`. `session.idle` fires once per *turn* while opencode's `session.diff` is cumulative for the whole session, so recording there added the running session total once per turn — a four-turn session reported its LOC four times over. This adds handling for the `session.deleted` event, which the plugin previously ignored. Fixing that also fixes the same defect in the gross counter: the per-session diff baseline is no longer discarded on every idle, so a later turn now emits the true delta instead of treating the whole session cumulative as new churn. The net values are also attached to the run and session spans as `session.total_lines_added` / `session.total_lines_removed`, on both the idle and error paths, so the information survives with traces enabled. Tests: add a cardinality guard asserting no metric data point carries `session.id` and that every handler-reachable log event still does, a non-vacuity check that fails if an instrument is missing from the test double, a multi-turn regression test for the over-count, and a test pinning the instrument names and kinds, which are the disable-metrics keys. BREAKING CHANGE: `session.id` is no longer present on any metric data point. Dashboards and alerts that group or filter metrics by `session.id` must move to traces or logs, or to the `project.id` / `model` / `agent` attributes that remain. The `opencode.lines_of_code.total` Gauge is removed and replaced by the `opencode.session.lines_of_code.total` Histogram, which exports as `opencode_session_lines_of_code_total_bucket` / `_sum` / `_count` (adjusting for `OPENCODE_METRIC_PREFIX`). Its `OPENCODE_DISABLE_METRICS` suffix is now `session.lines_of_code.total`; the old suffix `lines_of_code.total` no longer matches anything and is silently ignored. The new histogram is emitted only when a session ends, so sessions that are never deleted or errored report no line totals at all. Co-Authored-By: Claude Code --- README.md | 19 +- src/handlers/activity.ts | 32 ++-- src/handlers/message.ts | 22 ++- src/handlers/session.ts | 80 ++++++++- src/index.ts | 7 +- src/otel.ts | 16 +- src/types.ts | 6 +- tests/handlers/activity.test.ts | 30 +--- tests/handlers/disabled-metrics.test.ts | 5 +- tests/handlers/message.test.ts | 12 +- tests/handlers/metric-cardinality.test.ts | 200 ++++++++++++++++++++++ tests/handlers/session.test.ts | 137 ++++++++++++++- tests/handlers/spans.test.ts | 51 ++++++ tests/helpers.ts | 22 +-- tests/otel.test.ts | 58 ++++++- 15 files changed, 588 insertions(+), 109 deletions(-) create mode 100644 tests/handlers/metric-cardinality.test.ts diff --git a/README.md b/README.md index 36ae0a7..6ab5941 100644 --- a/README.md +++ b/README.md @@ -38,8 +38,8 @@ An [opencode](https://opencode.ai) plugin that exports telemetry via OpenTelemet | `opencode.session.count` | Counter | Incremented on each `session.created` event | | `opencode.token.usage` | Counter | Per token type: `input`, `output`, `reasoning`, `cacheRead`, `cacheCreation` | | `opencode.cost.usage` | Counter | USD cost per completed assistant message | -| `opencode.lines_of_code.count` | Counter | **Gross positive churn, not a net total.** Emits the positive delta of `additions`/`deletions` since the previous `session.diff` for the same session; negative deltas (when opencode's cumulative `additions` or `deletions` shrinks vs. the last event) are dropped. Summing the counter therefore reports gross lines added/removed across forward transitions — it does *not* reconcile back to the session's current state after any revert (full or partial). Intra-message rewrites that opencode collapses in its per-message cumulative are not visible here at all. Use `opencode.lines_of_code.total` for the authoritative live cumulative. | -| `opencode.lines_of_code.total` | Gauge | **Authoritative live cumulative lines added/removed for the session.** Refreshed on every `session.diff` with opencode's current cumulative value. Drops back to `0` if opencode reports a revert to baseline, and tracks partial reverts faithfully. Query this (not the counter) to answer "what does this session currently amount to". | +| `opencode.lines_of_code.count` | Counter | **Gross positive churn, not a net total.** Emits the positive delta of `additions`/`deletions` since the previous `session.diff` for the same session; negative deltas (when opencode's cumulative `additions` or `deletions` shrinks vs. the last event) are dropped. Summing the counter therefore reports gross lines added/removed across forward transitions — it does *not* reconcile back to the session's current state after any revert (full or partial). Intra-message rewrites that opencode collapses in its per-message cumulative are not visible here at all. Net per-session totals are reported by `opencode.session.lines_of_code.total` when the session ends. | +| `opencode.session.lines_of_code.total` | Histogram | **Net lines added/removed per session, recorded once when the session ends** (`session.deleted`, or `session.error` if the session errored first) from opencode's final cumulative `session.diff`. Two observations per session, split by `type=added` / `type=removed`. Because it reads the cumulative rather than the deltas, it tracks partial and full reverts faithfully — unlike the gross counter. It is deliberately **not** recorded on `session.idle`: idle fires once per *turn*, and opencode's `session.diff` is cumulative for the whole session, so recording there would add the running session total once per turn. The same values are attached to the run and session spans as `session.total_lines_added` / `session.total_lines_removed`. | | `opencode.commit.count` | Counter | Git commits detected via bash tool | | `opencode.tool.duration` | Histogram | Tool execution time in milliseconds | | `opencode.cache.count` | Counter | Cache activity per message: `type=cacheRead` or `type=cacheCreation` | @@ -49,6 +49,9 @@ An [opencode](https://opencode.ai) plugin that exports telemetry via OpenTelemet | `opencode.session.cost.total` | Histogram | Total cost per session in USD, recorded on idle | | `opencode.model.usage` | Counter | Messages per model and provider | | `opencode.retry.count` | Counter | API retries observed via `session.status` events | +| `opencode.subtask.count` | Counter | Sub-agent invocations observed via `subtask` message parts | + +All metrics are **low-cardinality by design**. `session.id` is deliberately *not* a metric label — it appears only on spans and log events, where per-session drill-down belongs and high cardinality is acceptable. Metric labels are limited to bounded dimensions (`project.id`, `model`, `provider`, `agent`, `agent.type`, `type`, `tool_name`, `success`, `is_subagent`) plus anything you add yourself via `OPENCODE_SPAN_ATTRIBUTES`. Keep those bounded too: every distinct label combination is a separate time series, and a histogram multiplies it by its bucket count (20 series per combination at the default boundaries). ### Log events @@ -63,6 +66,7 @@ An [opencode](https://opencode.ai) plugin that exports telemetry via OpenTelemet | `tool_result` | Tool completed or errored (duration, success, output size) | | `tool_decision` | Permission prompt answered (accept/reject) | | `commit` | Git commit detected | +| `subtask_invoked` | Sub-agent invoked (includes `agent`, `description`, `prompt_length`) | ## Installation @@ -105,7 +109,7 @@ The environment variables (set them in your shell profile — `~/.zshrc`, `~/.ba | `OPENCODE_OTLP_HEADERS` | *(unset)* | Comma-separated `key=value` headers added to all OTLP exports. **Keep out of version control — may contain sensitive auth tokens.** | | `OPENCODE_OTLP_HEADERS_HELPER` | *(unset)* | Executable script/binary that returns dynamic OTLP headers as JSON after an auth failure. Helper headers override `OPENCODE_OTLP_HEADERS`. | | `OPENCODE_RESOURCE_ATTRIBUTES` | *(unset)* | Comma-separated `key=value` pairs merged into the OTel resource. Example: `service.version=1.2.3,deployment.environment=production` | -| `OPENCODE_SPAN_ATTRIBUTES` | *(unset)* | Comma-separated `key=value` pairs attached to every emitted span, log event, and metric data point. Example: `team=platform,deployment.environment=production` | +| `OPENCODE_SPAN_ATTRIBUTES` | *(unset)* | Comma-separated `key=value` pairs attached to every emitted span, log event, and metric data point. Example: `team=platform,deployment.environment=production`. **Keep values low-cardinality** — they become metric labels, so an unbounded value (a session ID, request ID, or user ID) reintroduces the series explosion the plugin avoids elsewhere. | | `OPENCODE_OTLP_METRICS_TEMPORALITY` | *(unset)* | Metrics aggregation temporality: `delta`, `cumulative`, or `lowmemory`. Required for Datadog (`delta`). Copied to `OTEL_EXPORTER_OTLP_METRICS_TEMPORALITY_PREFERENCE`. | | `OPENCODE_TRACEPARENT` | *(unset)* | W3C [`traceparent`](https://www.w3.org/TR/trace-context/#traceparent-header) string. When set, all spans are parented under this remote context so opencode traces nest inside a caller's trace (e.g. a CI job). Invalid values are logged and ignored. Note: with the default `ParentBased` sampler, a value with the sampled flag off (`...-00`) suppresses all trace export. | | `OPENCODE_TRACESTATE` | *(unset)* | W3C [`tracestate`](https://www.w3.org/TR/trace-context/#tracestate-header) string, parsed alongside `OPENCODE_TRACEPARENT` and attached to the remote parent context. Ignored unless a valid `OPENCODE_TRACEPARENT` is also set. | @@ -191,6 +195,8 @@ export OPENCODE_SPAN_ATTRIBUTES="team=platform,deployment.environment=production - Use `OPENCODE_RESOURCE_ATTRIBUTES` for producer metadata on the OTel Resource. - Use `OPENCODE_SPAN_ATTRIBUTES` for attributes that need to appear on each span, log event, and metric data point for filtering or grouping in backends. +> **Watch the cardinality.** These pairs land on every metric data point as labels, so their values are multiplied by every other label and by the bucket count of each histogram. Use bounded values (`team`, `deployment.environment`, `service.version`) and avoid per-request or per-user values. A high-cardinality value here has exactly the same effect as the `session.id` label this plugin deliberately keeps off metrics — the only difference is that the plugin cannot bound it for you, so it is your configuration rather than the plugin that decides how many series get created. + ### Dynamic headers Use `OPENCODE_OTLP_HEADERS_HELPER` when your collector requires short-lived authentication tokens. When this is set, the plugin prewarms the helper once during startup so the first export can use fresh credentials. If a later OTLP export fails with an authentication error (`401`/`403` for HTTP or `UNAUTHENTICATED`/`PERMISSION_DENIED` for gRPC), the plugin refreshes headers again, rebuilds the exporter, and retries the failed export once. @@ -241,8 +247,8 @@ export OPENCODE_DISABLE_METRICS="retry.count" # Disable multiple metrics export OPENCODE_DISABLE_METRICS="cache.count,session.duration,session.token.total,session.cost.total,model.usage,retry.count,message.count" -# Disable the new per-session cumulative gauge while keeping the delta counter -export OPENCODE_DISABLE_METRICS="lines_of_code.total" +# Disable the per-session net LOC histogram while keeping the gross churn counter +export OPENCODE_DISABLE_METRICS="session.lines_of_code.total" ``` #### opencode-only metrics @@ -250,13 +256,14 @@ export OPENCODE_DISABLE_METRICS="lines_of_code.total" The following metrics are specific to opencode and have no equivalent in Claude Code's built-in monitoring. If you are using a Claude Code dashboard and want to avoid cluttering it with opencode-only metrics, you can disable them: ```bash -export OPENCODE_DISABLE_METRICS="cache.count,session.duration,session.token.total,session.cost.total,model.usage,retry.count,message.count" +export OPENCODE_DISABLE_METRICS="cache.count,session.duration,session.token.total,session.cost.total,model.usage,retry.count,message.count,session.lines_of_code.total" ``` | Metric suffix | Why it's opencode-only | |---------------|------------------------| | `cache.count` | Tracks cache read/write activity as occurrence counts — not a Claude Code signal | | `session.duration` | Session wall-clock duration — not emitted by Claude Code | +| `session.lines_of_code.total` | Per-session net LOC histogram recorded when the session ends — not emitted by Claude Code | | `session.token.total` | Per-session token histogram — not emitted by Claude Code | | `session.cost.total` | Per-session cost histogram — not emitted by Claude Code | | `model.usage` | Per-model message counter — not emitted by Claude Code | diff --git a/src/handlers/activity.ts b/src/handlers/activity.ts index 7ef47df..c30120c 100644 --- a/src/handlers/activity.ts +++ b/src/handlers/activity.ts @@ -4,19 +4,18 @@ import { agentAttrs, getSessionAgentMeta, isMetricEnabled, setBoundedMap } from import type { HandlerContext } from "../types.ts" /** - * Records lines-added/removed for a `session.diff` event. opencode publishes each event - * with the cumulative session diff (first snapshot → latest), so we emit two instruments: - * `opencode.lines_of_code.count` (Counter) receives only the *positive* per-event delta - * for each dimension (additions, deletions). Negative deltas — opencode reporting a smaller - * cumulative for a dimension than the previous event — are dropped, so the counter reports - * gross positive churn and does not reconcile to net after any revert (full or partial). - * `opencode.lines_of_code.total` (Gauge) mirrors opencode's current cumulative value on - * every event and is the authoritative live view. + * Records gross positive line churn for a `session.diff` event. opencode publishes each event + * with the cumulative session diff (first snapshot → latest), so `opencode.lines_of_code.count` + * (Counter) receives only the *positive* per-event delta for each dimension (additions, + * deletions). Negative deltas — opencode reporting a smaller cumulative for a dimension than + * the previous event — are dropped, so the counter reports gross positive churn and does not + * reconcile to net after any revert (full or partial). The cumulative totals are still tracked + * in `sessionDiffTotals` and reported as net per-session values by + * `opencode.session.lines_of_code.total` on `session.idle`. */ export function handleSessionDiff(e: EventSessionDiff, ctx: HandlerContext) { const sessionID = e.properties.sessionID const linesEnabled = isMetricEnabled("lines_of_code.count", ctx) - const totalEnabled = isMetricEnabled("lines_of_code.total", ctx) let totalAdded = 0 let totalRemoved = 0 for (const fileDiff of e.properties.diff) { @@ -30,20 +29,14 @@ export function handleSessionDiff(e: EventSessionDiff, ctx: HandlerContext) { const nextTotals = { additions: totalAdded, deletions: totalRemoved } setBoundedMap(ctx.sessionDiffTotals, sessionID, nextTotals) - const baseAttrs = { ...ctx.commonAttrs, "session.id": sessionID } - if (linesEnabled) { if (deltaAdded > 0) { - ctx.instruments.linesCounter.add(deltaAdded, { ...baseAttrs, type: "added" }) + ctx.instruments.linesCounter.add(deltaAdded, { ...ctx.commonAttrs, type: "added" }) } if (deltaRemoved > 0) { - ctx.instruments.linesCounter.add(deltaRemoved, { ...baseAttrs, type: "removed" }) + ctx.instruments.linesCounter.add(deltaRemoved, { ...ctx.commonAttrs, type: "removed" }) } } - if (totalEnabled) { - ctx.instruments.linesTotalGauge.record(totalAdded, { ...baseAttrs, type: "added" }) - ctx.instruments.linesTotalGauge.record(totalRemoved, { ...baseAttrs, type: "removed" }) - } ctx.log("debug", "otel: lines_of_code metrics updated", { sessionID, @@ -65,10 +58,7 @@ export function handleCommandExecuted(e: EventCommandExecuted, ctx: HandlerConte const { agentName, agentType } = getSessionAgentMeta(e.properties.sessionID, ctx) if (isMetricEnabled("commit.count", ctx)) { - ctx.instruments.commitCounter.add(1, { - ...ctx.commonAttrs, - "session.id": e.properties.sessionID, - }) + ctx.instruments.commitCounter.add(1, ctx.commonAttrs) ctx.log("debug", "otel: commit counter incremented", { sessionID: e.properties.sessionID }) } ctx.emitLog({ diff --git a/src/handlers/message.ts b/src/handlers/message.ts index 248228a..ebb0151 100644 --- a/src/handlers/message.ts +++ b/src/handlers/message.ts @@ -75,32 +75,32 @@ export function handleMessageUpdated(e: EventMessageUpdated, ctx: HandlerContext if (isMetricEnabled("token.usage", ctx)) { const { tokenCounter } = ctx.instruments - tokenCounter.add(assistant.tokens.input, { ...ctx.commonAttrs, "session.id": sessionID, model: modelID, agent, type: "input" }) - tokenCounter.add(assistant.tokens.output, { ...ctx.commonAttrs, "session.id": sessionID, model: modelID, agent, type: "output" }) - tokenCounter.add(assistant.tokens.reasoning, { ...ctx.commonAttrs, "session.id": sessionID, model: modelID, agent, type: "reasoning" }) - tokenCounter.add(assistant.tokens.cache.read, { ...ctx.commonAttrs, "session.id": sessionID, model: modelID, agent, type: "cacheRead" }) - tokenCounter.add(assistant.tokens.cache.write, { ...ctx.commonAttrs, "session.id": sessionID, model: modelID, agent, type: "cacheCreation" }) + tokenCounter.add(assistant.tokens.input, { ...ctx.commonAttrs,model: modelID, agent, type: "input" }) + tokenCounter.add(assistant.tokens.output, { ...ctx.commonAttrs,model: modelID, agent, type: "output" }) + tokenCounter.add(assistant.tokens.reasoning, { ...ctx.commonAttrs,model: modelID, agent, type: "reasoning" }) + tokenCounter.add(assistant.tokens.cache.read, { ...ctx.commonAttrs,model: modelID, agent, type: "cacheRead" }) + tokenCounter.add(assistant.tokens.cache.write, { ...ctx.commonAttrs,model: modelID, agent, type: "cacheCreation" }) } if (isMetricEnabled("cost.usage", ctx)) { - ctx.instruments.costCounter.add(assistant.cost, { ...ctx.commonAttrs, "session.id": sessionID, model: modelID, agent }) + ctx.instruments.costCounter.add(assistant.cost, { ...ctx.commonAttrs,model: modelID, agent }) } if (isMetricEnabled("cache.count", ctx)) { if (assistant.tokens.cache.read > 0) { - ctx.instruments.cacheCounter.add(1, { ...ctx.commonAttrs, "session.id": sessionID, model: modelID, agent, type: "cacheRead" }) + ctx.instruments.cacheCounter.add(1, { ...ctx.commonAttrs,model: modelID, agent, type: "cacheRead" }) } if (assistant.tokens.cache.write > 0) { - ctx.instruments.cacheCounter.add(1, { ...ctx.commonAttrs, "session.id": sessionID, model: modelID, agent, type: "cacheCreation" }) + ctx.instruments.cacheCounter.add(1, { ...ctx.commonAttrs,model: modelID, agent, type: "cacheCreation" }) } } if (isMetricEnabled("message.count", ctx)) { - ctx.instruments.messageCounter.add(1, { ...ctx.commonAttrs, "session.id": sessionID, model: modelID, agent }) + ctx.instruments.messageCounter.add(1, { ...ctx.commonAttrs,model: modelID, agent }) } if (isMetricEnabled("model.usage", ctx)) { - ctx.instruments.modelUsageCounter.add(1, { ...ctx.commonAttrs, "session.id": sessionID, model: modelID, provider: providerID, agent }) + ctx.instruments.modelUsageCounter.add(1, { ...ctx.commonAttrs,model: modelID, provider: providerID, agent }) } accumulateSessionTotals(sessionID, totalTokens, assistant.cost, ctx) @@ -245,7 +245,6 @@ export function handleMessagePartUpdated(e: EventMessagePartUpdated, ctx: Handle if (isMetricEnabled("subtask.count", ctx)) { ctx.instruments.subtaskCounter.add(1, { ...ctx.commonAttrs, - "session.id": subtask.sessionID, agent: subtask.agent, "agent.type": "subagent", }) @@ -328,7 +327,6 @@ export function handleMessagePartUpdated(e: EventMessagePartUpdated, ctx: Handle if (isMetricEnabled("tool.duration", ctx)) { ctx.instruments.toolDurationHistogram.record(duration_ms, { ...ctx.commonAttrs, - "session.id": toolPart.sessionID, tool_name: toolPart.tool, success, }) diff --git a/src/handlers/session.ts b/src/handlers/session.ts index 9a952dc..6463f4c 100644 --- a/src/handlers/session.ts +++ b/src/handlers/session.ts @@ -1,6 +1,6 @@ import { SeverityNumber } from "@opentelemetry/api-logs" import { SpanStatusCode } from "@opentelemetry/api" -import type { EventSessionCreated, EventSessionIdle, EventSessionError, EventSessionStatus } from "@opencode-ai/sdk" +import type { EventSessionCreated, EventSessionIdle, EventSessionError, EventSessionStatus, EventSessionDeleted } from "@opencode-ai/sdk" import { AGENT_NAME, INPUT_MIME_TYPE, @@ -88,7 +88,7 @@ export function handleSessionCreated(e: EventSessionCreated, ctx: HandlerContext const isSubagent = !!parentID const agentType: SessionAgentType = isSubagent ? "subagent" : "primary" if (isMetricEnabled("session.count", ctx)) { - ctx.instruments.sessionCounter.add(1, { ...ctx.commonAttrs, "session.id": sessionID, is_subagent: isSubagent }) + ctx.instruments.sessionCounter.add(1, { ...ctx.commonAttrs, is_subagent: isSubagent }) } setBoundedMap(ctx.sessionTotals, sessionID, { startMs: createdAt, tokens: 0, cost: 0, messages: 0, agent: "unknown", agentType }) @@ -129,6 +129,18 @@ export function handleSessionCreated(e: EventSessionCreated, ctx: HandlerContext return ctx.log("info", "otel: session.created", { sessionID, createdAt, isSubagent }) } +/** + * Records a session's net lines added/removed once, when the session ends, and drops the diff + * baseline so a later end event for the same session cannot record it twice. `session.idle` + * fires once per *turn*, not once per session, and opencode's `session.diff` is cumulative for + * the whole session — so recording there would add the running session total once per turn. + */ +function recordSessionLines(diff: { additions: number; deletions: number } | undefined, ctx: HandlerContext) { + if (!diff || !isMetricEnabled("session.lines_of_code.total", ctx)) return + ctx.instruments.sessionLinesTotal.record(diff.additions, { ...ctx.commonAttrs, type: "added" }) + ctx.instruments.sessionLinesTotal.record(diff.deletions, { ...ctx.commonAttrs, type: "removed" }) +} + function sweepSession(sessionID: string, ctx: HandlerContext) { for (const [id, perm] of ctx.pendingPermissions) { if (perm.sessionID === sessionID) ctx.pendingPermissions.delete(id) @@ -161,24 +173,23 @@ function sweepSession(sessionID: string, ctx: HandlerContext) { export function handleSessionIdle(e: EventSessionIdle, ctx: HandlerContext) { const sessionID = e.properties.sessionID const totals = ctx.sessionTotals.get(sessionID) + const diff = ctx.sessionDiffTotals.get(sessionID) const { agentName, agentType } = getSessionAgentMeta(sessionID, ctx) ctx.sessionTotals.delete(sessionID) - ctx.sessionDiffTotals.delete(sessionID) sweepSession(sessionID, ctx) - const attrs = { ...ctx.commonAttrs, "session.id": sessionID } let duration_ms: number | undefined if (totals) { duration_ms = Date.now() - totals.startMs if (isMetricEnabled("session.duration", ctx)) { - ctx.instruments.sessionDurationHistogram.record(duration_ms, attrs) + ctx.instruments.sessionDurationHistogram.record(duration_ms, ctx.commonAttrs) } if (isMetricEnabled("session.token.total", ctx)) { - ctx.instruments.sessionTokenGauge.record(totals.tokens, attrs) + ctx.instruments.sessionTokenGauge.record(totals.tokens, ctx.commonAttrs) } if (isMetricEnabled("session.cost.total", ctx)) { - ctx.instruments.sessionCostGauge.record(totals.cost, attrs) + ctx.instruments.sessionCostGauge.record(totals.cost, ctx.commonAttrs) } } @@ -193,6 +204,12 @@ export function handleSessionIdle(e: EventSessionIdle, ctx: HandlerContext) { "session.total_messages": totals.messages, }) } + if (diff) { + sessionSpan.setAttributes({ + "session.total_lines_added": diff.additions, + "session.total_lines_removed": diff.deletions, + }) + } sessionSpan.setStatus({ code: SpanStatusCode.OK }) sessionSpan.end() ctx.sessionSpans.delete(sessionID) @@ -210,6 +227,12 @@ export function handleSessionIdle(e: EventSessionIdle, ctx: HandlerContext) { "session.total_messages": totals.messages, }) } + if (diff) { + runSpan.setAttributes({ + "session.total_lines_added": diff.additions, + "session.total_lines_removed": diff.deletions, + }) + } runSpan.setStatus({ code: SpanStatusCode.OK }) runSpan.end() ctx.runSpans.delete(runID!) @@ -244,16 +267,24 @@ export function handleSessionError(e: EventSessionError, ctx: HandlerContext) { const error = errorSummary(e.properties.error) const { agentName, agentType } = rawID ? getSessionAgentMeta(rawID, ctx) : { agentName: "unknown", agentType: "unknown" as const } const totals = rawID ? ctx.sessionTotals.get(rawID) : undefined + const diff = rawID ? ctx.sessionDiffTotals.get(rawID) : undefined if (rawID) { ctx.sessionTotals.delete(rawID) ctx.sessionDiffTotals.delete(rawID) } + recordSessionLines(diff, ctx) sweepSession(sessionID, ctx) if (rawID) { const sessionSpan = ctx.sessionSpans.get(rawID) if (sessionSpan) { if (totals) sessionSpan.setAttributes({ [AGENT_NAME]: totals.agent, "agent.type": totals.agentType }) + if (diff) { + sessionSpan.setAttributes({ + "session.total_lines_added": diff.additions, + "session.total_lines_removed": diff.deletions, + }) + } sessionSpan.setStatus({ code: SpanStatusCode.ERROR, message: error }) sessionSpan.setAttribute("error", error) sessionSpan.end() @@ -264,6 +295,12 @@ export function handleSessionError(e: EventSessionError, ctx: HandlerContext) { const runSpan = runID ? ctx.runSpans.get(runID) : undefined if (runSpan) { if (totals) runSpan.setAttributes({ [AGENT_NAME]: totals.agent, "agent.type": totals.agentType }) + if (diff) { + runSpan.setAttributes({ + "session.total_lines_added": diff.additions, + "session.total_lines_removed": diff.deletions, + }) + } runSpan.setStatus({ code: SpanStatusCode.ERROR, message: error }) runSpan.setAttribute("error", error) runSpan.end() @@ -288,13 +325,40 @@ export function handleSessionError(e: EventSessionError, ctx: HandlerContext) { ctx.log("error", "otel: session.error", { sessionID, error }) } +/** Records the session's net lines once the session ends, ends any lingering spans, and clears all per-session state. */ +export function handleSessionDeleted(e: EventSessionDeleted, ctx: HandlerContext) { + const sessionID = e.properties.info.id + recordSessionLines(ctx.sessionDiffTotals.get(sessionID), ctx) + ctx.sessionDiffTotals.delete(sessionID) + ctx.sessionTotals.delete(sessionID) + + const sessionSpan = ctx.sessionSpans.get(sessionID) + if (sessionSpan) { + sessionSpan.setStatus({ code: SpanStatusCode.OK }) + sessionSpan.end() + ctx.sessionSpans.delete(sessionID) + } + const runID = ctx.activeRuns.get(sessionID) + if (runID) { + const runSpan = ctx.runSpans.get(runID) + if (runSpan) { + runSpan.setStatus({ code: SpanStatusCode.OK }) + runSpan.end() + } + ctx.runSpans.delete(runID) + ctx.activeRuns.delete(sessionID) + } + sweepSession(sessionID, ctx) + ctx.log("debug", "otel: session.deleted", { sessionID }) +} + /** Increments the retry counter when the session enters a retry state. */ export function handleSessionStatus(e: EventSessionStatus, ctx: HandlerContext) { if (e.properties.status.type !== "retry") return const { sessionID, status } = e.properties const { attempt, message: retryMessage } = status if (isMetricEnabled("retry.count", ctx)) { - ctx.instruments.retryCounter.add(1, { ...ctx.commonAttrs, "session.id": sessionID }) + ctx.instruments.retryCounter.add(1, ctx.commonAttrs) ctx.log("debug", "otel: retry counter incremented", { sessionID, attempt, retryMessage }) } } diff --git a/src/index.ts b/src/index.ts index 194270d..7354a3a 100644 --- a/src/index.ts +++ b/src/index.ts @@ -8,6 +8,7 @@ import type { EventSessionCreated, EventSessionIdle, EventSessionError, + EventSessionDeleted, EventSessionStatus, EventMessageUpdated, EventMessagePartUpdated, @@ -21,7 +22,7 @@ import { loadConfig, parseAttributePairs, resolveHelperPath, resolveLogLevel, ty import { probeEndpoint } from "./probe.ts" import { setupOtel, createInstruments, forceFlushOtel } from "./otel.ts" import { remoteParentContext } from "./trace-context.ts" -import { handleSessionCreated, handleSessionIdle, handleSessionError, handleSessionStatus, handleRunStarted } from "./handlers/session.ts" +import { handleSessionCreated, handleSessionIdle, handleSessionError, handleSessionDeleted, handleSessionStatus, handleRunStarted } from "./handlers/session.ts" import { handleMessageUpdated, handleMessagePartUpdated, startMessageSpan } from "./handlers/message.ts" import { handlePermissionUpdated, handlePermissionReplied } from "./handlers/permission.ts" import { handleSessionDiff, handleCommandExecuted } from "./handlers/activity.ts" @@ -306,6 +307,10 @@ export const OtelPlugin: Plugin = async ({ project, client, directory, worktree handleSessionError(event as EventSessionError, ctx) await flushTelemetry("session.error") break + case "session.deleted": + handleSessionDeleted(event as EventSessionDeleted, ctx) + await flushTelemetry("session.deleted") + break case "session.status": handleSessionStatus(event as EventSessionStatus, ctx) break diff --git a/src/otel.ts b/src/otel.ts index 27a2bcf..9809ff6 100644 --- a/src/otel.ts +++ b/src/otel.ts @@ -1,5 +1,5 @@ import { logs } from "@opentelemetry/api-logs" -import { metrics, trace } from "@opentelemetry/api" +import { metrics, trace, type Meter } from "@opentelemetry/api" import { LoggerProvider, BatchLogRecordProcessor } from "@opentelemetry/sdk-logs" import { MeterProvider, PeriodicExportingMetricReader } from "@opentelemetry/sdk-metrics" import { BasicTracerProvider, BatchSpanProcessor } from "@opentelemetry/sdk-trace-base" @@ -144,9 +144,11 @@ export async function setupOtel( return { meterProvider, loggerProvider, tracerProvider } } -/** Creates all metric instruments using the global `MeterProvider`. Metric names are prefixed with `prefix`. */ -export function createInstruments(prefix: string): Instruments { - const meter = metrics.getMeter("com.opencode") +/** + * Creates all metric instruments using the global `MeterProvider`, or `meter` when one is supplied. + * Metric names are prefixed with `prefix`. + */ +export function createInstruments(prefix: string, meter: Meter = metrics.getMeter("com.opencode")): Instruments { return { sessionCounter: meter.createCounter(`${prefix}session.count`, { unit: "{session}", @@ -162,11 +164,11 @@ export function createInstruments(prefix: string): Instruments { }), linesCounter: meter.createCounter(`${prefix}lines_of_code.count`, { unit: "{line}", - description: "Gross positive churn of lines added/removed across a session. Emits the positive delta vs. the previous session.diff; negative deltas (cumulative shrinkage) are dropped, so sums do not reconcile to net after any revert. Use lines_of_code.total for the authoritative live cumulative.", + description: "Gross positive churn of lines added/removed across a session. Emits the positive delta vs. the previous session.diff; negative deltas (cumulative shrinkage) are dropped, so sums do not reconcile to net after any revert. Use session.lines_of_code.total for the reverting net per-session total.", }), - linesTotalGauge: meter.createGauge(`${prefix}lines_of_code.total`, { + sessionLinesTotal: meter.createHistogram(`${prefix}session.lines_of_code.total`, { unit: "{line}", - description: "Authoritative live cumulative lines added/removed for the current session. Mirrors opencode's session.diff cumulative value on every event; tracks partial and full reverts faithfully.", + description: "Net lines added/removed from opencode's cumulative session.diff, recorded once when the session ends (session.deleted, or session.error). Two observations per session, split by type=added|removed. Unlike lines_of_code.count, this reflects partial and full reverts.", }), commitCounter: meter.createCounter(`${prefix}commit.count`, { unit: "{commit}", diff --git a/src/types.ts b/src/types.ts index da0e816..1386333 100644 --- a/src/types.ts +++ b/src/types.ts @@ -1,4 +1,4 @@ -import type { Context, Counter, Gauge, Histogram, Span, SpanContext, Tracer } from "@opentelemetry/api" +import type { Context, Counter, Histogram, Span, SpanContext, Tracer } from "@opentelemetry/api" import type { LogRecord } from "@opentelemetry/api-logs" /** Numeric priority map for log levels; higher value = higher severity. */ @@ -41,7 +41,7 @@ export type Instruments = { tokenCounter: Counter costCounter: Counter linesCounter: Counter - linesTotalGauge: Gauge + sessionLinesTotal: Histogram commitCounter: Counter toolDurationHistogram: Histogram cacheCounter: Counter @@ -57,7 +57,7 @@ export type Instruments = { /** Session role emitted by opencode: either the primary/root agent or a spawned subagent. */ export type SessionAgentType = "primary" | "subagent" -/** Accumulated per-session totals used for gauge snapshots on session.idle. */ +/** Accumulated per-session totals used for histogram snapshots on session.idle. */ export type SessionTotals = { startMs: number tokens: number diff --git a/tests/handlers/activity.test.ts b/tests/handlers/activity.test.ts index 077fce3..0045a5b 100644 --- a/tests/handlers/activity.test.ts +++ b/tests/handlers/activity.test.ts @@ -95,9 +95,9 @@ describe("handleSessionDiff", () => { // Cumulative goes {additions:10, deletions:0} -> {additions:5, deletions:5}. // Delta is {added:-5, removed:+5}. Negative added is skipped; positive removed // is emitted. Counter ends at added=10, removed=5 while the authoritative live - // cumulative is added=5, removed=5 — the counter is GROSS, not net. Live - // cumulative state is surfaced via linesTotalGauge (see next test). - const { ctx, counters, gauges } = makeCtx() + // cumulative is added=5, removed=5 — the counter is GROSS, not net. The net + // per-session values are surfaced by session.lines_of_code.total on session.idle. + const { ctx, counters } = makeCtx() handleSessionDiff(makeSessionDiff("ses_1", [{ file: "a.ts", additions: 10, deletions: 0 }]), ctx) handleSessionDiff(makeSessionDiff("ses_1", [{ file: "a.ts", additions: 5, deletions: 5 }]), ctx) @@ -105,21 +105,7 @@ describe("handleSessionDiff", () => { const removed = counters.lines.calls.filter((c) => c.attrs["type"] === "removed").map((c) => c.value) expect(added).toEqual([10]) expect(removed).toEqual([5]) - - const gaugeAdded = gauges.linesTotal.calls.filter((c) => c.attrs["type"] === "added").map((c) => c.value) - const gaugeRemoved = gauges.linesTotal.calls.filter((c) => c.attrs["type"] === "removed").map((c) => c.value) - expect(gaugeAdded).toEqual([10, 5]) - expect(gaugeRemoved).toEqual([0, 5]) - }) - - test("linesTotalGauge records cumulative totals, including zero after revert", () => { - const { ctx, gauges } = makeCtx() - handleSessionDiff(makeSessionDiff("ses_1", [{ file: "a.ts", additions: 5, deletions: 2 }]), ctx) - handleSessionDiff(makeSessionDiff("ses_1", [{ file: "a.ts", additions: 0, deletions: 0 }]), ctx) - const added = gauges.linesTotal.calls.filter((c) => c.attrs["type"] === "added").map((c) => c.value) - const removed = gauges.linesTotal.calls.filter((c) => c.attrs["type"] === "removed").map((c) => c.value) - expect(added).toEqual([5, 0]) - expect(removed).toEqual([2, 0]) + expect(ctx.sessionDiffTotals.get("ses_1")).toEqual({ additions: 5, deletions: 5 }) }) test("tracks deltas independently per session", () => { @@ -127,10 +113,10 @@ describe("handleSessionDiff", () => { handleSessionDiff(makeSessionDiff("ses_1", [{ file: "a.ts", additions: 3, deletions: 0 }]), ctx) handleSessionDiff(makeSessionDiff("ses_2", [{ file: "b.ts", additions: 7, deletions: 0 }]), ctx) handleSessionDiff(makeSessionDiff("ses_1", [{ file: "a.ts", additions: 5, deletions: 0 }]), ctx) - const ses1 = counters.lines.calls.filter((c) => c.attrs["session.id"] === "ses_1").map((c) => c.value) - const ses2 = counters.lines.calls.filter((c) => c.attrs["session.id"] === "ses_2").map((c) => c.value) - expect(ses1).toEqual([3, 2]) - expect(ses2).toEqual([7]) + const added = counters.lines.calls.filter((c) => c.attrs["type"] === "added").map((c) => c.value) + expect(added).toEqual([3, 7, 2]) + expect(ctx.sessionDiffTotals.get("ses_1")).toEqual({ additions: 5, deletions: 0 }) + expect(ctx.sessionDiffTotals.get("ses_2")).toEqual({ additions: 7, deletions: 0 }) }) }) diff --git a/tests/handlers/disabled-metrics.test.ts b/tests/handlers/disabled-metrics.test.ts index cece7d8..19d8e84 100644 --- a/tests/handlers/disabled-metrics.test.ts +++ b/tests/handlers/disabled-metrics.test.ts @@ -232,7 +232,7 @@ describe("OPENCODE_DISABLE_METRICS", () => { "session.count", "token.usage", "cost.usage", "lines_of_code.count", "commit.count", "tool.duration", "cache.count", "session.duration", "message.count", "session.token.total", "session.cost.total", - "model.usage", "retry.count", "subtask.count", + "model.usage", "retry.count", "subtask.count", "session.lines_of_code.total", ] const { ctx, counters, histograms, gauges } = makeCtx("proj_test", all) const subtaskEvent = { @@ -244,9 +244,9 @@ describe("OPENCODE_DISABLE_METRICS", () => { await handleSessionCreated(makeSessionCreated("ses_1"), ctx) await handleMessageUpdated(makeAssistantMessage(), ctx) + handleSessionDiff(makeSessionDiff(), ctx) handleSessionIdle(makeSessionIdle("ses_1"), ctx) handleSessionStatus(makeSessionStatus("ses_1"), ctx) - handleSessionDiff(makeSessionDiff(), ctx) handleCommandExecuted(makeCommandExecuted("git commit -m 'test'"), ctx) await handleMessagePartUpdated(makeToolPart("running"), ctx) await handleMessagePartUpdated(makeToolPart("completed"), ctx) @@ -264,6 +264,7 @@ describe("OPENCODE_DISABLE_METRICS", () => { expect(counters.subtask.calls).toHaveLength(0) expect(histograms.tool.calls).toHaveLength(0) expect(histograms.sessionDuration.calls).toHaveLength(0) + expect(histograms.sessionLinesTotal.calls).toHaveLength(0) expect(gauges.sessionToken.calls).toHaveLength(0) expect(gauges.sessionCost.calls).toHaveLength(0) }) diff --git a/tests/handlers/message.test.ts b/tests/handlers/message.test.ts index 0fed30a..19d9951 100644 --- a/tests/handlers/message.test.ts +++ b/tests/handlers/message.test.ts @@ -177,10 +177,11 @@ describe("handleMessageUpdated", () => { await handleMessageUpdated(makeAssistantMessageUpdated({ sessionID: "ses_1", modelID: "claude-3-5-sonnet" }), ctx) expect(counters.message.calls).toHaveLength(1) expect(counters.message.calls.at(0)!.value).toBe(1) - expect(counters.message.calls.at(0)!.attrs["session.id"]).toBe("ses_1") + expect(counters.message.calls.at(0)!.attrs["session.id"]).toBeUndefined() + expect(counters.message.calls.at(0)!.attrs["model"]).toBe("claude-3-5-sonnet") }) - test("increments model usage counter with session.id, model and provider", async () => { + test("increments model usage counter with model and provider", async () => { const { ctx, counters } = makeCtx() await handleMessageUpdated( makeAssistantMessageUpdated({ sessionID: "ses_1", modelID: "claude-3-5-sonnet", providerID: "anthropic" }), @@ -188,7 +189,7 @@ describe("handleMessageUpdated", () => { ) expect(counters.modelUsage.calls).toHaveLength(1) const call = counters.modelUsage.calls.at(0)! - expect(call.attrs["session.id"]).toBe("ses_1") + expect(call.attrs["session.id"]).toBeUndefined() expect(call.attrs["model"]).toBe("claude-3-5-sonnet") expect(call.attrs["provider"]).toBe("anthropic") }) @@ -398,14 +399,15 @@ describe("handleMessageUpdated — agent attribute", () => { }) describe("handleMessagePartUpdated — subtask parts", () => { - test("increments subtask counter with agent and session.id attrs", async () => { + test("increments subtask counter with agent attrs", async () => { const { ctx, counters } = makeCtx() await handleMessagePartUpdated(makeSubtaskPartUpdated({ sessionID: "ses_1", agent: "build" }), ctx) expect(counters.subtask.calls).toHaveLength(1) const call = counters.subtask.calls.at(0)! expect(call.value).toBe(1) expect(call.attrs["agent"]).toBe("build") - expect(call.attrs["session.id"]).toBe("ses_1") + expect(call.attrs["agent.type"]).toBe("subagent") + expect(call.attrs["session.id"]).toBeUndefined() }) test("emits subtask_invoked log record", async () => { diff --git a/tests/handlers/metric-cardinality.test.ts b/tests/handlers/metric-cardinality.test.ts new file mode 100644 index 0000000..c64bc50 --- /dev/null +++ b/tests/handlers/metric-cardinality.test.ts @@ -0,0 +1,200 @@ +import { describe, test, expect } from "bun:test" +import { handleSessionCreated, handleSessionIdle, handleSessionDeleted, handleSessionStatus } from "../../src/handlers/session.ts" +import { handleMessageUpdated, handleMessagePartUpdated } from "../../src/handlers/message.ts" +import { handleSessionDiff, handleCommandExecuted } from "../../src/handlers/activity.ts" +import { handlePermissionUpdated, handlePermissionReplied } from "../../src/handlers/permission.ts" +import { makeCtx } from "../helpers.ts" +import type { + EventSessionCreated, + EventSessionIdle, + EventSessionDeleted, + EventSessionStatus, + EventMessageUpdated, + EventMessagePartUpdated, + EventSessionDiff, + EventCommandExecuted, + EventPermissionUpdated, + EventPermissionReplied, +} from "@opencode-ai/sdk" + +function makeSessionCreated(sessionID: string, parentID?: string): EventSessionCreated { + return { + type: "session.created", + properties: { info: { id: sessionID, projectID: "proj_test", directory: "/tmp", parentID, time: { created: 1000 } } }, + } as unknown as EventSessionCreated +} + +function makeSessionIdle(sessionID: string): EventSessionIdle { + return { type: "session.idle", properties: { sessionID } } as EventSessionIdle +} + +function makeSessionDeleted(sessionID: string): EventSessionDeleted { + return { type: "session.deleted", properties: { info: { id: sessionID } } } as unknown as EventSessionDeleted +} + +function makeSessionStatus(sessionID: string): EventSessionStatus { + return { + type: "session.status", + properties: { sessionID, status: { type: "retry", attempt: 1, message: "rate limited", next: 5000 } }, + } as unknown as EventSessionStatus +} + +function makeAssistantMessage(opts: { sessionID?: string; error?: { name: string } } = {}): EventMessageUpdated { + const sessionID = opts.sessionID ?? "ses_1" + return { + type: "message.updated", + properties: { + info: { + id: "msg_1", role: "assistant", sessionID, + modelID: "claude-3-5-sonnet", providerID: "anthropic", + cost: 0.01, + tokens: { input: 100, output: 50, reasoning: 0, cache: { read: 20, write: 5 } }, + time: { created: 1000, completed: 2000 }, + ...(opts.error ? { error: opts.error } : {}), + }, + }, + } as unknown as EventMessageUpdated +} + +function makeToolPart(status: "running" | "completed", sessionID = "ses_1"): EventMessagePartUpdated { + return { + type: "message.part.updated", + properties: { + part: { + type: "tool", sessionID, callID: "call_1", messageID: "msg_1", tool: "bash", + state: status === "running" + ? { status: "running", time: { start: 1000 } } + : { status: "completed", time: { start: 1000, end: 1500 }, output: "ok" }, + }, + }, + } as unknown as EventMessagePartUpdated +} + +function makeSubtaskPart(sessionID = "ses_1"): EventMessagePartUpdated { + return { + type: "message.part.updated", + properties: { + part: { type: "subtask", sessionID, messageID: "msg_1", agent: "build", description: "desc", prompt: "prompt" }, + }, + } as unknown as EventMessagePartUpdated +} + +function makeSessionDiff(sessionID = "ses_1"): EventSessionDiff { + return { + type: "session.diff", + properties: { sessionID, diff: [{ file: "a.ts", additions: 10, deletions: 3 }] }, + } as unknown as EventSessionDiff +} + +function makeCommandExecuted(cmd: string, sessionID = "ses_1"): EventCommandExecuted { + return { + type: "command.executed", + properties: { sessionID, name: "bash", arguments: cmd }, + } as unknown as EventCommandExecuted +} + +function makePermissionUpdated(id: string, sessionID = "ses_1"): EventPermissionUpdated { + return { + type: "permission.updated", + properties: { id, sessionID, type: "bash", title: "Run bash", metadata: {}, time: { created: 1000 } }, + } as unknown as EventPermissionUpdated +} + +function makePermissionReplied(id: string, sessionID = "ses_1"): EventPermissionReplied { + return { + type: "permission.replied", + properties: { permissionID: id, sessionID, response: "allow" }, + } as unknown as EventPermissionReplied +} + +/** + * Every emitLog site reachable from a handler. `user_prompt` is excluded: it is emitted from the + * plugin's `chat.message` hook in src/index.ts and needs a full plugin harness to reach. If a body + * here stops appearing, the loop below fails rather than silently covering fewer sites. + */ +const EXPECTED_LOG_BODIES = [ + "api_error", + "api_request", + "commit", + "session.created", + "session.idle", + "subtask_invoked", + "tool_decision", + "tool_result", +] + +describe("metric cardinality", () => { + test("no metric data point carries session.id (covers instruments registered in MockContext)", async () => { + const mocks = makeCtx("proj_test", [], [], true, { team: "platform" }) + const { ctx } = mocks + + await handleSessionCreated(makeSessionCreated("ses_1"), ctx) + await handleMessageUpdated(makeAssistantMessage(), ctx) + await handleMessageUpdated(makeAssistantMessage({ error: { name: "APIError" } }), ctx) + await handleMessagePartUpdated(makeToolPart("running"), ctx) + await handleMessagePartUpdated(makeToolPart("completed"), ctx) + await handleMessagePartUpdated(makeSubtaskPart(), ctx) + await handlePermissionUpdated(makePermissionUpdated("perm_1"), ctx) + await handlePermissionReplied(makePermissionReplied("perm_1"), ctx) + handleSessionStatus(makeSessionStatus("ses_1"), ctx) + handleSessionDiff(makeSessionDiff(), ctx) + handleCommandExecuted(makeCommandExecuted("git commit -m 'test'"), ctx) + handleSessionIdle(makeSessionIdle("ses_1"), ctx) + handleSessionDeleted(makeSessionDeleted("ses_1"), ctx) + + const instruments = [ + ...Object.entries(mocks.counters), + ...Object.entries(mocks.histograms), + ...Object.entries(mocks.gauges), + ] + + expect( + instruments.length, + "HandlerContext.instruments has a member that MockContext does not register as a spy, so the loop below cannot see it", + ).toBe(Object.keys(ctx.instruments).length) + + for (const [name, spy] of instruments) { + expect(spy.calls.length, `instrument "${name}" recorded nothing, so this guard would pass vacuously`).toBeGreaterThan(0) + } + + for (const [name, spy] of instruments) { + for (const call of spy.calls) { + expect(call.attrs["session.id"], `instrument "${name}" leaked session.id`).toBeUndefined() + expect(call.attrs["project.id"]).toBe("proj_test") + expect(call.attrs["team"]).toBe("platform") + } + } + }) + + test("every handler-reachable log event still carries session.id", async () => { + const { ctx, logger } = makeCtx() + await handleSessionCreated(makeSessionCreated("ses_1"), ctx) + await handleMessageUpdated(makeAssistantMessage(), ctx) + await handleMessageUpdated(makeAssistantMessage({ error: { name: "APIError" } }), ctx) + await handleMessagePartUpdated(makeToolPart("running"), ctx) + await handleMessagePartUpdated(makeToolPart("completed"), ctx) + await handleMessagePartUpdated(makeSubtaskPart(), ctx) + await handlePermissionUpdated(makePermissionUpdated("perm_1"), ctx) + await handlePermissionReplied(makePermissionReplied("perm_1"), ctx) + handleSessionDiff(makeSessionDiff(), ctx) + handleCommandExecuted(makeCommandExecuted("git commit -m 'test'"), ctx) + handleSessionIdle(makeSessionIdle("ses_1"), ctx) + handleSessionDeleted(makeSessionDeleted("ses_1"), ctx) + + const bodies = [...new Set(logger.records.map((r) => r.body))].sort() + for (const body of EXPECTED_LOG_BODIES) { + expect(bodies, `log event "${body}" was never emitted, so it is not actually covered here`).toContain(body) + } + + for (const record of logger.records) { + expect(record.attributes?.["session.id"], `log event "${record.body}" lost session.id`).toBe("ses_1") + } + }) + + test("subagent session span still carries session.id", () => { + const { ctx, tracer } = makeCtx() + handleSessionCreated(makeSessionCreated("ses_child", "ses_parent"), ctx) + expect(tracer.spans).toHaveLength(1) + expect(tracer.spans[0]!.attributes["session.id"]).toBe("ses_child") + }) +}) diff --git a/tests/handlers/session.test.ts b/tests/handlers/session.test.ts index bbada8a..fef1870 100644 --- a/tests/handlers/session.test.ts +++ b/tests/handlers/session.test.ts @@ -1,7 +1,8 @@ import { describe, test, expect } from "bun:test" -import { handleSessionCreated, handleSessionIdle, handleSessionError, handleSessionStatus } from "../../src/handlers/session.ts" +import { handleSessionCreated, handleSessionIdle, handleSessionError, handleSessionDeleted, handleSessionStatus, handleRunStarted } from "../../src/handlers/session.ts" +import { handleSessionDiff } from "../../src/handlers/activity.ts" import { makeCtx, makeTracer } from "../helpers.ts" -import type { EventSessionCreated, EventSessionIdle, EventSessionError, EventSessionStatus } from "@opencode-ai/sdk" +import type { EventSessionCreated, EventSessionIdle, EventSessionError, EventSessionDeleted, EventSessionStatus, EventSessionDiff } from "@opencode-ai/sdk" import type { Span } from "@opentelemetry/api" function makeSessionCreated(sessionID: string, createdAt = 1000, parentID?: string): EventSessionCreated { @@ -30,6 +31,14 @@ function makeSessionError(sessionID: string, error?: { name: string }): EventSes } as unknown as EventSessionError } +function makeSessionDiff(sessionID: string, diff: Array<{ file: string; additions: number; deletions: number }>): EventSessionDiff { + return { type: "session.diff", properties: { sessionID, diff } } as unknown as EventSessionDiff +} + +function makeSessionDeleted(sessionID: string): EventSessionDeleted { + return { type: "session.deleted", properties: { info: { id: sessionID } } } as unknown as EventSessionDeleted +} + function makeSessionStatus(sessionID: string, status: { type: "retry"; attempt: number; message: string; next: number } | { type: "busy" } | { type: "idle" }): EventSessionStatus { return { type: "session.status", properties: { sessionID, status } } as unknown as EventSessionStatus } @@ -41,7 +50,8 @@ describe("handleSessionCreated", () => { expect(counters.session.calls).toHaveLength(1) const call = counters.session.calls.at(0)! expect(call.value).toBe(1) - expect(call.attrs["session.id"]).toBe("ses_1") + expect(call.attrs["session.id"]).toBeUndefined() + expect(call.attrs["is_subagent"]).toBe(false) }) test("emits session.created log record with correct timestamp", async () => { @@ -118,7 +128,7 @@ describe("handleSessionIdle", () => { handleSessionIdle(makeSessionIdle("ses_1"), ctx) expect(histograms.sessionDuration.calls).toHaveLength(1) expect(histograms.sessionDuration.calls.at(0)!.value).toBeGreaterThan(0) - expect(histograms.sessionDuration.calls.at(0)!.attrs["session.id"]).toBe("ses_1") + expect(histograms.sessionDuration.calls.at(0)!.attrs["session.id"]).toBeUndefined() }) test("records session token and cost histograms when totals exist", async () => { @@ -132,6 +142,25 @@ describe("handleSessionIdle", () => { expect(gauges.sessionCost.calls.at(0)!.value).toBe(0.03) }) + test("does not record the LOC histogram on idle", async () => { + const { ctx, histograms } = makeCtx() + await handleSessionCreated(makeSessionCreated("ses_1"), ctx) + handleSessionDiff(makeSessionDiff("ses_1", [{ file: "a.ts", additions: 10, deletions: 0 }]), ctx) + handleSessionIdle(makeSessionIdle("ses_1"), ctx) + expect(histograms.sessionLinesTotal.calls).toHaveLength(0) + }) + + test("keeps the session diff baseline across idle so later turns emit true deltas", async () => { + const { ctx, counters } = makeCtx() + await handleSessionCreated(makeSessionCreated("ses_1"), ctx) + handleSessionDiff(makeSessionDiff("ses_1", [{ file: "a.ts", additions: 10, deletions: 0 }]), ctx) + handleSessionIdle(makeSessionIdle("ses_1"), ctx) + handleSessionDiff(makeSessionDiff("ses_1", [{ file: "a.ts", additions: 25, deletions: 0 }]), ctx) + const added = counters.lines.calls.filter((c) => c.attrs["type"] === "added").map((c) => c.value) + expect(added).toEqual([10, 15]) + expect(ctx.sessionDiffTotals.get("ses_1")).toEqual({ additions: 25, deletions: 0 }) + }) + test("emits total_tokens and total_messages in log record attributes", async () => { const { ctx, logger } = makeCtx() await handleSessionCreated(makeSessionCreated("ses_1"), ctx) @@ -151,6 +180,7 @@ describe("handleSessionIdle", () => { expect(histograms.sessionDuration.calls).toHaveLength(0) expect(gauges.sessionToken.calls).toHaveLength(0) expect(gauges.sessionCost.calls).toHaveLength(0) + expect(histograms.sessionLinesTotal.calls).toHaveLength(0) }) test("removes sessionTotals entry on idle", async () => { @@ -162,6 +192,103 @@ describe("handleSessionIdle", () => { }) }) +describe("handleSessionDeleted", () => { + test("records the session's net LOC once, diverging from the gross counter", async () => { + const { ctx, counters, histograms } = makeCtx() + await handleSessionCreated(makeSessionCreated("ses_1"), ctx) + handleSessionDiff(makeSessionDiff("ses_1", [{ file: "a.ts", additions: 10, deletions: 0 }]), ctx) + handleSessionDiff(makeSessionDiff("ses_1", [{ file: "a.ts", additions: 5, deletions: 5 }]), ctx) + handleSessionDeleted(makeSessionDeleted("ses_1"), ctx) + + const added = histograms.sessionLinesTotal.calls.filter((c) => c.attrs["type"] === "added").map((c) => c.value) + const removed = histograms.sessionLinesTotal.calls.filter((c) => c.attrs["type"] === "removed").map((c) => c.value) + expect(added).toEqual([5]) + expect(removed).toEqual([5]) + + const counterAdded = counters.lines.calls.filter((c) => c.attrs["type"] === "added").map((c) => c.value) + expect(counterAdded).toEqual([10]) + }) + + test("records exactly one observation pair for a multi-turn session", async () => { + const { ctx, histograms } = makeCtx() + await handleSessionCreated(makeSessionCreated("ses_1"), ctx) + handleSessionDiff(makeSessionDiff("ses_1", [{ file: "a.ts", additions: 10, deletions: 0 }]), ctx) + handleSessionIdle(makeSessionIdle("ses_1"), ctx) + handleSessionDiff(makeSessionDiff("ses_1", [{ file: "a.ts", additions: 25, deletions: 0 }]), ctx) + handleSessionIdle(makeSessionIdle("ses_1"), ctx) + handleSessionDeleted(makeSessionDeleted("ses_1"), ctx) + + const added = histograms.sessionLinesTotal.calls.filter((c) => c.attrs["type"] === "added").map((c) => c.value) + expect(added).toEqual([25]) + expect(added.reduce((a, b) => a + b, 0)).toBe(25) + }) + + test("carries common attributes and no session.id on the LOC histogram", async () => { + const { ctx, histograms } = makeCtx("proj_test", [], [], true, { team: "platform" }) + await handleSessionCreated(makeSessionCreated("ses_1"), ctx) + handleSessionDiff(makeSessionDiff("ses_1", [{ file: "a.ts", additions: 4, deletions: 1 }]), ctx) + handleSessionDeleted(makeSessionDeleted("ses_1"), ctx) + expect(histograms.sessionLinesTotal.calls).toHaveLength(2) + for (const call of histograms.sessionLinesTotal.calls) { + expect(call.attrs["project.id"]).toBe("proj_test") + expect(call.attrs["team"]).toBe("platform") + expect(call.attrs["session.id"]).toBeUndefined() + } + }) + + test("does not record when the session saw no diff", async () => { + const { ctx, histograms } = makeCtx() + await handleSessionCreated(makeSessionCreated("ses_1"), ctx) + handleSessionDeleted(makeSessionDeleted("ses_1"), ctx) + expect(histograms.sessionLinesTotal.calls).toHaveLength(0) + }) + + test("does not record when session.lines_of_code.total is disabled", async () => { + const { ctx, histograms } = makeCtx("proj_test", ["session.lines_of_code.total"]) + await handleSessionCreated(makeSessionCreated("ses_1"), ctx) + handleSessionDiff(makeSessionDiff("ses_1", [{ file: "a.ts", additions: 4, deletions: 1 }]), ctx) + handleSessionDeleted(makeSessionDeleted("ses_1"), ctx) + expect(histograms.sessionLinesTotal.calls).toHaveLength(0) + }) + + test("does not record twice when error and deleted both fire", async () => { + const { ctx, histograms } = makeCtx() + await handleSessionCreated(makeSessionCreated("ses_1"), ctx) + handleSessionDiff(makeSessionDiff("ses_1", [{ file: "a.ts", additions: 4, deletions: 1 }]), ctx) + handleSessionError(makeSessionError("ses_1", { name: "Boom" }), ctx) + handleSessionDeleted(makeSessionDeleted("ses_1"), ctx) + expect(histograms.sessionLinesTotal.calls).toHaveLength(2) + }) + + test("ends a lingering session span for a deleted subagent session", async () => { + const { ctx, tracer } = makeCtx() + handleRunStarted("user_parent", "ses_parent", "build", "prompt", "anthropic/claude", 900, ctx) + await handleSessionCreated(makeSessionCreated("ses_child", 1000, "ses_parent"), ctx) + const childSpan = tracer.spans.find((s) => s.attributes["session.id"] === "ses_child")! + handleSessionDeleted(makeSessionDeleted("ses_child"), ctx) + expect(ctx.sessionSpans.has("ses_child")).toBe(false) + expect(childSpan.ended).toBe(true) + }) + + test("ends a lingering run span when its session is deleted mid-run", async () => { + const { ctx, tracer } = makeCtx() + handleRunStarted("user_1", "ses_1", "build", "prompt", "anthropic/claude", 900, ctx) + handleSessionDeleted(makeSessionDeleted("ses_1"), ctx) + expect(ctx.runSpans.has("user_1")).toBe(false) + expect(ctx.activeRuns.has("ses_1")).toBe(false) + expect(tracer.spans[0]!.ended).toBe(true) + }) + + test("clears the session diff baseline so state does not leak", async () => { + const { ctx } = makeCtx() + await handleSessionCreated(makeSessionCreated("ses_1"), ctx) + handleSessionDiff(makeSessionDiff("ses_1", [{ file: "a.ts", additions: 4, deletions: 1 }]), ctx) + handleSessionDeleted(makeSessionDeleted("ses_1"), ctx) + expect(ctx.sessionDiffTotals.has("ses_1")).toBe(false) + expect(ctx.sessionTotals.has("ses_1")).toBe(false) + }) +}) + describe("handleSessionError", () => { test("emits session.error log record", () => { const { ctx, logger } = makeCtx() @@ -246,7 +373,7 @@ describe("handleSessionStatus", () => { handleSessionStatus(makeSessionStatus("ses_1", { type: "retry", attempt: 1, message: "rate limited", next: 5000 }), ctx) expect(counters.retry.calls).toHaveLength(1) expect(counters.retry.calls.at(0)!.value).toBe(1) - expect(counters.retry.calls.at(0)!.attrs["session.id"]).toBe("ses_1") + expect(counters.retry.calls.at(0)!.attrs["session.id"]).toBeUndefined() }) test("ignores busy status", () => { diff --git a/tests/handlers/spans.test.ts b/tests/handlers/spans.test.ts index 18851d0..42b3088 100644 --- a/tests/handlers/spans.test.ts +++ b/tests/handlers/spans.test.ts @@ -182,6 +182,57 @@ describe("session spans", () => { expect(span.attributes["agent.type"]).toBe("primary") }) + test("sets net LOC attributes on the run span before ending on idle", () => { + const { ctx, tracer } = makeCtx() + handleRunStarted("user_1", "ses_1", "build", "prompt", "anthropic/claude", 1000, ctx) + ctx.sessionDiffTotals.set("ses_1", { additions: 12, deletions: 4 }) + handleSessionIdle(makeSessionIdle("ses_1"), ctx) + const span = tracer.spans[0]! + expect(span.attributes["session.total_lines_added"]).toBe(12) + expect(span.attributes["session.total_lines_removed"]).toBe(4) + }) + + test("sets net LOC attributes on the subagent session span on idle", () => { + const { ctx, tracer } = makeCtx() + handleRunStarted("user_parent", "ses_parent", "build", "prompt", "anthropic/claude", 900, ctx) + handleSessionCreated(makeSessionCreated("ses_1", 1000, "ses_parent"), ctx) + ctx.sessionDiffTotals.set("ses_1", { additions: 7, deletions: 2 }) + handleSessionIdle(makeSessionIdle("ses_1"), ctx) + const span = tracer.spans[1]! + expect(span.attributes["session.total_lines_added"]).toBe(7) + expect(span.attributes["session.total_lines_removed"]).toBe(2) + }) + + test("omits LOC attributes when the session saw no diff", () => { + const { ctx, tracer } = makeCtx() + handleRunStarted("user_1", "ses_1", "build", "prompt", "anthropic/claude", 1000, ctx) + handleSessionIdle(makeSessionIdle("ses_1"), ctx) + const span = tracer.spans[0]! + expect(span.attributes["session.total_lines_added"]).toBeUndefined() + expect(span.attributes["session.total_lines_removed"]).toBeUndefined() + }) + + test("sets LOC span attributes even when the LOC metric is disabled", () => { + const { ctx, tracer } = makeCtx("proj_test", ["session.lines_of_code.total"]) + handleRunStarted("user_1", "ses_1", "build", "prompt", "anthropic/claude", 1000, ctx) + ctx.sessionDiffTotals.set("ses_1", { additions: 5, deletions: 1 }) + handleSessionIdle(makeSessionIdle("ses_1"), ctx) + const span = tracer.spans[0]! + expect(span.attributes["session.total_lines_added"]).toBe(5) + expect(span.attributes["session.total_lines_removed"]).toBe(1) + }) + + test("sets net LOC attributes on the run span on session.error", () => { + const { ctx, tracer } = makeCtx() + handleRunStarted("user_1", "ses_1", "build", "prompt", "anthropic/claude", 1000, ctx) + ctx.sessionDiffTotals.set("ses_1", { additions: 9, deletions: 3 }) + handleSessionError(makeSessionError("ses_1", { name: "NetworkError" }), ctx) + const span = tracer.spans[0]! + expect(span.attributes["session.total_lines_added"]).toBe(9) + expect(span.attributes["session.total_lines_removed"]).toBe(3) + expect(span.status.code).toBe(SpanStatusCode.ERROR) + }) + test("ends run span with ERROR status on session.error", () => { const { ctx, tracer } = makeCtx() handleRunStarted("user_1", "ses_1", "build", "prompt", "anthropic/claude", 1000, ctx) diff --git a/tests/helpers.ts b/tests/helpers.ts index a1594b9..666d6cd 100644 --- a/tests/helpers.ts +++ b/tests/helpers.ts @@ -1,6 +1,6 @@ import type { HandlerContext, Instruments } from "../src/types.ts" import type { LogRecord } from "@opentelemetry/api-logs" -import type { Counter, Gauge, Histogram, Span, SpanOptions, Tracer, Context, SpanContext, SpanStatus, Attributes } from "@opentelemetry/api" +import type { Counter, Histogram, Span, SpanOptions, Tracer, Context, SpanContext, SpanStatus, Attributes } from "@opentelemetry/api" import { ROOT_CONTEXT, SpanStatusCode, trace } from "@opentelemetry/api" export type SpyCounter = { @@ -13,11 +13,6 @@ export type SpyHistogram = { record(value: number, attrs?: Record): void } -export type SpyGauge = { - calls: Array<{ value: number; attrs: Record }> - record(value: number, attrs?: Record): void -} - export type SpyLogger = { records: LogRecord[] emit(record: LogRecord): void @@ -63,11 +58,6 @@ function makeHistogram(): SpyHistogram { return spy } -function makeGauge(): SpyGauge { - const spy: SpyGauge = { calls: [], record(v, a = {}) { spy.calls.push({ value: v, attrs: a }) } } - return spy -} - function makeLogger(): SpyLogger { const spy: SpyLogger = { records: [], emit(r) { spy.records.push(r) } } return spy @@ -160,11 +150,11 @@ export type MockContext = { histograms: { tool: SpyHistogram sessionDuration: SpyHistogram + sessionLinesTotal: SpyHistogram } gauges: { sessionToken: SpyHistogram sessionCost: SpyHistogram - linesTotal: SpyGauge } logger: SpyLogger pluginLog: SpyPluginLog @@ -192,7 +182,7 @@ export function makeCtx( const sessionDurationHistogram = makeHistogram() const sessionTokenGauge = makeHistogram() const sessionCostGauge = makeHistogram() - const linesTotalGauge = makeGauge() + const sessionLinesTotal = makeHistogram() const logger = makeLogger() const pluginLog = makePluginLog() const tracer = makeTracer() @@ -202,7 +192,7 @@ export function makeCtx( tokenCounter: token as unknown as Counter, costCounter: cost as unknown as Counter, linesCounter: lines as unknown as Counter, - linesTotalGauge: linesTotalGauge as unknown as Gauge, + sessionLinesTotal: sessionLinesTotal as unknown as Histogram, commitCounter: commit as unknown as Counter, toolDurationHistogram: toolHistogram as unknown as Histogram, cacheCounter: cache as unknown as Counter, @@ -249,8 +239,8 @@ export function makeCtx( return { ctx, counters: { session, token, cost, lines, commit, cache, message, modelUsage, retry, subtask }, - histograms: { tool: toolHistogram, sessionDuration: sessionDurationHistogram }, - gauges: { sessionToken: sessionTokenGauge, sessionCost: sessionCostGauge, linesTotal: linesTotalGauge }, + histograms: { tool: toolHistogram, sessionDuration: sessionDurationHistogram, sessionLinesTotal }, + gauges: { sessionToken: sessionTokenGauge, sessionCost: sessionCostGauge }, logger, pluginLog, tracer, diff --git a/tests/otel.test.ts b/tests/otel.test.ts index e49fdd2..2158486 100644 --- a/tests/otel.test.ts +++ b/tests/otel.test.ts @@ -8,7 +8,8 @@ import { OTLPMetricExporter as OTLPProtoMetricExporter } from "@opentelemetry/ex import { OTLPTraceExporter } from "@opentelemetry/exporter-trace-otlp-grpc" import { OTLPTraceExporter as OTLPHttpTraceExporter } from "@opentelemetry/exporter-trace-otlp-http" import { OTLPTraceExporter as OTLPProtoTraceExporter } from "@opentelemetry/exporter-trace-otlp-proto" -import { buildResource, forceFlushOtel, setupOtel, type OtelProviders } from "../src/otel.ts" +import type { Meter } from "@opentelemetry/api" +import { buildResource, createInstruments, forceFlushOtel, setupOtel, type OtelProviders } from "../src/otel.ts" let providers: OtelProviders | undefined @@ -124,6 +125,61 @@ describe("setupOtel", () => { }) }) +describe("createInstruments", () => { + /** + * Records the instrument names and kinds the meter is asked for, without an SDK. The global + * provider cannot be swapped here — the OTel API only accepts one registration per process and + * the `setupOtel` tests above register first — so the meter is injected directly. + */ + function collectInstrumentNames(prefix = "opencode.") { + const seen: Array<{ kind: string; name: string }> = [] + const fakeMeter = { + createCounter: (name: string) => { seen.push({ kind: "counter", name }); return {} }, + createHistogram: (name: string) => { seen.push({ kind: "histogram", name }); return {} }, + createGauge: (name: string) => { seen.push({ kind: "gauge", name }); return {} }, + } as unknown as Meter + createInstruments(prefix, fakeMeter) + return seen.map((s) => `${s.kind}:${s.name}`).sort() + } + + /** + * Metric names and their instrument kinds are the plugin's public contract — dashboards and + * alert rules key off both, and each name's suffix is the OPENCODE_DISABLE_METRICS key. + */ + const EXPECTED = [ + "counter:opencode.cache.count", + "counter:opencode.commit.count", + "counter:opencode.cost.usage", + "counter:opencode.lines_of_code.count", + "counter:opencode.message.count", + "counter:opencode.model.usage", + "counter:opencode.retry.count", + "counter:opencode.session.count", + "counter:opencode.subtask.count", + "counter:opencode.token.usage", + "histogram:opencode.session.cost.total", + "histogram:opencode.session.duration", + "histogram:opencode.session.lines_of_code.total", + "histogram:opencode.session.token.total", + "histogram:opencode.tool.duration", + ].sort() + + test("registers every metric with the expected name and kind", () => { + expect(collectInstrumentNames()).toEqual(EXPECTED) + }) + + test("honours a custom metric prefix", () => { + expect(collectInstrumentNames("claude_code.")).toEqual( + EXPECTED.map((entry) => entry.replace("opencode.", "claude_code.")), + ) + }) + + test("does not register a bare lines_of_code.total", () => { + expect(collectInstrumentNames()).not.toContain("histogram:opencode.lines_of_code.total") + expect(collectInstrumentNames()).not.toContain("gauge:opencode.lines_of_code.total") + }) +}) + describe("forceFlushOtel", () => { test("flushes metrics, logs, and traces", async () => { const calls: string[] = [] From 125360e9ec9cde1104a3d526b89e0c24ca059135 Mon Sep 17 00:00:00 2001 From: Shawn Zhang Date: Sat, 19 Sep 2026 00:33:15 +0800 Subject: [PATCH 2/2] feat(metrics)!: drop project.id from metric labels `project.id` was spread into every metric data point through `commonAttrs`. It is derived from the project directory, so it stays small for interactive use, but it has the same two properties that made `session.id` a problem: it is unbounded in CI, where every checkout can be a fresh path, and cumulative aggregation never evicts, so a long-lived process keeps re-exporting every project it has ever seen on every export. Split the shared attribute set in two. `commonAttrs` keeps `project.id` and is used by spans and log events, where per-project drill-down belongs. The new `metricAttrs` carries only the configured `OPENCODE_SPAN_ATTRIBUTES` pairs and is what every metric call site now spreads. With both identifiers off metrics, the remaining labels are bounded dimensions only: `model`, `provider`, `agent`, `agent.type`, `type`, `tool_name`, `success`, `is_subagent`. `project.id` is unchanged on spans and OTLP log events. Tests: the cardinality guard now asserts `project.id` is absent from every metric data point as well as `session.id`, and asserts the reverse for logs and spans so the split cannot silently drop the attribute from both sides. Two existing tests that pinned `project.id` onto counters are inverted to pin it off. Mutation-verified: re-injecting `project.id` into a single counter fails the guard with `instrument "commit" leaked project.id`. BREAKING CHANGE: `project.id` is no longer present on any metric data point. Dashboards and alerts that group metrics by project must move to traces or log events, where `project.id` remains, or use the `model` / `agent` attributes that stay on metrics. Cost and token attribution per project is no longer possible from metrics alone. Co-Authored-By: Claude Code --- README.md | 4 ++-- src/handlers/activity.ts | 6 +++--- src/handlers/message.ts | 24 +++++++++++------------ src/handlers/session.ts | 14 ++++++------- src/index.ts | 5 ++++- src/types.ts | 7 +++++++ tests/handlers/message.test.ts | 4 ++-- tests/handlers/metric-cardinality.test.ts | 23 +++++++++++++--------- tests/handlers/session.test.ts | 6 +++--- tests/helpers.ts | 1 + 10 files changed, 55 insertions(+), 39 deletions(-) diff --git a/README.md b/README.md index 6ab5941..15820f2 100644 --- a/README.md +++ b/README.md @@ -51,7 +51,7 @@ An [opencode](https://opencode.ai) plugin that exports telemetry via OpenTelemet | `opencode.retry.count` | Counter | API retries observed via `session.status` events | | `opencode.subtask.count` | Counter | Sub-agent invocations observed via `subtask` message parts | -All metrics are **low-cardinality by design**. `session.id` is deliberately *not* a metric label — it appears only on spans and log events, where per-session drill-down belongs and high cardinality is acceptable. Metric labels are limited to bounded dimensions (`project.id`, `model`, `provider`, `agent`, `agent.type`, `type`, `tool_name`, `success`, `is_subagent`) plus anything you add yourself via `OPENCODE_SPAN_ATTRIBUTES`. Keep those bounded too: every distinct label combination is a separate time series, and a histogram multiplies it by its bucket count (20 series per combination at the default boundaries). +All metrics are **low-cardinality by design**. `session.id` and `project.id` are deliberately *not* metric labels — they appear only on spans and log events, where per-session and per-project drill-down belongs and high cardinality is acceptable. `project.id` is derived from the project directory, so it stays small for interactive use but grows without bound in CI, where every checkout can be a fresh path. Metric labels are limited to bounded dimensions (`model`, `provider`, `agent`, `agent.type`, `type`, `tool_name`, `success`, `is_subagent`) plus anything you add yourself via `OPENCODE_SPAN_ATTRIBUTES`. Keep those bounded too: every distinct label combination is a separate time series, and a histogram multiplies it by its bucket count (20 series per combination at the default boundaries). ### Log events @@ -195,7 +195,7 @@ export OPENCODE_SPAN_ATTRIBUTES="team=platform,deployment.environment=production - Use `OPENCODE_RESOURCE_ATTRIBUTES` for producer metadata on the OTel Resource. - Use `OPENCODE_SPAN_ATTRIBUTES` for attributes that need to appear on each span, log event, and metric data point for filtering or grouping in backends. -> **Watch the cardinality.** These pairs land on every metric data point as labels, so their values are multiplied by every other label and by the bucket count of each histogram. Use bounded values (`team`, `deployment.environment`, `service.version`) and avoid per-request or per-user values. A high-cardinality value here has exactly the same effect as the `session.id` label this plugin deliberately keeps off metrics — the only difference is that the plugin cannot bound it for you, so it is your configuration rather than the plugin that decides how many series get created. +> **Watch the cardinality.** These pairs land on every metric data point as labels, so their values are multiplied by every other label and by the bucket count of each histogram. Use bounded values (`team`, `deployment.environment`, `service.version`) and avoid per-request or per-user values. A high-cardinality value here has exactly the same effect as the `session.id` and `project.id` labels this plugin deliberately keeps off metrics — the only difference is that the plugin cannot bound it for you, so it is your configuration rather than the plugin that decides how many series get created. ### Dynamic headers diff --git a/src/handlers/activity.ts b/src/handlers/activity.ts index c30120c..26a54f8 100644 --- a/src/handlers/activity.ts +++ b/src/handlers/activity.ts @@ -31,10 +31,10 @@ export function handleSessionDiff(e: EventSessionDiff, ctx: HandlerContext) { if (linesEnabled) { if (deltaAdded > 0) { - ctx.instruments.linesCounter.add(deltaAdded, { ...ctx.commonAttrs, type: "added" }) + ctx.instruments.linesCounter.add(deltaAdded, { ...ctx.metricAttrs, type: "added" }) } if (deltaRemoved > 0) { - ctx.instruments.linesCounter.add(deltaRemoved, { ...ctx.commonAttrs, type: "removed" }) + ctx.instruments.linesCounter.add(deltaRemoved, { ...ctx.metricAttrs, type: "removed" }) } } @@ -58,7 +58,7 @@ export function handleCommandExecuted(e: EventCommandExecuted, ctx: HandlerConte const { agentName, agentType } = getSessionAgentMeta(e.properties.sessionID, ctx) if (isMetricEnabled("commit.count", ctx)) { - ctx.instruments.commitCounter.add(1, ctx.commonAttrs) + ctx.instruments.commitCounter.add(1, ctx.metricAttrs) ctx.log("debug", "otel: commit counter incremented", { sessionID: e.properties.sessionID }) } ctx.emitLog({ diff --git a/src/handlers/message.ts b/src/handlers/message.ts index ebb0151..538f0cc 100644 --- a/src/handlers/message.ts +++ b/src/handlers/message.ts @@ -75,32 +75,32 @@ export function handleMessageUpdated(e: EventMessageUpdated, ctx: HandlerContext if (isMetricEnabled("token.usage", ctx)) { const { tokenCounter } = ctx.instruments - tokenCounter.add(assistant.tokens.input, { ...ctx.commonAttrs,model: modelID, agent, type: "input" }) - tokenCounter.add(assistant.tokens.output, { ...ctx.commonAttrs,model: modelID, agent, type: "output" }) - tokenCounter.add(assistant.tokens.reasoning, { ...ctx.commonAttrs,model: modelID, agent, type: "reasoning" }) - tokenCounter.add(assistant.tokens.cache.read, { ...ctx.commonAttrs,model: modelID, agent, type: "cacheRead" }) - tokenCounter.add(assistant.tokens.cache.write, { ...ctx.commonAttrs,model: modelID, agent, type: "cacheCreation" }) + tokenCounter.add(assistant.tokens.input, { ...ctx.metricAttrs,model: modelID, agent, type: "input" }) + tokenCounter.add(assistant.tokens.output, { ...ctx.metricAttrs,model: modelID, agent, type: "output" }) + tokenCounter.add(assistant.tokens.reasoning, { ...ctx.metricAttrs,model: modelID, agent, type: "reasoning" }) + tokenCounter.add(assistant.tokens.cache.read, { ...ctx.metricAttrs,model: modelID, agent, type: "cacheRead" }) + tokenCounter.add(assistant.tokens.cache.write, { ...ctx.metricAttrs,model: modelID, agent, type: "cacheCreation" }) } if (isMetricEnabled("cost.usage", ctx)) { - ctx.instruments.costCounter.add(assistant.cost, { ...ctx.commonAttrs,model: modelID, agent }) + ctx.instruments.costCounter.add(assistant.cost, { ...ctx.metricAttrs,model: modelID, agent }) } if (isMetricEnabled("cache.count", ctx)) { if (assistant.tokens.cache.read > 0) { - ctx.instruments.cacheCounter.add(1, { ...ctx.commonAttrs,model: modelID, agent, type: "cacheRead" }) + ctx.instruments.cacheCounter.add(1, { ...ctx.metricAttrs,model: modelID, agent, type: "cacheRead" }) } if (assistant.tokens.cache.write > 0) { - ctx.instruments.cacheCounter.add(1, { ...ctx.commonAttrs,model: modelID, agent, type: "cacheCreation" }) + ctx.instruments.cacheCounter.add(1, { ...ctx.metricAttrs,model: modelID, agent, type: "cacheCreation" }) } } if (isMetricEnabled("message.count", ctx)) { - ctx.instruments.messageCounter.add(1, { ...ctx.commonAttrs,model: modelID, agent }) + ctx.instruments.messageCounter.add(1, { ...ctx.metricAttrs,model: modelID, agent }) } if (isMetricEnabled("model.usage", ctx)) { - ctx.instruments.modelUsageCounter.add(1, { ...ctx.commonAttrs,model: modelID, provider: providerID, agent }) + ctx.instruments.modelUsageCounter.add(1, { ...ctx.metricAttrs,model: modelID, provider: providerID, agent }) } accumulateSessionTotals(sessionID, totalTokens, assistant.cost, ctx) @@ -244,7 +244,7 @@ export function handleMessagePartUpdated(e: EventMessagePartUpdated, ctx: Handle const subtask = part as unknown as SubtaskPart if (isMetricEnabled("subtask.count", ctx)) { ctx.instruments.subtaskCounter.add(1, { - ...ctx.commonAttrs, + ...ctx.metricAttrs, agent: subtask.agent, "agent.type": "subagent", }) @@ -326,7 +326,7 @@ export function handleMessagePartUpdated(e: EventMessagePartUpdated, ctx: Handle if (isMetricEnabled("tool.duration", ctx)) { ctx.instruments.toolDurationHistogram.record(duration_ms, { - ...ctx.commonAttrs, + ...ctx.metricAttrs, tool_name: toolPart.tool, success, }) diff --git a/src/handlers/session.ts b/src/handlers/session.ts index 6463f4c..dc17c50 100644 --- a/src/handlers/session.ts +++ b/src/handlers/session.ts @@ -88,7 +88,7 @@ export function handleSessionCreated(e: EventSessionCreated, ctx: HandlerContext const isSubagent = !!parentID const agentType: SessionAgentType = isSubagent ? "subagent" : "primary" if (isMetricEnabled("session.count", ctx)) { - ctx.instruments.sessionCounter.add(1, { ...ctx.commonAttrs, is_subagent: isSubagent }) + ctx.instruments.sessionCounter.add(1, { ...ctx.metricAttrs, is_subagent: isSubagent }) } setBoundedMap(ctx.sessionTotals, sessionID, { startMs: createdAt, tokens: 0, cost: 0, messages: 0, agent: "unknown", agentType }) @@ -137,8 +137,8 @@ export function handleSessionCreated(e: EventSessionCreated, ctx: HandlerContext */ function recordSessionLines(diff: { additions: number; deletions: number } | undefined, ctx: HandlerContext) { if (!diff || !isMetricEnabled("session.lines_of_code.total", ctx)) return - ctx.instruments.sessionLinesTotal.record(diff.additions, { ...ctx.commonAttrs, type: "added" }) - ctx.instruments.sessionLinesTotal.record(diff.deletions, { ...ctx.commonAttrs, type: "removed" }) + ctx.instruments.sessionLinesTotal.record(diff.additions, { ...ctx.metricAttrs, type: "added" }) + ctx.instruments.sessionLinesTotal.record(diff.deletions, { ...ctx.metricAttrs, type: "removed" }) } function sweepSession(sessionID: string, ctx: HandlerContext) { @@ -183,13 +183,13 @@ export function handleSessionIdle(e: EventSessionIdle, ctx: HandlerContext) { if (totals) { duration_ms = Date.now() - totals.startMs if (isMetricEnabled("session.duration", ctx)) { - ctx.instruments.sessionDurationHistogram.record(duration_ms, ctx.commonAttrs) + ctx.instruments.sessionDurationHistogram.record(duration_ms, ctx.metricAttrs) } if (isMetricEnabled("session.token.total", ctx)) { - ctx.instruments.sessionTokenGauge.record(totals.tokens, ctx.commonAttrs) + ctx.instruments.sessionTokenGauge.record(totals.tokens, ctx.metricAttrs) } if (isMetricEnabled("session.cost.total", ctx)) { - ctx.instruments.sessionCostGauge.record(totals.cost, ctx.commonAttrs) + ctx.instruments.sessionCostGauge.record(totals.cost, ctx.metricAttrs) } } @@ -358,7 +358,7 @@ export function handleSessionStatus(e: EventSessionStatus, ctx: HandlerContext) const { sessionID, status } = e.properties const { attempt, message: retryMessage } = status if (isMetricEnabled("retry.count", ctx)) { - ctx.instruments.retryCounter.add(1, ctx.commonAttrs) + ctx.instruments.retryCounter.add(1, ctx.metricAttrs) ctx.log("debug", "otel: retry counter incremented", { sessionID, attempt, retryMessage }) } } diff --git a/src/index.ts b/src/index.ts index 7354a3a..7588f98 100644 --- a/src/index.ts +++ b/src/index.ts @@ -119,10 +119,12 @@ export const OtelPlugin: Plugin = async ({ project, client, directory, worktree const messageOutputs = new Map() const llmRequestContexts = new Map() const { disabledMetrics, disabledTraces } = config + const spanAttributePairs = parseAttributePairs(config.spanAttributes) const commonAttrs = { - ...parseAttributePairs(config.spanAttributes), + ...spanAttributePairs, "project.id": project.id, } as const + const metricAttrs = { ...spanAttributePairs } as const if (disabledMetrics.size > 0) { await log("info", "metrics disabled", { disabled: [...disabledMetrics] }) @@ -148,6 +150,7 @@ export const OtelPlugin: Plugin = async ({ project, client, directory, worktree emitLog, instruments, commonAttrs, + metricAttrs, pendingToolSpans, pendingPermissions, sessionTotals, diff --git a/src/types.ts b/src/types.ts index 1386333..62f3f87 100644 --- a/src/types.ts +++ b/src/types.ts @@ -89,7 +89,14 @@ export type HandlerContext = { log: PluginLogger emitLog: (record: LogRecord) => void instruments: Instruments + /** Attributes for emitted spans and log events: the configured span attributes plus `project.id`. */ commonAttrs: CommonAttrs + /** + * Attributes for metric data points: the configured span attributes only. Identifiers that are + * useful for drill-down but unbounded as Prometheus labels — `project.id`, `session.id` — belong + * on spans and log events, never here. + */ + metricAttrs: CommonAttrs pendingToolSpans: Map pendingPermissions: Map sessionTotals: Map diff --git a/tests/handlers/message.test.ts b/tests/handlers/message.test.ts index 19d9951..23767de 100644 --- a/tests/handlers/message.test.ts +++ b/tests/handlers/message.test.ts @@ -426,10 +426,10 @@ describe("handleMessagePartUpdated — subtask parts", () => { expect(record.attributes?.["prompt_length"]).toBe("Create a plan".length) }) - test("includes project.id in subtask counter attrs", async () => { + test("does not include project.id in subtask counter attrs", async () => { const { ctx, counters } = makeCtx("proj_xyz") await handleMessagePartUpdated(makeSubtaskPartUpdated(), ctx) - expect(counters.subtask.calls.at(0)!.attrs["project.id"]).toBe("proj_xyz") + expect(counters.subtask.calls.at(0)!.attrs["project.id"]).toBeUndefined() }) test("does not record subtask counter when subtask.count is disabled", async () => { diff --git a/tests/handlers/metric-cardinality.test.ts b/tests/handlers/metric-cardinality.test.ts index c64bc50..eb91f8d 100644 --- a/tests/handlers/metric-cardinality.test.ts +++ b/tests/handlers/metric-cardinality.test.ts @@ -1,5 +1,5 @@ import { describe, test, expect } from "bun:test" -import { handleSessionCreated, handleSessionIdle, handleSessionDeleted, handleSessionStatus } from "../../src/handlers/session.ts" +import { handleSessionCreated, handleSessionIdle, handleSessionDeleted, handleSessionStatus, handleRunStarted } from "../../src/handlers/session.ts" import { handleMessageUpdated, handleMessagePartUpdated } from "../../src/handlers/message.ts" import { handleSessionDiff, handleCommandExecuted } from "../../src/handlers/activity.ts" import { handlePermissionUpdated, handlePermissionReplied } from "../../src/handlers/permission.ts" @@ -124,7 +124,7 @@ const EXPECTED_LOG_BODIES = [ ] describe("metric cardinality", () => { - test("no metric data point carries session.id (covers instruments registered in MockContext)", async () => { + test("no metric data point carries session.id or project.id (covers instruments registered in MockContext)", async () => { const mocks = makeCtx("proj_test", [], [], true, { team: "platform" }) const { ctx } = mocks @@ -160,13 +160,13 @@ describe("metric cardinality", () => { for (const [name, spy] of instruments) { for (const call of spy.calls) { expect(call.attrs["session.id"], `instrument "${name}" leaked session.id`).toBeUndefined() - expect(call.attrs["project.id"]).toBe("proj_test") - expect(call.attrs["team"]).toBe("platform") + expect(call.attrs["project.id"], `instrument "${name}" leaked project.id`).toBeUndefined() + expect(call.attrs["team"], `instrument "${name}" lost the configured span attributes`).toBe("platform") } } }) - test("every handler-reachable log event still carries session.id", async () => { + test("every handler-reachable log event still carries session.id and project.id", async () => { const { ctx, logger } = makeCtx() await handleSessionCreated(makeSessionCreated("ses_1"), ctx) await handleMessageUpdated(makeAssistantMessage(), ctx) @@ -188,13 +188,18 @@ describe("metric cardinality", () => { for (const record of logger.records) { expect(record.attributes?.["session.id"], `log event "${record.body}" lost session.id`).toBe("ses_1") + expect(record.attributes?.["project.id"], `log event "${record.body}" lost project.id`).toBe("proj_test") } }) - test("subagent session span still carries session.id", () => { + test("spans still carry session.id and project.id", () => { const { ctx, tracer } = makeCtx() - handleSessionCreated(makeSessionCreated("ses_child", "ses_parent"), ctx) - expect(tracer.spans).toHaveLength(1) - expect(tracer.spans[0]!.attributes["session.id"]).toBe("ses_child") + handleRunStarted("user_1", "ses_1", "build", "prompt", "anthropic/claude", 900, ctx) + handleSessionCreated(makeSessionCreated("ses_child", "ses_1"), ctx) + expect(tracer.spans.length).toBeGreaterThan(0) + for (const span of tracer.spans) { + expect(span.attributes["project.id"], `span "${span.name}" lost project.id`).toBe("proj_test") + } + expect(tracer.spans.find((s) => s.attributes["session.id"] === "ses_child")).toBeDefined() }) }) diff --git a/tests/handlers/session.test.ts b/tests/handlers/session.test.ts index fef1870..e9fcc53 100644 --- a/tests/handlers/session.test.ts +++ b/tests/handlers/session.test.ts @@ -73,10 +73,10 @@ describe("handleSessionCreated", () => { expect(call.extra?.["sessionID"]).toBe("ses_1") }) - test("includes project.id in counter attrs", async () => { + test("does not include project.id in counter attrs", async () => { const { ctx, counters } = makeCtx("proj_abc") await handleSessionCreated(makeSessionCreated("ses_1"), ctx) - expect(counters.session.calls.at(0)!.attrs["project.id"]).toBe("proj_abc") + expect(counters.session.calls.at(0)!.attrs["project.id"]).toBeUndefined() }) test("stores session totals with startMs", async () => { @@ -230,7 +230,7 @@ describe("handleSessionDeleted", () => { handleSessionDeleted(makeSessionDeleted("ses_1"), ctx) expect(histograms.sessionLinesTotal.calls).toHaveLength(2) for (const call of histograms.sessionLinesTotal.calls) { - expect(call.attrs["project.id"]).toBe("proj_test") + expect(call.attrs["project.id"]).toBeUndefined() expect(call.attrs["team"]).toBe("platform") expect(call.attrs["session.id"]).toBeUndefined() } diff --git a/tests/helpers.ts b/tests/helpers.ts index 666d6cd..3fa7927 100644 --- a/tests/helpers.ts +++ b/tests/helpers.ts @@ -213,6 +213,7 @@ export function makeCtx( }, instruments, commonAttrs: { "project.id": projectID, ...extraCommonAttrs }, + metricAttrs: { ...extraCommonAttrs }, pendingToolSpans: new Map(), pendingPermissions: new Map(), sessionTotals: new Map(),