From 4b9d4a104bae8cc71f45a80f6cf615530fefae92 Mon Sep 17 00:00:00 2001 From: qqqys Date: Tue, 15 Sep 2026 15:49:28 +0800 Subject: [PATCH 1/4] feat(telemetry): emit a Goal lifecycle event and metrics A Goal runs on its own, and every way it stops is recorded only in the session transcript: telemetry had no Goal event and no Goal metric. Each committed transition an operator acts on (the user's controls and the stops: complete, blocked, usage_limited, verifier_reject) is now a `qwen-code.goal_state` event, subscribed where the Config builds the runtime. Per-turn causes are left out. The event carries identifiers, enums and numbers only; the objective, stop reasons and checkpoint failure text are never sent, because `telemetry.logPrompts` defaults to on. A transition counter and two outcome histograms keep the Goal id off metric attributes. `restore()` republishes a resumed session's Goal with the cause of the record it recovered, which a subscriber cannot tell from the live transition that first produced it. Broadcast listeners now receive an optional third argument, and the restore broadcast is the only one that marks itself `replayed`, so a resumed session does not report its Goal a second time. --- docs/design/2026-09-15-goal-telemetry.md | 47 +++++ .../design/2026-09-15-goal-telemetry.zh-CN.md | 47 +++++ docs/developers/development/telemetry.md | 16 ++ docs/users/features/goals.md | 4 + packages/core/src/config/config.test.ts | 46 ++++- packages/core/src/config/config.ts | 12 ++ packages/core/src/goals/goal-protocol.ts | 13 ++ packages/core/src/goals/goal-runtime.test.ts | 45 +++++ packages/core/src/goals/goal-runtime.ts | 33 +++- packages/core/src/telemetry/constants.ts | 1 + .../core/src/telemetry/goal-events.test.ts | 167 ++++++++++++++++++ packages/core/src/telemetry/goal-events.ts | 65 +++++++ packages/core/src/telemetry/index.ts | 20 ++- packages/core/src/telemetry/loggers.test.ts | 69 ++++++++ packages/core/src/telemetry/loggers.ts | 23 +++ packages/core/src/telemetry/metrics.test.ts | 97 ++++++++++ packages/core/src/telemetry/metrics.ts | 83 +++++++++ .../telemetry/qwen-logger/qwen-logger.test.ts | 35 ++++ .../src/telemetry/qwen-logger/qwen-logger.ts | 29 +++ packages/core/src/telemetry/types.ts | 68 +++++++ 20 files changed, 911 insertions(+), 9 deletions(-) create mode 100644 docs/design/2026-09-15-goal-telemetry.md create mode 100644 docs/design/2026-09-15-goal-telemetry.zh-CN.md create mode 100644 packages/core/src/telemetry/goal-events.test.ts create mode 100644 packages/core/src/telemetry/goal-events.ts diff --git a/docs/design/2026-09-15-goal-telemetry.md b/docs/design/2026-09-15-goal-telemetry.md new file mode 100644 index 00000000000..e825616370c --- /dev/null +++ b/docs/design/2026-09-15-goal-telemetry.md @@ -0,0 +1,47 @@ +# Goal telemetry + +[English](2026-09-15-goal-telemetry.md) | [简体中文](2026-09-15-goal-telemetry.zh-CN.md) + +## Problem + +A Goal runs autonomously, and the ways it stops — the verifier completing or blocking it, a token, turn or active-time budget running out, the no-progress bound pausing it, the user pausing or clearing it — are recorded only in the session transcript. The telemetry package has no Goal event and no Goal metric. An operator who wants to know how often Goals end blocked, how much a completed Goal spends, or whether a budget is set too low has to read transcripts one at a time. + +Codex counts goal outcomes in its metrics, and Claude Code emits `tengu_goal_*` analytics events. Neither carries the objective text. + +## Design + +**One event, distinguished by cause.** Every reported transition is a `qwen-code.goal_state` event whose `cause` is the runtime's own `GoalStateCause`. A separate event per transition would each need a type, a logger, an analytics-sink method and a documentation entry while carrying the same fields. + +**Which causes are reported.** `create`, `replace`, `edit`, `pause`, `resume`, `clear`, `complete`, `blocked`, `usage_limited` and `verifier_reject`: the user's controls and the stops a user acts on. `turn_finished` and `checkpoint` happen on every turn; they would multiply the volume, and per-turn token spend is already in the API metrics. `migrated` is a one-off format migration. `verifier_accept` is always followed by the `complete` or `blocked` it accepted. Broadcasts without a cause are activity changes inside the runtime. + +**Where it is wired.** `Config.initializeGoalRuntime` subscribes to the runtime it has just created. It is the one place that holds both the runtime and the `Config` every telemetry logger takes, and it subscribes before the restore it starts, so no transition can commit with nobody listening. The mapping from a snapshot to an event is a pure function in the telemetry package, `goalStateEventFromSnapshot`. + +**Restored state is not reported again.** `restore()` republishes a resumed session's Goal with the cause of the record it recovered: a paused Goal comes back as a `pause` broadcast, a budget-stopped Goal as `usage_limited`. A subscriber cannot tell that broadcast from the live transition that first produced it, and comparing against `getRecoveryCause()` is ambiguous as soon as a later live transition carries the same cause. The runtime therefore passes a third broadcast argument, `meta`, with `replayed: true` on that one broadcast and nothing on any other, and the telemetry subscriber skips replays. Existing listeners that take two arguments are unaffected. + +**No free text.** The event carries identifiers, enums and numbers: the Goal id and revision, the resulting status, the limit kind, the turn count and turn budget, tokens used and the token budget, active time and the active-time budget, and the objective's length in code points. The objective, the stop reason and the checkpoint failure message are never included. `telemetry.logPrompts`, the switch that gates prompt text elsewhere, defaults to on, so gating the objective behind it would include it by default. An active Goal's committed `activeTimeMs` lags the clock, so the event reads it as of the broadcast. + +**Metrics stay bounded.** `qwen-code.goal.transition.count` counts every event, tagged by `cause`, `status` and `limit_kind`. On `complete`, `blocked` and `usage_limited`, the histograms `qwen-code.goal.tokens_used` and `qwen-code.goal.turn_count` record what the Goal had spent, tagged by `cause` and `limit_kind`. The Goal id stays on the log record: every Goal is a new value, which is the unbounded time-series fan-out the metrics module already declines for `session.id` by default. + +**Both sinks.** The log record goes to OpenTelemetry when the SDK is initialized, and the analytics sink receives the event when usage statistics are enabled, as with every other event. The analytics payload leaves out the Goal id, because that sink aggregates by installation. + +## Scope + +- `goal-protocol.ts`: `GoalBroadcastMeta`. +- `goal-runtime.ts`: the optional `meta` argument on `subscribe` listeners and on `broadcast`, set on the restore broadcast. +- `telemetry/types.ts` and `constants.ts`: `GoalStateEvent`, `GOAL_STATE_EVENT_CAUSES`, `makeGoalStateEvent`, `EVENT_GOAL_STATE`. +- `telemetry/goal-events.ts`: `goalStateEventFromSnapshot`. +- `telemetry/loggers.ts`, `qwen-logger/qwen-logger.ts`, `metrics.ts` and `index.ts`: `logGoalState`, `logGoalStateEvent`, `recordGoalStateMetrics` and the three instruments. +- `config/config.ts`: the subscriber. +- Documentation: the telemetry reference and the Goals feature page. + +Not changed: the per-stream Goal state subscription in `client.ts` that feeds the UI, Goal proposal approvals, and spans for Goal turns. + +## Verification + +- `goal-events.test.ts`: every reported cause maps to an event and every unreported cause does not; figures are carried and absent ones are left out rather than set to `undefined`; an active Goal's time is read as of the broadcast; the objective length counts code points; `clear` names the removed Goal and carries no figures; no objective or reason text appears in the serialized event. +- `goal-runtime.test.ts`: the restore broadcast carries `meta.replayed`, and a later live transition carries no `meta`. +- `loggers.test.ts`: the log record's body and attributes, the metrics call, and the analytics sink still being called when the OpenTelemetry SDK is off. +- `qwen-logger.test.ts`: the analytics event leaves out the Goal id and absent figures. +- `metrics.test.ts`: the instruments are registered; the counter carries only its three bounded attributes; the histograms record only on the three outcomes. +- `config.test.ts`: a created Goal is reported once; a resumed session's recovered Goal is not reported, and the user's next control on it is. +- End to end: a headless run writing telemetry to a file before and after the change, and a resumed session that reports no second transition for the recovered Goal. diff --git a/docs/design/2026-09-15-goal-telemetry.zh-CN.md b/docs/design/2026-09-15-goal-telemetry.zh-CN.md new file mode 100644 index 00000000000..77861a49969 --- /dev/null +++ b/docs/design/2026-09-15-goal-telemetry.zh-CN.md @@ -0,0 +1,47 @@ +# Goal 遥测 + +[English](2026-09-15-goal-telemetry.md) | [简体中文](2026-09-15-goal-telemetry.zh-CN.md) + +## 问题 + +Goal 是自主运行的，它停下来的方式——verifier 判定完成或 blocked、token/轮数/活跃时长预算耗尽、空转上限触发 pause、用户 pause 或 clear——只记录在会话 transcript 里。遥测包里既没有 Goal 事件，也没有 Goal 指标。运维人员想知道 Goal 有多大比例以 blocked 结束、一个完成的 Goal 花了多少、某个预算是否设得太低，只能逐个翻 transcript。 + +Codex 在指标里统计 goal 结果，Claude Code 发出 `tengu_goal_*` 分析事件。两者都不携带目标文本。 + +## 设计 + +**一个事件，用 cause 区分。** 每次上报的状态转换都是一个 `qwen-code.goal_state` 事件，其 `cause` 就是运行时自身的 `GoalStateCause`。如果每种转换单独一个事件，每个都要一个类型、一个 logger、一个分析 sink 方法和一条文档，而字段完全相同。 + +**上报哪些 cause。** `create`、`replace`、`edit`、`pause`、`resume`、`clear`、`complete`、`blocked`、`usage_limited` 和 `verifier_reject`：用户的控制操作，以及用户需要处理的停止。`turn_finished` 与 `checkpoint` 每轮都会发生，会成倍放大事件量，而每轮的 token 花费已经在 API 指标里。`migrated` 是一次性的格式迁移。`verifier_accept` 之后总会紧跟它所接受的 `complete` 或 `blocked`。没有 cause 的广播是运行时内部的活动状态变化。 + +**接线位置。** `Config.initializeGoalRuntime` 订阅它刚创建的运行时。这是唯一同时持有运行时和每个遥测 logger 所需 `Config` 的地方；并且订阅发生在它启动 restore 之前，所以不存在状态转换已提交却没有监听者的窗口。从快照到事件的映射是遥测包里的纯函数 `goalStateEventFromSnapshot`。 + +**恢复出来的状态不重复上报。** `restore()` 会以所恢复记录的 cause 重新发布续跑会话的 Goal：一个 paused 的 Goal 以 `pause` 广播回来，一个因预算停下的 Goal 以 `usage_limited` 回来。订阅者无法把这次广播和最初产生它的那次实时转换区分开；而与 `getRecoveryCause()` 比较，一旦之后的实时转换带着相同 cause 就会产生歧义。因此运行时给广播加第三个参数 `meta`，只在这一次广播上传 `replayed: true`，其余广播都不传；遥测订阅者跳过重播。只接收两个参数的现有监听者不受影响。 + +**不带自由文本。** 事件只携带标识、枚举和数字：Goal id 与 revision、转换后的状态、限制类型、轮数与轮数预算、已用 token 与 token 预算、活跃时长与活跃时长预算，以及目标按码点计的长度。目标、停止原因和 checkpoint 失败信息一律不包含。别处用来控制 prompt 文本的开关 `telemetry.logPrompts` 默认开启，所以把目标放在它后面就等于默认上报。active 状态的 Goal 已提交的 `activeTimeMs` 落后于时钟，所以事件按广播时刻读取。 + +**指标保持有界。** `qwen-code.goal.transition.count` 统计每个事件，属性为 `cause`、`status` 和 `limit_kind`。在 `complete`、`blocked` 和 `usage_limited` 时，直方图 `qwen-code.goal.tokens_used` 与 `qwen-code.goal.turn_count` 记录 Goal 到此为止的花费，属性为 `cause` 和 `limit_kind`。Goal id 只留在日志记录上：每个 Goal 都是一个新值，这正是指标模块默认对 `session.id` 所拒绝的无界时间序列膨胀。 + +**两个 sink。** 与其他所有事件一样，OpenTelemetry SDK 初始化时日志记录发往 OpenTelemetry，启用使用统计时分析 sink 收到该事件。分析 sink 的载荷不含 Goal id，因为该 sink 按安装实例聚合。 + +## 范围 + +- `goal-protocol.ts`：`GoalBroadcastMeta`。 +- `goal-runtime.ts`：`subscribe` 监听器与 `broadcast` 上可选的 `meta` 参数，在 restore 广播上设置。 +- `telemetry/types.ts` 与 `constants.ts`：`GoalStateEvent`、`GOAL_STATE_EVENT_CAUSES`、`makeGoalStateEvent`、`EVENT_GOAL_STATE`。 +- `telemetry/goal-events.ts`：`goalStateEventFromSnapshot`。 +- `telemetry/loggers.ts`、`qwen-logger/qwen-logger.ts`、`metrics.ts` 与 `index.ts`：`logGoalState`、`logGoalStateEvent`、`recordGoalStateMetrics` 以及三个指标。 +- `config/config.ts`：订阅者。 +- 文档：遥测参考文档与 Goal 功能页。 + +不改动：`client.ts` 里为 UI 提供数据的按流 Goal 状态订阅、Goal 提案审批、Goal 轮的 span。 + +## 验证 + +- `goal-events.test.ts`：每个上报的 cause 都映射为事件，每个不上报的 cause 都不产生事件；数值字段被携带，缺失的字段直接省略而不是设为 `undefined`；active Goal 的时长按广播时刻读取；目标长度按码点计数；`clear` 给出被移除的 Goal 且不带数值；序列化后的事件里不出现目标或原因文本。 +- `goal-runtime.test.ts`：restore 广播带 `meta.replayed`，之后的实时转换不带 `meta`。 +- `loggers.test.ts`：日志记录的 body 与属性、指标调用，以及 OpenTelemetry SDK 关闭时分析 sink 仍被调用。 +- `qwen-logger.test.ts`：分析事件不含 Goal id 与缺失的数值字段。 +- `metrics.test.ts`：三个指标已注册；计数器只带三个有界属性；直方图只在三种结果时记录。 +- `config.test.ts`：新建的 Goal 上报一次；续跑会话恢复出来的 Goal 不上报，用户对它的下一次控制操作会上报。 +- 端到端：改动前后各跑一次把遥测写入文件的 headless 运行，并验证续跑会话不会为恢复出来的 Goal 再上报一次转换。 diff --git a/docs/developers/development/telemetry.md b/docs/developers/development/telemetry.md index f145738131e..a02c4d0c979 100644 --- a/docs/developers/development/telemetry.md +++ b/docs/developers/development/telemetry.md @@ -716,6 +716,11 @@ The following events are logged: - `qwen-code.subagent_execution`: Subagent lifecycle event. - **Attributes**: `subagent_name` (string), `status` ("started", "completed", "failed", "cancelled"), `terminate_reason` (optional), `result` (optional), `execution_summary` (optional) +#### Goal Events + +- `qwen-code.goal_state`: A committed Goal state transition. Emitted for `create`, `replace`, `edit`, `pause`, `resume`, `clear`, `complete`, `blocked`, `usage_limited`, and `verifier_reject`. Per-turn `turn_finished` and `checkpoint` are not reported, and neither is the state a resumed session recovers from its transcript. The objective, the stop reason, and checkpoint failure text are never included, whatever `telemetry.logPrompts` is set to. + - **Attributes**: `cause` (string), `goal_id` (string), `revision` (int), `status` ("active", "paused", "blocked", "usage_limited", "complete"; absent on `clear`), `limit_kind` ("evidence_catalog", "checkpoint_request", "token_budget", "turn_budget", "time_budget"; optional), `turn_count` (int, optional), `tokens_used` (int, optional), `token_budget` (int, optional), `turn_budget` (int, optional), `active_time_ms` (int, optional), `active_time_budget_ms` (int, optional), `objective_length` (int, optional; code points) + #### Arena Events - `qwen-code.arena_session_started`: Arena session begins. @@ -816,6 +821,17 @@ Metrics are numerical measurements of behavior over time. Metric names use the ` - `qwen-code.chat.invalid_chunk.count` (Counter, Int): Invalid chunks from stream. +#### Goal Metrics + +- `qwen-code.goal.transition.count` (Counter, Int): Goal state transitions, one per `qwen-code.goal_state` event. + - **Attributes**: `cause`, `status` (optional), `limit_kind` (optional) + +- `qwen-code.goal.tokens_used` (Histogram, `{token}`): Tokens a Goal had spent when it completed, was blocked, or reached a usage limit. + - **Attributes**: `cause` ("complete", "blocked", "usage_limited"), `limit_kind` (optional) + +- `qwen-code.goal.turn_count` (Histogram, `{turn}`): Turns a Goal had finished at the same three outcomes. + - **Attributes**: `cause` ("complete", "blocked", "usage_limited"), `limit_kind` (optional) + #### Arena Metrics - `qwen-code.arena.session.count` (Counter, Int): Arena sessions by status. diff --git a/docs/users/features/goals.md b/docs/users/features/goals.md index ec666c2caa2..4e236ecab97 100644 --- a/docs/users/features/goals.md +++ b/docs/users/features/goals.md @@ -88,3 +88,7 @@ In an interactive terminal or a Web Shell turn with an attached client, the mode Turn it off with `goals.modelProposed: "disabled"` in your user settings. Because the setting decides whether the model may ask you to start an autonomous loop, it is honored only from user and system scope; a workspace `.qwen/settings.json` value is ignored with a warning. The skill is instructed to be read-only, and only its non-mutating tools are auto-approved (`get_goal`, `read_file`, `glob`, `grep_search`). `ask_user_question` is deliberately not auto-approved, so its question dialog is shown before the skill drafts from your answers. Like other bundled skills, a project or personal skill named `goal-draft` overrides it, and `skills.disabled` can turn it off. See [Skills](./skills.md) for how bundled skills are discovered. + +## Telemetry + +When [telemetry](../../developers/development/telemetry.md) is enabled, each Goal state change — set, replace, edit, pause, resume, clear, verifier rejection, and every stop — is recorded as a `qwen-code.goal_state` event with the Goal's turn count, token spend, budgets, and active time. The objective text and stop reasons are never recorded. A resumed session does not record its recovered Goal again. diff --git a/packages/core/src/config/config.test.ts b/packages/core/src/config/config.test.ts index 1e100753e9a..45a57e6dd2f 100644 --- a/packages/core/src/config/config.test.ts +++ b/packages/core/src/config/config.test.ts @@ -90,7 +90,7 @@ import { resetDebugLoggingState, setDebugLogSession, } from '../utils/debugLogger.js'; -import { logRipgrepFallback } from '../telemetry/loggers.js'; +import { logGoalState, logRipgrepFallback } from '../telemetry/loggers.js'; import { RipgrepFallbackEvent } from '../telemetry/types.js'; import { ToolRegistry } from '../tools/tool-registry.js'; import { ToolNames } from '../tools/tool-names.js'; @@ -393,6 +393,7 @@ vi.mock('../telemetry/loggers.js', async (importOriginal) => { return { ...actual, logRipgrepFallback: vi.fn(), + logGoalState: vi.fn(), logStartSession: vi.fn(actual.logStartSession), logSessionEnd: vi.fn(actual.logSessionEnd), }; @@ -3977,6 +3978,49 @@ describe('Server Config (config.ts)', () => { expect(replacement.getSnapshot().goal?.status).toBe('active'); }); + it('reports a committed Goal transition to telemetry', async () => { + vi.mocked(logGoalState).mockClear(); + const config = new Config({ ...baseParams, chatRecording: true }); + const runtime = config.getGoalRuntime(); + + await runtime.dispatch({ action: 'create', objective: 'ship' }); + + expect(logGoalState).toHaveBeenCalledTimes(1); + expect(logGoalState).toHaveBeenCalledWith( + config, + expect.objectContaining({ + cause: 'create', + status: 'active', + revision: 1, + }), + ); + }); + + it("does not report a resumed session's recovered Goal again", async () => { + // The restore broadcast names the recovered record's cause. Reporting it + // would count this paused Goal as paused a second time. + vi.mocked(logGoalState).mockClear(); + const config = new Config({ + ...baseParams, + chatRecording: true, + sessionData: resumedGoalSession('paused'), + }); + + const runtime = await config.getGoalRuntimeReady(); + expect(logGoalState).not.toHaveBeenCalled(); + + await runtime.dispatch({ + action: 'resume', + expectedGoalId: 'g-resumed', + expectedRevision: 1, + }); + expect(logGoalState).toHaveBeenCalledTimes(1); + expect(logGoalState).toHaveBeenCalledWith( + config, + expect.objectContaining({ cause: 'resume', goal_id: 'g-resumed' }), + ); + }); + it('holds selective Goal readiness and autonomous work until finalization', async () => { const record = resumedGoalSession('active').conversation.messages[0]!; const config = new Config({ diff --git a/packages/core/src/config/config.ts b/packages/core/src/config/config.ts index d41f53c1ae6..3e06af1c61e 100644 --- a/packages/core/src/config/config.ts +++ b/packages/core/src/config/config.ts @@ -160,6 +160,8 @@ import { logStartSession, logSessionEnd, logRipgrepFallback, + logGoalState, + goalStateEventFromSnapshot, RipgrepFallbackEvent, StartSessionEvent, type TelemetryTarget, @@ -9693,6 +9695,16 @@ export class Config { turnBudgetGrant: this.goalTurnBudgetGrant, activeTimeBudgetGrantMs: this.goalActiveTimeBudgetGrantMs, }); + // Every committed transition reaches telemetry from here, the one place + // that holds both the runtime and the Config its loggers need. Subscribed + // before the restore below starts, so the broadcast that republishes a + // resumed session's Goal is seen and skipped rather than missed and then + // mistaken for the next live transition. + runtime.subscribe((snapshot, cause, meta) => { + if (meta?.replayed) return; + const event = goalStateEventFromSnapshot(snapshot, cause); + if (event) logGoalState(this, event); + }); this.goalRuntime = runtime; if (this.goalTurnHost) { this.goalTurnHostUnbind = runtime.bindHost(this.goalTurnHost); diff --git a/packages/core/src/goals/goal-protocol.ts b/packages/core/src/goals/goal-protocol.ts index 7dfb86dcf2e..805c8fd190a 100644 --- a/packages/core/src/goals/goal-protocol.ts +++ b/packages/core/src/goals/goal-protocol.ts @@ -726,6 +726,19 @@ export type GoalStateCause = | 'clear' | 'migrated'; +/** + * What a runtime broadcast carries beyond the snapshot and its cause. + * + * `restore()` republishes recovered state with the cause of the record it was + * recovered from, so a subscriber that counts transitions cannot otherwise + * tell that broadcast from the live one that first produced it, and would + * count the same `create` or `usage_limited` again on every resume. + */ +export interface GoalBroadcastMeta { + /** True only on the broadcast that republishes restored state. */ + replayed: boolean; +} + export interface GoalStateRecordPayloadV2 { v: typeof GOAL_STATE_VERSION; cause: GoalStateCause; diff --git a/packages/core/src/goals/goal-runtime.test.ts b/packages/core/src/goals/goal-runtime.test.ts index a7455fa8824..b2ace8502d1 100644 --- a/packages/core/src/goals/goal-runtime.test.ts +++ b/packages/core/src/goals/goal-runtime.test.ts @@ -29,6 +29,7 @@ import { goalActiveTimeBudgetReason, goalCheckpointHealthVisible, goalTurnBudgetReason, + type GoalBroadcastMeta, type GoalSnapshotV2, type GoalStateCause, type GoalStateRecordPayloadV2, @@ -4514,6 +4515,50 @@ describe('goal runtime', () => { expect(observed).toEqual(['pause']); }); + it('marks only the restore broadcast as a replay', async () => { + // The restore broadcast carries the persisted record's cause. A subscriber + // counting transitions would otherwise count the recovered `pause` again + // on every resume, as if the user had just paused. + const runtime = createGoalRuntime({ journal: fakeGoalJournal() }); + runtime.bindHost(fakeGoalTurnHost()); + const observed: Array<{ + cause: GoalStateCause | undefined; + meta: GoalBroadcastMeta | undefined; + }> = []; + runtime.subscribe((_snapshot, cause, meta) => + observed.push({ cause, meta }), + ); + + await runtime.restore([ + goalStateRecord({ + v: 2, + activity: 'idle', + goal: { + goalId: 'g-1', + revision: 1, + objective: 'ship it', + status: 'paused', + evidenceCursor: { recordId: 'create-record' }, + turnCount: 2, + activeTimeMs: 10, + tokensUsed: 0, + createdAt: 1, + updatedAt: 2, + }, + }), + ]); + await runtime.dispatch({ + action: 'resume', + expectedGoalId: 'g-1', + expectedRevision: 1, + }); + + expect(observed[0]).toEqual({ cause: 'pause', meta: { replayed: true } }); + const live = observed.slice(1); + expect(live.map(({ cause }) => cause)).toContain('resume'); + expect(live.every(({ meta }) => meta === undefined)).toBe(true); + }); + it('resumes an idle stopped goal exactly once', async () => { const journal = fakeGoalJournal(); const host = fakeGoalTurnHost(); diff --git a/packages/core/src/goals/goal-runtime.ts b/packages/core/src/goals/goal-runtime.ts index bcd5ad78462..aa88edc8137 100644 --- a/packages/core/src/goals/goal-runtime.ts +++ b/packages/core/src/goals/goal-runtime.ts @@ -48,6 +48,7 @@ import { isGoalTokenBudgetSpent, isGoalTurnBudgetSpent, isRepeatedBlockerProposal, + type GoalBroadcastMeta, type GoalCheckpointFailureShape, type GoalControlRequest, type GoalEvidenceCheckpoint, @@ -247,8 +248,16 @@ export interface GoalRuntime { * cause the broadcast carried. */ getRecoveryCause?(): GoalStateCause | undefined; + /** + * `meta.replayed` is set on the one broadcast `restore()` makes to + * republish recovered state; every other broadcast passes no `meta`. + */ subscribe( - listener: (snapshot: GoalSnapshotV2, cause?: GoalStateCause) => void, + listener: ( + snapshot: GoalSnapshotV2, + cause?: GoalStateCause, + meta?: GoalBroadcastMeta, + ) => void, ): () => void; restore(records: readonly GoalRecoveryRecord[]): Promise; prepareRestore( @@ -319,7 +328,11 @@ export function createGoalRuntime( activity: 'idle', }; const listeners = new Set< - (value: GoalSnapshotV2, cause?: GoalStateCause) => void + ( + value: GoalSnapshotV2, + cause?: GoalStateCause, + meta?: GoalBroadcastMeta, + ) => void >(); let dispatchTail = Promise.resolve(); let host: GoalTurnHost | undefined; @@ -661,10 +674,10 @@ export function createGoalRuntime( const getSnapshot = (): GoalSnapshotV2 => structuredClone(snapshot); - const broadcast = (cause?: GoalStateCause) => { + const broadcast = (cause?: GoalStateCause, meta?: GoalBroadcastMeta) => { for (const listener of listeners) { try { - listener(getSnapshot(), cause); + listener(getSnapshot(), cause, meta); } catch { // Subscribers cannot roll back a committed runtime transition. } @@ -1556,7 +1569,11 @@ export function createGoalRuntime( return recoveryCause; }, subscribe( - listener: (value: GoalSnapshotV2, cause?: GoalStateCause) => void, + listener: ( + value: GoalSnapshotV2, + cause?: GoalStateCause, + meta?: GoalBroadcastMeta, + ) => void, ): () => void { listeners.add(listener); return () => listeners.delete(listener); @@ -1691,7 +1708,11 @@ export function createGoalRuntime( restoreActivation = restorePreparation.then(async (attempt) => { assertAvailable(); restoreActivationPending = false; - if (preparedRestoreHasSnapshot) broadcast(preparedRestoreCause); + // The cause is the recovered record's: the transition it names was + // published by the session that made it, so mark this one a replay. + if (preparedRestoreHasSnapshot) { + broadcast(preparedRestoreCause, { replayed: true }); + } if (!attempt) { await enqueue(async () => { assertAvailable(); diff --git a/packages/core/src/telemetry/constants.ts b/packages/core/src/telemetry/constants.ts index f8bad02eb8f..60156a58b81 100644 --- a/packages/core/src/telemetry/constants.ts +++ b/packages/core/src/telemetry/constants.ts @@ -48,6 +48,7 @@ export const EVENT_MALFORMED_JSON_RESPONSE = export const EVENT_FILE_OPERATION = 'qwen-code.file_operation'; export const EVENT_MODEL_SLASH_COMMAND = 'qwen-code.slash_command.model'; export const EVENT_SUBAGENT_EXECUTION = 'qwen-code.subagent_execution'; +export const EVENT_GOAL_STATE = 'qwen-code.goal_state'; export const EVENT_SKILL_LAUNCH = 'qwen-code.skill_launch'; export const EVENT_AUTH = 'qwen-code.auth'; export const EVENT_USER_FEEDBACK = 'qwen-code.user_feedback'; diff --git a/packages/core/src/telemetry/goal-events.test.ts b/packages/core/src/telemetry/goal-events.test.ts new file mode 100644 index 00000000000..3ab6d27b382 --- /dev/null +++ b/packages/core/src/telemetry/goal-events.test.ts @@ -0,0 +1,167 @@ +/** + * @license + * Copyright 2026 Qwen Team + * SPDX-License-Identifier: Apache-2.0 + */ + +import { describe, expect, it } from 'vitest'; +import type { + GoalRecord, + GoalSnapshotV2, + GoalStateCause, +} from '../goals/goal-protocol.js'; +import { + goalStateEventFromSnapshot, + isGoalStateEventCause, +} from './goal-events.js'; +import { GOAL_STATE_EVENT_CAUSES } from './types.js'; + +const NOW = 1_000_000; + +function goal(overrides: Partial = {}): GoalRecord { + return { + goalId: 'g-1', + revision: 3, + objective: 'ship the release notes', + status: 'paused', + evidenceCursor: { recordId: 'r-1' }, + turnCount: 4, + activeTimeMs: 12_000, + tokensUsed: 81_234, + createdAt: NOW - 60_000, + updatedAt: NOW - 5_000, + ...overrides, + }; +} + +function snapshot( + value: GoalRecord | null, + extra: Partial = {}, +): GoalSnapshotV2 { + return { v: 2, activity: 'idle', goal: value, ...extra }; +} + +describe('goalStateEventFromSnapshot', () => { + it.each(GOAL_STATE_EVENT_CAUSES.filter((cause) => cause !== 'clear'))( + 'reports %s', + (cause) => { + expect( + goalStateEventFromSnapshot(snapshot(goal()), cause, NOW), + ).toMatchObject({ + 'event.name': 'goal_state', + cause, + goal_id: 'g-1', + revision: 3, + }); + }, + ); + + it.each([ + 'turn_finished', + 'checkpoint', + 'migrated', + 'verifier_accept', + undefined, + ])('does not report %s', (cause) => { + // Per-turn causes would multiply the volume; an accept is always followed + // by the stop it accepted; a missing cause is an activity change. + expect(isGoalStateEventCause(cause)).toBe(false); + expect( + goalStateEventFromSnapshot(snapshot(goal()), cause, NOW), + ).toBeUndefined(); + }); + + it('carries the figures and none of the free text', () => { + const event = goalStateEventFromSnapshot( + snapshot( + goal({ + status: 'usage_limited', + limitKind: 'token_budget', + tokenBudget: 80_000, + lastReason: + 'The Goal spent its autonomous token budget (80,000 tokens).', + }), + ), + 'usage_limited', + NOW, + ); + + expect(event).toEqual({ + 'event.name': 'goal_state', + 'event.timestamp': expect.any(String), + cause: 'usage_limited', + goal_id: 'g-1', + revision: 3, + status: 'usage_limited', + limit_kind: 'token_budget', + turn_count: 4, + tokens_used: 81_234, + token_budget: 80_000, + active_time_ms: 12_000, + objective_length: 22, + }); + // The objective and the stop reason are text a user or a model wrote. + const serialized = JSON.stringify(event); + expect(serialized).not.toContain('release notes'); + expect(serialized).not.toContain('autonomous token budget'); + }); + + it('leaves figures the Goal does not have absent rather than undefined', () => { + const event = goalStateEventFromSnapshot(snapshot(goal()), 'pause', NOW)!; + + for (const key of [ + 'limit_kind', + 'token_budget', + 'turn_budget', + 'active_time_budget_ms', + ]) { + expect(Object.keys(event)).not.toContain(key); + } + }); + + it("reads an active Goal's running clock as of the broadcast", () => { + // `activeTimeMs` is only committed on a transition; an active Goal has + // been accruing since `updatedAt`. + const event = goalStateEventFromSnapshot( + snapshot(goal({ status: 'active' })), + 'resume', + NOW, + ); + + expect(event?.active_time_ms).toBe(17_000); + }); + + it('counts the objective in code points', () => { + const event = goalStateEventFromSnapshot( + snapshot(goal({ objective: '发布说明🚀' })), + 'create', + NOW, + ); + + expect(event?.objective_length).toBe(5); + }); + + it('names the cleared Goal and carries no figures on clear', () => { + const event = goalStateEventFromSnapshot( + snapshot(null, { + clearedGoal: { goalId: 'g-1', revision: 3, updatedAt: NOW }, + }), + 'clear', + NOW, + ); + + expect(event).toEqual({ + 'event.name': 'goal_state', + 'event.timestamp': expect.any(String), + cause: 'clear', + goal_id: 'g-1', + revision: 3, + }); + }); + + it('reports nothing for a clear with no Goal to name', () => { + expect( + goalStateEventFromSnapshot(snapshot(null), 'clear', NOW), + ).toBeUndefined(); + }); +}); diff --git a/packages/core/src/telemetry/goal-events.ts b/packages/core/src/telemetry/goal-events.ts new file mode 100644 index 00000000000..2c5a61b09c7 --- /dev/null +++ b/packages/core/src/telemetry/goal-events.ts @@ -0,0 +1,65 @@ +/** + * @license + * Copyright 2026 Qwen Team + * SPDX-License-Identifier: Apache-2.0 + */ + +import type { GoalSnapshotV2, GoalStateCause } from '../goals/goal-protocol.js'; +import { elapsedActiveTime } from '../goals/goal-reducer.js'; +import { + GOAL_STATE_EVENT_CAUSES, + makeGoalStateEvent, + type GoalStateEvent, + type GoalStateEventCause, +} from './types.js'; + +const REPORTED_CAUSES: ReadonlySet = new Set( + GOAL_STATE_EVENT_CAUSES, +); + +export function isGoalStateEventCause( + cause: GoalStateCause | undefined, +): cause is GoalStateEventCause { + return cause !== undefined && REPORTED_CAUSES.has(cause); +} + +/** + * The telemetry event for one Goal runtime broadcast, or undefined when the + * broadcast is not a transition worth reporting. + * + * Reads the snapshot the broadcast carried. A `clear` leaves `goal` null and + * names the Goal it removed in `clearedGoal`. An active Goal's committed + * `activeTimeMs` lags the clock, so the figure is read as of `now`. + */ +export function goalStateEventFromSnapshot( + snapshot: GoalSnapshotV2, + cause: GoalStateCause | undefined, + now: number = Date.now(), +): GoalStateEvent | undefined { + if (!isGoalStateEventCause(cause)) return undefined; + const goal = snapshot.goal; + if (!goal) { + const cleared = snapshot.clearedGoal; + return cause === 'clear' && cleared + ? makeGoalStateEvent({ + cause, + goal_id: cleared.goalId, + revision: cleared.revision, + }) + : undefined; + } + return makeGoalStateEvent({ + cause, + goal_id: goal.goalId, + revision: goal.revision, + status: goal.status, + limit_kind: goal.limitKind, + turn_count: goal.turnCount, + tokens_used: goal.tokensUsed, + token_budget: goal.tokenBudget, + turn_budget: goal.turnBudget, + active_time_ms: elapsedActiveTime(goal, now), + active_time_budget_ms: goal.activeTimeBudgetMs, + objective_length: [...goal.objective].length, + }); +} diff --git a/packages/core/src/telemetry/index.ts b/packages/core/src/telemetry/index.ts index 431eb847d1d..51a89758e89 100644 --- a/packages/core/src/telemetry/index.ts +++ b/packages/core/src/telemetry/index.ts @@ -42,6 +42,7 @@ export { logApiCancel, logApiResponse, logFlashFallback, + logGoalState, logSlashCommand, logConversationFinishedEvent, logKittySequenceOverflow, @@ -67,7 +68,12 @@ export { logMemoryRecall, logMemoryRecallDelivery, } from './loggers.js'; -export type { SlashCommandEvent, ChatCompressionEvent } from './types.js'; +export type { + SlashCommandEvent, + ChatCompressionEvent, + GoalStateEvent, + GoalStateEventCause, +} from './types.js'; export { SlashCommandStatus, EndSessionEvent, @@ -99,7 +105,16 @@ export { MemoryRecallDeliveryEvent, RepeatedToolFailureGuardEvent, } from './types.js'; -export { makeSlashCommandEvent, makeChatCompressionEvent } from './types.js'; +export { + makeSlashCommandEvent, + makeChatCompressionEvent, + makeGoalStateEvent, + GOAL_STATE_EVENT_CAUSES, +} from './types.js'; +export { + goalStateEventFromSnapshot, + isGoalStateEventCause, +} from './goal-events.js'; export type { ArenaSessionStartedEvent, ArenaAgentCompletedEvent, @@ -141,6 +156,7 @@ export { recordArenaSessionStartedMetrics, recordArenaAgentCompletedMetrics, recordArenaSessionEndedMetrics, + recordGoalStateMetrics, // Auto-Memory metrics functions recordMemoryExtractMetrics, recordMemoryDreamMetrics, diff --git a/packages/core/src/telemetry/loggers.test.ts b/packages/core/src/telemetry/loggers.test.ts index 5102eccbbf1..a4ad86983d9 100644 --- a/packages/core/src/telemetry/loggers.test.ts +++ b/packages/core/src/telemetry/loggers.test.ts @@ -28,6 +28,7 @@ import { EVENT_API_RESPONSE, EVENT_CLI_CONFIG, EVENT_FLASH_FALLBACK, + EVENT_GOAL_STATE, EVENT_TOOL_CALL, EVENT_REPEATED_TOOL_FAILURE_GUARD, EVENT_USER_PROMPT, @@ -57,6 +58,7 @@ import { logLoopDetected, logRepeatedToolFailureGuard, logFlashFallback, + logGoalState, logChatCompression, logMalformedJsonResponse, logFileOperation, @@ -86,6 +88,7 @@ import { ApiRequestEvent, ApiResponseEvent, FlashFallbackEvent, + makeGoalStateEvent, StartSessionEvent, ToolCallEvent, UserPromptEvent, @@ -1138,6 +1141,72 @@ describe('loggers', () => { }); }); + describe('logGoalState', () => { + const mockConfig = { + getSessionId: () => 'test-session-id', + getUsageStatisticsEnabled: () => true, + getTelemetryMetricsIncludeSessionId: () => false, + } as unknown as Config; + + beforeEach(() => { + vi.spyOn(QwenLogger.prototype, 'logGoalStateEvent'); + vi.spyOn(metrics, 'recordGoalStateMetrics'); + }); + + it('emits the transition with its figures and records its metrics', () => { + const event = makeGoalStateEvent({ + cause: 'usage_limited', + goal_id: 'g-1', + revision: 2, + status: 'usage_limited', + limit_kind: 'turn_budget', + turn_count: 20, + tokens_used: 1_234, + }); + + logGoalState(mockConfig, event); + + expect(mockLogger.emit).toHaveBeenCalledWith({ + body: 'Goal usage_limited.', + attributes: { + 'session.id': 'test-session-id', + 'event.name': EVENT_GOAL_STATE, + 'event.timestamp': '2025-01-01T00:00:00.000Z', + cause: 'usage_limited', + goal_id: 'g-1', + revision: 2, + status: 'usage_limited', + limit_kind: 'turn_budget', + turn_count: 20, + tokens_used: 1_234, + }, + }); + expect(QwenLogger.prototype.logGoalStateEvent).toHaveBeenCalledWith( + event, + ); + expect(metrics.recordGoalStateMetrics).toHaveBeenCalledWith( + mockConfig, + event, + ); + }); + + it('still reaches the analytics sink when the OpenTelemetry SDK is off', () => { + vi.spyOn(sdk, 'isTelemetrySdkInitialized').mockReturnValue(false); + const event = makeGoalStateEvent({ + cause: 'create', + goal_id: 'g-1', + revision: 1, + }); + + logGoalState(mockConfig, event); + + expect(QwenLogger.prototype.logGoalStateEvent).toHaveBeenCalledWith( + event, + ); + expect(mockLogger.emit).not.toHaveBeenCalled(); + }); + }); + describe('logRipgrepFallback', () => { const mockConfig = { getSessionId: () => 'test-session-id', diff --git a/packages/core/src/telemetry/loggers.ts b/packages/core/src/telemetry/loggers.ts index 2897db215ba..a24d57c4ea3 100644 --- a/packages/core/src/telemetry/loggers.ts +++ b/packages/core/src/telemetry/loggers.ts @@ -40,6 +40,7 @@ import { EVENT_MODEL_SLASH_COMMAND, EVENT_EXTENSION_DISABLE, EVENT_SUBAGENT_EXECUTION, + EVENT_GOAL_STATE, EVENT_MALFORMED_JSON_RESPONSE, EVENT_INVALID_CHUNK, EVENT_AUTH, @@ -70,6 +71,7 @@ import { recordInvalidChunk, recordModelSlashCommand, recordSubagentExecutionMetrics, + recordGoalStateMetrics, recordTokenUsageMetrics, recordToolCallMetrics, recordToolExecutionMetrics, @@ -118,6 +120,7 @@ import type { ExtensionInstallEvent, ModelSlashCommandEvent, SubagentExecutionEvent, + GoalStateEvent, MalformedJsonResponseEvent, InvalidChunkEvent, AuthEvent, @@ -1045,6 +1048,26 @@ export function logSubagentExecution( ); } +export function logGoalState(config: Config, event: GoalStateEvent): void { + QwenLogger.getInstance(config)?.logGoalStateEvent(event); + if (!isTelemetrySdkInitialized()) return; + + const attributes: LogAttributes = { + ...getCommonAttributes(config), + ...event, + 'event.name': EVENT_GOAL_STATE, + 'event.timestamp': new Date().toISOString(), + }; + + const logger = logs.getLogger(SERVICE_NAME); + const logRecord: LogRecord = { + body: `Goal ${event.cause}.`, + attributes, + }; + logger.emit(logRecord); + recordGoalStateMetrics(config, event); +} + export function logModelSlashCommand( config: Config, event: ModelSlashCommandEvent, diff --git a/packages/core/src/telemetry/metrics.test.ts b/packages/core/src/telemetry/metrics.test.ts index 890213f45d1..420c83985a8 100644 --- a/packages/core/src/telemetry/metrics.test.ts +++ b/packages/core/src/telemetry/metrics.test.ts @@ -20,6 +20,7 @@ import { ApiRequestPhase, } from './metrics.js'; import { makeFakeConfig } from '../test-utils/config.js'; +import type { GoalStateEvent } from './types.js'; const mockCounterAddFn: Mock< (value: number, attributes?: Attributes, context?: Context) => void @@ -85,6 +86,7 @@ describe('Telemetry Metrics', () => { let recordBaselineComparisonModule: typeof import('./metrics.js').recordBaselineComparison; let recordChannelMemoryRecallMetricsModule: typeof import('./metrics.js').recordChannelMemoryRecallMetrics; let recordMemoryRecallDeliveryMetricsModule: typeof import('./metrics.js').recordMemoryRecallDeliveryMetrics; + let recordGoalStateMetricsModule: typeof import('./metrics.js').recordGoalStateMetrics; beforeEach(async () => { vi.resetModules(); @@ -121,6 +123,7 @@ describe('Telemetry Metrics', () => { metricsJsModule.recordChannelMemoryRecallMetrics; recordMemoryRecallDeliveryMetricsModule = metricsJsModule.recordMemoryRecallDeliveryMetrics; + recordGoalStateMetricsModule = metricsJsModule.recordGoalStateMetrics; const otelApiModule = await import('@opentelemetry/api'); @@ -207,6 +210,100 @@ describe('Telemetry Metrics', () => { }); }); + describe('recordGoalStateMetrics', () => { + const goalEvent = (fields: Partial): GoalStateEvent => ({ + 'event.name': 'goal_state', + 'event.timestamp': '2025-01-01T00:00:00.000Z', + cause: 'create', + goal_id: 'g-1', + revision: 1, + ...fields, + }); + + it('records nothing before metrics are initialized', () => { + recordGoalStateMetricsModule( + makeFakeConfig({}), + goalEvent({ cause: 'complete', tokens_used: 10, turn_count: 1 }), + ); + + expect(mockCounterAddFn).not.toHaveBeenCalled(); + expect(mockHistogramRecordFn).not.toHaveBeenCalled(); + }); + + it('registers the Goal counter and histograms', () => { + initializeMetricsModule(makeFakeConfig({})); + + expect(mockCreateCounterFn).toHaveBeenCalledWith( + 'qwen-code.goal.transition.count', + expect.anything(), + ); + expect(mockCreateHistogramFn).toHaveBeenCalledWith( + 'qwen-code.goal.tokens_used', + expect.objectContaining({ unit: '{token}' }), + ); + expect(mockCreateHistogramFn).toHaveBeenCalledWith( + 'qwen-code.goal.turn_count', + expect.objectContaining({ unit: '{turn}' }), + ); + }); + + it('counts a transition by its bounded attributes only', () => { + // The Goal id and revision are per-Goal values; on a metric they would + // open a new time series for every Goal. + const config = makeFakeConfig({ sessionId: 'test-session-id' }); + initializeMetricsModule(config); + mockCounterAddFn.mockClear(); + + recordGoalStateMetricsModule( + config, + goalEvent({ + cause: 'pause', + status: 'paused', + turn_count: 3, + tokens_used: 500, + }), + ); + + expect(mockCounterAddFn).toHaveBeenCalledWith(1, { + cause: 'pause', + status: 'paused', + }); + // A pause is not an outcome, so nothing is recorded as spend. + expect(mockHistogramRecordFn).not.toHaveBeenCalled(); + }); + + it('records spend and turns on an outcome', () => { + const config = makeFakeConfig({ sessionId: 'test-session-id' }); + initializeMetricsModule(config); + mockCounterAddFn.mockClear(); + + recordGoalStateMetricsModule( + config, + goalEvent({ + cause: 'usage_limited', + status: 'usage_limited', + limit_kind: 'time_budget', + turn_count: 12, + tokens_used: 45_000, + }), + ); + + expect(mockCounterAddFn).toHaveBeenCalledWith(1, { + cause: 'usage_limited', + status: 'usage_limited', + limit_kind: 'time_budget', + }); + expect(mockHistogramRecordFn).toHaveBeenCalledWith(45_000, { + cause: 'usage_limited', + limit_kind: 'time_budget', + }); + expect(mockHistogramRecordFn).toHaveBeenCalledWith(12, { + cause: 'usage_limited', + limit_kind: 'time_budget', + }); + }); + }); + describe('recordTokenUsageMetrics', () => { const mockConfig = { getSessionId: () => 'test-session-id', diff --git a/packages/core/src/telemetry/metrics.ts b/packages/core/src/telemetry/metrics.ts index b413714bc57..7646a648d3d 100644 --- a/packages/core/src/telemetry/metrics.ts +++ b/packages/core/src/telemetry/metrics.ts @@ -9,7 +9,10 @@ import { diag, metrics, ValueType } from '@opentelemetry/api'; import { SERVICE_NAME, EVENT_CHAT_COMPRESSION } from './constants.js'; import type { Config } from '../config/config.js'; import type { TelemetryRuntimeConfig } from './runtime-config.js'; +import type { GoalLimitKind, GoalStatus } from '../goals/goal-protocol.js'; import type { + GoalStateEvent, + GoalStateEventCause, ModelSlashCommandEvent, MemoryRecallDeliveryPhase, MemoryRecallDeliveryPoint, @@ -35,6 +38,19 @@ const API_RETRY_COUNT = `${SERVICE_NAME}.api.retry.count`; const MODEL_SLASH_COMMAND_CALL_COUNT = `${SERVICE_NAME}.slash_command.model.call_count`; export const SUBAGENT_EXECUTION_COUNT = `${SERVICE_NAME}.subagent.execution.count`; +// Goal Metrics +const GOAL_TRANSITION_COUNT = `${SERVICE_NAME}.goal.transition.count`; +const GOAL_TOKENS_USED = `${SERVICE_NAME}.goal.tokens_used`; +const GOAL_TURN_COUNT = `${SERVICE_NAME}.goal.turn_count`; + +/** The Goal stops a user reads as the end of a run. */ +type GoalOutcomeCause = Extract< + GoalStateEventCause, + 'complete' | 'blocked' | 'usage_limited' +>; +const GOAL_OUTCOME_CAUSES: ReadonlySet = + new Set(['complete', 'blocked', 'usage_limited']); + // Arena Metrics const ARENA_SESSION_COUNT = `${SERVICE_NAME}.arena.session.count`; const ARENA_SESSION_DURATION = `${SERVICE_NAME}.arena.session.duration`; @@ -225,6 +241,17 @@ const COUNTER_DEFINITIONS = { tokens_after: number; }, }, + [GOAL_TRANSITION_COUNT]: { + description: + 'Counts Goal state transitions, tagged by cause, resulting status, and limit kind.', + valueType: ValueType.INT, + assign: (c: Counter) => (goalTransitionCounter = c), + attributes: {} as { + cause: GoalStateEventCause; + status?: GoalStatus; + limit_kind?: GoalLimitKind; + }, + }, } as const; const HISTOGRAM_DEFINITIONS = { @@ -246,6 +273,28 @@ const HISTOGRAM_DEFINITIONS = { model: string; }, }, + [GOAL_TOKENS_USED]: { + description: + 'Tokens a Goal had spent when it completed, was blocked, or reached a usage limit.', + unit: '{token}', + valueType: ValueType.INT, + assign: (h: Histogram) => (goalTokensUsedHistogram = h), + attributes: {} as { + cause: GoalOutcomeCause; + limit_kind?: GoalLimitKind; + }, + }, + [GOAL_TURN_COUNT]: { + description: + 'Turns a Goal had finished when it completed, was blocked, or reached a usage limit.', + unit: '{turn}', + valueType: ValueType.INT, + assign: (h: Histogram) => (goalTurnCountHistogram = h), + attributes: {} as { + cause: GoalOutcomeCause; + limit_kind?: GoalLimitKind; + }, + }, } as const; const PERFORMANCE_COUNTER_DEFINITIONS = { @@ -433,6 +482,9 @@ let contentRetryCounter: Counter | undefined; let contentRetryFailureCounter: Counter | undefined; let apiRetryCounter: Counter | undefined; let subagentExecutionCounter: Counter | undefined; +let goalTransitionCounter: Counter | undefined; +let goalTokensUsedHistogram: Histogram | undefined; +let goalTurnCountHistogram: Histogram | undefined; let modelSlashCommandCallCounter: Counter | undefined; // Performance Monitoring Metrics @@ -621,6 +673,37 @@ export function initializeMetrics(config: TelemetryRuntimeConfig): void { isMetricsInitialized = true; } +/** + * Counts a Goal transition and, on the three outcomes a user reads as the end + * of a run, records what the Goal had spent getting there. + * + * The Goal id and revision stay on the log record: every Goal is a new value, + * the same unbounded time-series fan-out the opt-in `session.id` guards + * against. + */ +export function recordGoalStateMetrics( + config: Config, + event: GoalStateEvent, +): void { + if (!goalTransitionCounter || !isMetricsInitialized) return; + const common = baseMetricDefinition.getCommonAttributes(config); + const limitKind = event.limit_kind ? { limit_kind: event.limit_kind } : {}; + goalTransitionCounter.add(1, { + ...common, + cause: event.cause, + ...(event.status ? { status: event.status } : {}), + ...limitKind, + }); + if (!GOAL_OUTCOME_CAUSES.has(event.cause)) return; + const outcome = { ...common, cause: event.cause, ...limitKind }; + if (event.tokens_used !== undefined) { + goalTokensUsedHistogram?.record(event.tokens_used, outcome); + } + if (event.turn_count !== undefined) { + goalTurnCountHistogram?.record(event.turn_count, outcome); + } +} + export function recordChatCompressionMetrics( config: Config, attributes: MetricDefinitions[typeof EVENT_CHAT_COMPRESSION]['attributes'], diff --git a/packages/core/src/telemetry/qwen-logger/qwen-logger.test.ts b/packages/core/src/telemetry/qwen-logger/qwen-logger.test.ts index a471a011b3c..3563fac25c9 100644 --- a/packages/core/src/telemetry/qwen-logger/qwen-logger.test.ts +++ b/packages/core/src/telemetry/qwen-logger/qwen-logger.test.ts @@ -28,6 +28,7 @@ import { ProtocolTagSanitizedEvent, RipgrepRuntimeRecoveryEvent, SubagentExecutionEvent, + makeGoalStateEvent, type ToolCallEvent, } from '../types.js'; import type { RumEvent, RumPayload } from './event-types.js'; @@ -456,6 +457,40 @@ describe('QwenLogger', () => { ); }); + it('journals a Goal transition without its Goal id or absent figures', () => { + const logger = QwenLogger.getInstance(mockConfig)!; + const enqueueSpy = vi.spyOn(logger, 'enqueueLogEvent'); + + logger.logGoalStateEvent( + makeGoalStateEvent({ + cause: 'blocked', + goal_id: 'g-1', + revision: 4, + status: 'blocked', + turn_count: 7, + tokens_used: 9_000, + }), + ); + + const rumEvent = enqueueSpy.mock.calls[0]![0]; + expect(rumEvent).toMatchObject({ + event_type: 'action', + type: 'goal', + name: 'goal_state', + properties: { + cause: 'blocked', + revision: 4, + status: 'blocked', + turn_count: 7, + tokens_used: 9_000, + }, + }); + const keys = Object.keys(rumEvent.properties ?? {}); + expect(keys).not.toContain('goal_id'); + expect(keys).not.toContain('limit_kind'); + expect(keys).not.toContain('token_budget'); + }); + it('logs protocol tag sanitization without model content', () => { const logger = QwenLogger.getInstance(mockConfig)!; const enqueueSpy = vi.spyOn(logger, 'enqueueLogEvent'); diff --git a/packages/core/src/telemetry/qwen-logger/qwen-logger.ts b/packages/core/src/telemetry/qwen-logger/qwen-logger.ts index 1fd4a6d2359..87fa91ae650 100644 --- a/packages/core/src/telemetry/qwen-logger/qwen-logger.ts +++ b/packages/core/src/telemetry/qwen-logger/qwen-logger.ts @@ -36,6 +36,7 @@ import type { ContentRetryFailureEvent, ConversationFinishedEvent, SubagentExecutionEvent, + GoalStateEvent, ExtensionInstallEvent, ExtensionUninstallEvent, ToolOutputTruncatedEvent, @@ -619,6 +620,34 @@ export class QwenLogger { this.flushIfNeeded(); } + logGoalStateEvent(event: GoalStateEvent): void { + // The Goal id is left out: this sink aggregates by installation, where a + // per-Goal identifier only adds a unique value to every row. + const properties: Record = { + cause: event.cause, + revision: event.revision, + }; + for (const key of [ + 'status', + 'limit_kind', + 'turn_count', + 'tokens_used', + 'token_budget', + 'turn_budget', + 'active_time_ms', + 'active_time_budget_ms', + 'objective_length', + ] as const) { + if (event[key] !== undefined) properties[key] = event[key]; + } + const rumEvent = this.createActionEvent('goal', 'goal_state', { + properties, + }); + + this.enqueueLogEvent(rumEvent); + this.flushIfNeeded(); + } + logToolOutputTruncatedEvent(event: ToolOutputTruncatedEvent): void { const rumEvent = this.createActionEvent('tool', 'tool_output_truncated', { properties: { diff --git a/packages/core/src/telemetry/types.ts b/packages/core/src/telemetry/types.ts index 4fdb421d5a9..0d0d7d5a93b 100644 --- a/packages/core/src/telemetry/types.ts +++ b/packages/core/src/telemetry/types.ts @@ -25,6 +25,11 @@ import { STRUCTURED_OUTPUT_REDACTED_ARGS } from '../tools/syntheticOutput.js'; import type { SkillTool } from '../tools/skill.js'; import type { AgentTool } from '../tools/agent/agent.js'; import type { ToolErrorType } from '../tools/tool-error.js'; +import type { + GoalLimitKind, + GoalStateCause, + GoalStatus, +} from '../goals/goal-protocol.js'; export interface BaseTelemetryEvent { 'event.name': string; @@ -1104,6 +1109,68 @@ export class SubagentExecutionEvent implements BaseTelemetryEvent { } } +/** + * The Goal state causes a {@link GoalStateEvent} reports: the user's controls + * and the stops a user acts on. Per-turn `turn_finished` and `checkpoint`, the + * one-off `migrated`, and `verifier_accept` (always followed by the `complete` + * or `blocked` it accepted) are left out. + */ +export const GOAL_STATE_EVENT_CAUSES = [ + 'create', + 'replace', + 'edit', + 'pause', + 'resume', + 'clear', + 'complete', + 'blocked', + 'usage_limited', + 'verifier_reject', +] as const satisfies readonly GoalStateCause[]; + +export type GoalStateEventCause = (typeof GOAL_STATE_EVENT_CAUSES)[number]; + +/** + * A committed Goal state transition. + * + * Numbers and enums only. The objective, the stop reason and the checkpoint + * failure are free text a user or a model wrote, and `telemetry.logPrompts` + * defaults to on, so none of them is carried under any setting; the objective + * contributes its length. + */ +export interface GoalStateEvent extends BaseTelemetryEvent { + 'event.name': 'goal_state'; + cause: GoalStateEventCause; + goal_id: string; + revision: number; + /** Absent on `clear`, which leaves no Goal to describe. */ + status?: GoalStatus; + limit_kind?: GoalLimitKind; + turn_count?: number; + tokens_used?: number; + token_budget?: number; + turn_budget?: number; + active_time_ms?: number; + active_time_budget_ms?: number; + /** Code points in the objective. */ + objective_length?: number; +} + +export function makeGoalStateEvent( + fields: Omit, +): GoalStateEvent { + // Absent stays absent: a key holding `undefined` would still reach the log + // record's attributes and the analytics sink as an empty field. + const present = Object.fromEntries( + Object.entries(fields).filter(([, value]) => value !== undefined), + ) as Omit; + return { + ...present, + 'event.name': 'goal_state', + 'event.timestamp': new Date().toISOString(), + }; +} + export class AuthEvent implements BaseTelemetryEvent { 'event.name': 'auth'; 'event.timestamp': string; @@ -1252,6 +1319,7 @@ export type TelemetryEvent = | ContentRetryFailureEvent | ApiRetryEvent | SubagentExecutionEvent + | GoalStateEvent | ExtensionEnableEvent | ExtensionInstallEvent | ExtensionUninstallEvent From c27e98727b8088ec660f89a2ead193b2fa903118 Mon Sep 17 00:00:00 2001 From: qqqys <266654365+qqqys@users.noreply.github.com> Date: Tue, 15 Sep 2026 22:43:05 +0800 Subject: [PATCH 2/4] fix(telemetry): correct Goal reporting scope and histogram buckets --- docs/developers/development/telemetry.md | 3 +- docs/users/features/goals.md | 6 +- packages/core/src/config/config.test.ts | 12 +++ .../core/src/telemetry/goal-events.test.ts | 89 ++++++++++++++----- packages/core/src/telemetry/metrics.test.ts | 78 +++++++++++----- packages/core/src/telemetry/metrics.ts | 22 +++-- .../telemetry/qwen-logger/qwen-logger.test.ts | 64 +++++++++++++ 7 files changed, 225 insertions(+), 49 deletions(-) diff --git a/docs/developers/development/telemetry.md b/docs/developers/development/telemetry.md index a02c4d0c979..bb4fbe805a2 100644 --- a/docs/developers/development/telemetry.md +++ b/docs/developers/development/telemetry.md @@ -718,7 +718,8 @@ The following events are logged: #### Goal Events -- `qwen-code.goal_state`: A committed Goal state transition. Emitted for `create`, `replace`, `edit`, `pause`, `resume`, `clear`, `complete`, `blocked`, `usage_limited`, and `verifier_reject`. Per-turn `turn_finished` and `checkpoint` are not reported, and neither is the state a resumed session recovers from its transcript. The objective, the stop reason, and checkpoint failure text are never included, whatever `telemetry.logPrompts` is set to. +- `qwen-code.goal_state`: A reported Goal runtime transition, not one event per transcript record. Emitted for `create`, `replace`, `edit`, `pause`, `resume`, `clear`, `complete`, `blocked`, `usage_limited`, and `verifier_reject`. Per-turn `turn_finished` and `checkpoint` are not reported, and neither is the state a resumed session recovers from its transcript. A checkpoint check following a verifier rejection may be journaled as `verifier_reject` while broadcasting the excluded `checkpoint` cause; only the rejection transition is reported. The objective, the stop reason, and checkpoint failure text are never included in this event, whatever `telemetry.logPrompts` is set to. Tool-call events can still carry objectives and model-authored reasons in `function_args`. + - **Scope**: `replace` describes the successor Goal and does not settle the outgoing Goal. `pause` includes both user and automatic no-progress pauses without distinguishing their initiator. Outcome histograms include only `complete`, `blocked`, and `usage_limited`; they do not measure the final spend of every removed or paused Goal. - **Attributes**: `cause` (string), `goal_id` (string), `revision` (int), `status` ("active", "paused", "blocked", "usage_limited", "complete"; absent on `clear`), `limit_kind` ("evidence_catalog", "checkpoint_request", "token_budget", "turn_budget", "time_budget"; optional), `turn_count` (int, optional), `tokens_used` (int, optional), `token_budget` (int, optional), `turn_budget` (int, optional), `active_time_ms` (int, optional), `active_time_budget_ms` (int, optional), `objective_length` (int, optional; code points) #### Arena Events diff --git a/docs/users/features/goals.md b/docs/users/features/goals.md index 4e236ecab97..6b8ce637a52 100644 --- a/docs/users/features/goals.md +++ b/docs/users/features/goals.md @@ -91,4 +91,8 @@ The skill is instructed to be read-only, and only its non-mutating tools are aut ## Telemetry -When [telemetry](../../developers/development/telemetry.md) is enabled, each Goal state change — set, replace, edit, pause, resume, clear, verifier rejection, and every stop — is recorded as a `qwen-code.goal_state` event with the Goal's turn count, token spend, budgets, and active time. The objective text and stop reasons are never recorded. A resumed session does not record its recovered Goal again. +Goal transitions are reported through two independent settings: [telemetry](../../developers/development/telemetry.md) enables OpenTelemetry events and metrics, while `privacy.usageStatisticsEnabled` controls usage statistics and is on by default. The OpenTelemetry event is named `qwen-code.goal_state`; usage statistics report the same transition data without the Goal id. + +Reported transitions are set, replace, edit, pause, resume, clear, verifier rejection, completion, blocking, and usage limits. Events carry turn count, token spend, active time, and any configured budgets. A `clear` event identifies only the removed Goal and its revision, with no usage figures. A `replace` event describes the new Goal, not the removed Goal's final spend. User pauses and automatic no-progress pauses share the same `pause` cause. Only completion, blocking, and usage limits contribute to the outcome histograms. A resumed session does not report its recovered Goal again. + +The Goal event itself contains no objective text or stop reasons, only the objective's length in code points. Other telemetry can contain that text: tool-call telemetry records the arguments of `propose_goal` and `update_goal`, including the objective or model-authored reason, even when `telemetry.logPrompts` is off. diff --git a/packages/core/src/config/config.test.ts b/packages/core/src/config/config.test.ts index 45a57e6dd2f..ea9810b8d57 100644 --- a/packages/core/src/config/config.test.ts +++ b/packages/core/src/config/config.test.ts @@ -4019,6 +4019,18 @@ describe('Server Config (config.ts)', () => { config, expect.objectContaining({ cause: 'resume', goal_id: 'g-resumed' }), ); + + expect(runtime.getRecoveryCause()).toBe('pause'); + await runtime.dispatch({ + action: 'pause', + expectedGoalId: 'g-resumed', + expectedRevision: runtime.getSnapshot().goal!.revision, + }); + expect(logGoalState).toHaveBeenCalledTimes(2); + expect(logGoalState).toHaveBeenLastCalledWith( + config, + expect.objectContaining({ cause: 'pause', goal_id: 'g-resumed' }), + ); }); it('holds selective Goal readiness and autonomous work until finalization', async () => { diff --git a/packages/core/src/telemetry/goal-events.test.ts b/packages/core/src/telemetry/goal-events.test.ts index 3ab6d27b382..739e0e91dc1 100644 --- a/packages/core/src/telemetry/goal-events.test.ts +++ b/packages/core/src/telemetry/goal-events.test.ts @@ -4,7 +4,7 @@ * SPDX-License-Identifier: Apache-2.0 */ -import { describe, expect, it } from 'vitest'; +import { describe, expect, expectTypeOf, it } from 'vitest'; import type { GoalRecord, GoalSnapshotV2, @@ -17,6 +17,23 @@ import { import { GOAL_STATE_EVENT_CAUSES } from './types.js'; const NOW = 1_000_000; +const REPORTED_CAUSES = [ + 'create', + 'replace', + 'edit', + 'pause', + 'resume', + 'complete', + 'blocked', + 'usage_limited', + 'verifier_reject', +] as const; +const UNREPORTED_CAUSES = [ + 'turn_finished', + 'checkpoint', + 'migrated', + 'verifier_accept', +] as const; function goal(overrides: Partial = {}): GoalRecord { return { @@ -42,27 +59,29 @@ function snapshot( } describe('goalStateEventFromSnapshot', () => { - it.each(GOAL_STATE_EVENT_CAUSES.filter((cause) => cause !== 'clear'))( - 'reports %s', - (cause) => { - expect( - goalStateEventFromSnapshot(snapshot(goal()), cause, NOW), - ).toMatchObject({ - 'event.name': 'goal_state', - cause, - goal_id: 'g-1', - revision: 3, - }); - }, - ); - - it.each([ - 'turn_finished', - 'checkpoint', - 'migrated', - 'verifier_accept', - undefined, - ])('does not report %s', (cause) => { + it('classifies every runtime cause and pins the reported set', () => { + expectTypeOf().toEqualTypeOf< + | (typeof REPORTED_CAUSES)[number] + | (typeof UNREPORTED_CAUSES)[number] + | 'clear' + >(); + expect([...GOAL_STATE_EVENT_CAUSES].sort()).toEqual( + [...REPORTED_CAUSES, 'clear'].sort(), + ); + }); + + it.each(REPORTED_CAUSES)('reports %s', (cause) => { + expect( + goalStateEventFromSnapshot(snapshot(goal()), cause, NOW), + ).toMatchObject({ + 'event.name': 'goal_state', + cause, + goal_id: 'g-1', + revision: 3, + }); + }); + + it.each([...UNREPORTED_CAUSES, undefined])('does not report %s', (cause) => { // Per-turn causes would multiply the volume; an accept is always followed // by the stop it accepted; a missing cause is an activity change. expect(isGoalStateEventCause(cause)).toBe(false); @@ -119,6 +138,32 @@ describe('goalStateEventFromSnapshot', () => { } }); + it('preserves zero figures on a newly created Goal', () => { + const event = goalStateEventFromSnapshot( + snapshot( + goal({ + status: 'active', + turnCount: 0, + tokensUsed: 0, + activeTimeMs: 0, + createdAt: NOW, + updatedAt: NOW, + }), + ), + 'create', + NOW, + ); + + expect(event).toMatchObject({ + turn_count: 0, + tokens_used: 0, + active_time_ms: 0, + }); + expect(Object.keys(event!)).toEqual( + expect.arrayContaining(['turn_count', 'tokens_used', 'active_time_ms']), + ); + }); + it("reads an active Goal's running clock as of the broadcast", () => { // `activeTimeMs` is only committed on a transition; an active Goal has // been accruing since `updatedAt`. diff --git a/packages/core/src/telemetry/metrics.test.ts b/packages/core/src/telemetry/metrics.test.ts index 420c83985a8..fdaaca76d31 100644 --- a/packages/core/src/telemetry/metrics.test.ts +++ b/packages/core/src/telemetry/metrics.test.ts @@ -239,7 +239,15 @@ describe('Telemetry Metrics', () => { ); expect(mockCreateHistogramFn).toHaveBeenCalledWith( 'qwen-code.goal.tokens_used', - expect.objectContaining({ unit: '{token}' }), + expect.objectContaining({ + unit: '{token}', + advice: { + explicitBucketBoundaries: [ + 1_000, 10_000, 100_000, 500_000, 1_000_000, 5_000_000, 10_000_000, + 30_000_000, + ], + }, + }), ); expect(mockCreateHistogramFn).toHaveBeenCalledWith( 'qwen-code.goal.turn_count', @@ -272,34 +280,64 @@ describe('Telemetry Metrics', () => { expect(mockHistogramRecordFn).not.toHaveBeenCalled(); }); - it('records spend and turns on an outcome', () => { - const config = makeFakeConfig({ sessionId: 'test-session-id' }); + it.each(['complete', 'blocked', 'usage_limited'] as const)( + 'records spend and turns on %s', + (cause) => { + const config = makeFakeConfig({ sessionId: 'test-session-id' }); + initializeMetricsModule(config); + mockCounterAddFn.mockClear(); + const limitAttributes = + cause === 'usage_limited' + ? { limit_kind: 'time_budget' as const } + : {}; + + recordGoalStateMetricsModule( + config, + goalEvent({ + cause, + status: cause, + ...limitAttributes, + turn_count: 12, + tokens_used: 45_000, + }), + ); + + expect(mockCounterAddFn).toHaveBeenCalledWith(1, { + cause, + status: cause, + ...limitAttributes, + }); + expect(mockHistogramRecordFn).toHaveBeenCalledWith(45_000, { + cause, + ...limitAttributes, + }); + expect(mockHistogramRecordFn).toHaveBeenCalledWith(12, { + cause, + ...limitAttributes, + }); + }, + ); + + it('records zero spend and turns on an outcome', () => { + const config = makeFakeConfig({}); initializeMetricsModule(config); - mockCounterAddFn.mockClear(); recordGoalStateMetricsModule( config, goalEvent({ - cause: 'usage_limited', - status: 'usage_limited', - limit_kind: 'time_budget', - turn_count: 12, - tokens_used: 45_000, + cause: 'complete', + status: 'complete', + tokens_used: 0, + turn_count: 0, }), ); - expect(mockCounterAddFn).toHaveBeenCalledWith(1, { - cause: 'usage_limited', - status: 'usage_limited', - limit_kind: 'time_budget', - }); - expect(mockHistogramRecordFn).toHaveBeenCalledWith(45_000, { - cause: 'usage_limited', - limit_kind: 'time_budget', + expect(mockHistogramRecordFn).toHaveBeenCalledTimes(2); + expect(mockHistogramRecordFn).toHaveBeenNthCalledWith(1, 0, { + cause: 'complete', }); - expect(mockHistogramRecordFn).toHaveBeenCalledWith(12, { - cause: 'usage_limited', - limit_kind: 'time_budget', + expect(mockHistogramRecordFn).toHaveBeenNthCalledWith(2, 0, { + cause: 'complete', }); }); }); diff --git a/packages/core/src/telemetry/metrics.ts b/packages/core/src/telemetry/metrics.ts index 7646a648d3d..20ce313cdb7 100644 --- a/packages/core/src/telemetry/metrics.ts +++ b/packages/core/src/telemetry/metrics.ts @@ -278,6 +278,12 @@ const HISTOGRAM_DEFINITIONS = { 'Tokens a Goal had spent when it completed, was blocked, or reached a usage limit.', unit: '{token}', valueType: ValueType.INT, + advice: { + explicitBucketBoundaries: [ + 1_000, 10_000, 100_000, 500_000, 1_000_000, 5_000_000, 10_000_000, + 30_000_000, + ] as number[], + }, assign: (h: Histogram) => (goalTokensUsedHistogram = h), attributes: {} as { cause: GoalOutcomeCause; @@ -579,11 +585,17 @@ export function initializeMetrics(config: TelemetryRuntimeConfig): void { valueType: ValueType.INT, }); - Object.entries(HISTOGRAM_DEFINITIONS).forEach( - ([name, { description, unit, valueType, assign }]) => { - assign(meter.createHistogram(name, { description, unit, valueType })); - }, - ); + Object.entries(HISTOGRAM_DEFINITIONS).forEach(([name, definition]) => { + const { description, unit, valueType, assign } = definition; + assign( + meter.createHistogram(name, { + description, + unit, + valueType, + ...('advice' in definition ? { advice: definition.advice } : {}), + }), + ); + }); // Increment session counter after all metrics are initialized sessionCounter?.add(1, baseMetricDefinition.getCommonAttributes(config)); diff --git a/packages/core/src/telemetry/qwen-logger/qwen-logger.test.ts b/packages/core/src/telemetry/qwen-logger/qwen-logger.test.ts index 3563fac25c9..f86911a66b5 100644 --- a/packages/core/src/telemetry/qwen-logger/qwen-logger.test.ts +++ b/packages/core/src/telemetry/qwen-logger/qwen-logger.test.ts @@ -491,6 +491,70 @@ describe('QwenLogger', () => { expect(keys).not.toContain('token_budget'); }); + it('journals every allowed Goal property without the Goal id', () => { + const logger = QwenLogger.getInstance(mockConfig)!; + const enqueueSpy = vi.spyOn(logger, 'enqueueLogEvent'); + + logger.logGoalStateEvent( + makeGoalStateEvent({ + cause: 'usage_limited', + goal_id: 'g-1', + revision: 4, + status: 'usage_limited', + limit_kind: 'time_budget', + turn_count: 7, + tokens_used: 9_000, + token_budget: 80_000, + turn_budget: 50, + active_time_ms: 60_000, + active_time_budget_ms: 60_000, + objective_length: 22, + }), + ); + + const rumEvent = enqueueSpy.mock.calls[0]![0]; + expect(rumEvent.properties).toEqual({ + cause: 'usage_limited', + revision: 4, + status: 'usage_limited', + limit_kind: 'time_budget', + turn_count: 7, + tokens_used: 9_000, + token_budget: 80_000, + turn_budget: 50, + active_time_ms: 60_000, + active_time_budget_ms: 60_000, + objective_length: 22, + }); + expect(Object.keys(rumEvent.properties ?? {})).not.toContain('goal_id'); + }); + + it('preserves zero Goal figures in analytics', () => { + const logger = QwenLogger.getInstance(mockConfig)!; + const enqueueSpy = vi.spyOn(logger, 'enqueueLogEvent'); + + logger.logGoalStateEvent( + makeGoalStateEvent({ + cause: 'create', + goal_id: 'g-1', + revision: 1, + status: 'active', + turn_count: 0, + tokens_used: 0, + active_time_ms: 0, + }), + ); + + expect(enqueueSpy.mock.calls[0]![0].properties).toEqual({ + cause: 'create', + revision: 1, + status: 'active', + turn_count: 0, + tokens_used: 0, + active_time_ms: 0, + }); + }); + it('logs protocol tag sanitization without model content', () => { const logger = QwenLogger.getInstance(mockConfig)!; const enqueueSpy = vi.spyOn(logger, 'enqueueLogEvent'); From fb7cfccafdc0adc5da3e5750ce346ce132ed46d0 Mon Sep 17 00:00:00 2001 From: qqqys <266654365+qqqys@users.noreply.github.com> Date: Tue, 15 Sep 2026 22:47:10 +0800 Subject: [PATCH 3/4] test(telemetry): handle optional Goal recovery accessor --- packages/core/src/config/config.test.ts | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/packages/core/src/config/config.test.ts b/packages/core/src/config/config.test.ts index ea9810b8d57..fafcb33bc1c 100644 --- a/packages/core/src/config/config.test.ts +++ b/packages/core/src/config/config.test.ts @@ -4020,7 +4020,7 @@ describe('Server Config (config.ts)', () => { expect.objectContaining({ cause: 'resume', goal_id: 'g-resumed' }), ); - expect(runtime.getRecoveryCause()).toBe('pause'); + expect(runtime.getRecoveryCause?.()).toBe('pause'); await runtime.dispatch({ action: 'pause', expectedGoalId: 'g-resumed', From 25de52faf2ed4f68bc94fae07c0925c9308ff758 Mon Sep 17 00:00:00 2001 From: qqqys <266654365+qqqys@users.noreply.github.com> Date: Wed, 16 Sep 2026 10:27:23 +0800 Subject: [PATCH 4/4] fix(telemetry): pin Goal metric semantics and coverage --- docs/design/2026-09-15-goal-telemetry.md | 2 +- .../design/2026-09-15-goal-telemetry.zh-CN.md | 2 +- docs/developers/development/telemetry.md | 10 ++- docs/users/features/goals.md | 2 +- packages/core/src/goals/goal-runtime.test.ts | 9 ++ .../core/src/telemetry/goal-events.test.ts | 30 +++++++ packages/core/src/telemetry/goal-events.ts | 1 + packages/core/src/telemetry/metrics.test.ts | 84 ++++++++++++++++++- packages/core/src/telemetry/metrics.ts | 18 +++- .../telemetry/qwen-logger/qwen-logger.test.ts | 4 + .../src/telemetry/qwen-logger/qwen-logger.ts | 1 + packages/core/src/telemetry/types.ts | 1 + 12 files changed, 149 insertions(+), 15 deletions(-) diff --git a/docs/design/2026-09-15-goal-telemetry.md b/docs/design/2026-09-15-goal-telemetry.md index e825616370c..bb26f716b1d 100644 --- a/docs/design/2026-09-15-goal-telemetry.md +++ b/docs/design/2026-09-15-goal-telemetry.md @@ -20,7 +20,7 @@ Codex counts goal outcomes in its metrics, and Claude Code emits `tengu_goal_*` **No free text.** The event carries identifiers, enums and numbers: the Goal id and revision, the resulting status, the limit kind, the turn count and turn budget, tokens used and the token budget, active time and the active-time budget, and the objective's length in code points. The objective, the stop reason and the checkpoint failure message are never included. `telemetry.logPrompts`, the switch that gates prompt text elsewhere, defaults to on, so gating the objective behind it would include it by default. An active Goal's committed `activeTimeMs` lags the clock, so the event reads it as of the broadcast. -**Metrics stay bounded.** `qwen-code.goal.transition.count` counts every event, tagged by `cause`, `status` and `limit_kind`. On `complete`, `blocked` and `usage_limited`, the histograms `qwen-code.goal.tokens_used` and `qwen-code.goal.turn_count` record what the Goal had spent, tagged by `cause` and `limit_kind`. The Goal id stays on the log record: every Goal is a new value, which is the unbounded time-series fan-out the metrics module already declines for `session.id` by default. +**Metrics stay bounded.** `qwen-code.goal.transition.count` counts every event, tagged by `cause`, `status` and `limit_kind`. On `complete`, `blocked` and `usage_limited`, the histograms `qwen-code.goal.tokens_used` and `qwen-code.goal.turn_count` record what the Goal had spent, tagged by `cause` and `limit_kind`. The Goal id stays on the log record: every Goal is a new value, which is the unbounded time-series fan-out the metrics module already declines for `session.id` by default. A resumed Goal contributes one observation per stop, with lifetime cumulative spend and turns. Histogram `_count` counts stops rather than distinct Goals, and `_sum` is not total Goal spend. **Both sinks.** The log record goes to OpenTelemetry when the SDK is initialized, and the analytics sink receives the event when usage statistics are enabled, as with every other event. The analytics payload leaves out the Goal id, because that sink aggregates by installation. diff --git a/docs/design/2026-09-15-goal-telemetry.zh-CN.md b/docs/design/2026-09-15-goal-telemetry.zh-CN.md index 77861a49969..a6ee341fb9a 100644 --- a/docs/design/2026-09-15-goal-telemetry.zh-CN.md +++ b/docs/design/2026-09-15-goal-telemetry.zh-CN.md @@ -20,7 +20,7 @@ Codex 在指标里统计 goal 结果，Claude Code 发出 `tengu_goal_*` 分析 **不带自由文本。** 事件只携带标识、枚举和数字：Goal id 与 revision、转换后的状态、限制类型、轮数与轮数预算、已用 token 与 token 预算、活跃时长与活跃时长预算，以及目标按码点计的长度。目标、停止原因和 checkpoint 失败信息一律不包含。别处用来控制 prompt 文本的开关 `telemetry.logPrompts` 默认开启，所以把目标放在它后面就等于默认上报。active 状态的 Goal 已提交的 `activeTimeMs` 落后于时钟，所以事件按广播时刻读取。 -**指标保持有界。** `qwen-code.goal.transition.count` 统计每个事件，属性为 `cause`、`status` 和 `limit_kind`。在 `complete`、`blocked` 和 `usage_limited` 时，直方图 `qwen-code.goal.tokens_used` 与 `qwen-code.goal.turn_count` 记录 Goal 到此为止的花费，属性为 `cause` 和 `limit_kind`。Goal id 只留在日志记录上：每个 Goal 都是一个新值，这正是指标模块默认对 `session.id` 所拒绝的无界时间序列膨胀。 +**指标保持有界。** `qwen-code.goal.transition.count` 统计每个事件，属性为 `cause`、`status` 和 `limit_kind`。在 `complete`、`blocked` 和 `usage_limited` 时，直方图 `qwen-code.goal.tokens_used` 与 `qwen-code.goal.turn_count` 记录 Goal 到此为止的花费，属性为 `cause` 和 `limit_kind`。Goal id 只留在日志记录上：每个 Goal 都是一个新值，这正是指标模块默认对 `session.id` 所拒绝的无界时间序列膨胀。 恢复后的 Goal 每次停止都会贡献一个观测值，其中花费和轮数按整个 Goal 生命周期累计。因此直方图 `_count` 统计停止次数而非不同 Goal 的数量，`_sum` 不能作为 Goal 的总花费。 **两个 sink。** 与其他所有事件一样，OpenTelemetry SDK 初始化时日志记录发往 OpenTelemetry，启用使用统计时分析 sink 收到该事件。分析 sink 的载荷不含 Goal id，因为该 sink 按安装实例聚合。 diff --git a/docs/developers/development/telemetry.md b/docs/developers/development/telemetry.md index b3ab5f97757..fee83b3561f 100644 --- a/docs/developers/development/telemetry.md +++ b/docs/developers/development/telemetry.md @@ -719,8 +719,8 @@ The following events are logged: #### Goal Events - `qwen-code.goal_state`: A reported Goal runtime transition, not one event per transcript record. Emitted for `create`, `replace`, `edit`, `pause`, `resume`, `clear`, `complete`, `blocked`, `usage_limited`, and `verifier_reject`. Per-turn `turn_finished` and `checkpoint` are not reported, and neither is the state a resumed session recovers from its transcript. A checkpoint check following a verifier rejection may be journaled as `verifier_reject` while broadcasting the excluded `checkpoint` cause; only the rejection transition is reported. The objective, the stop reason, and checkpoint failure text are never included in this event, whatever `telemetry.logPrompts` is set to. Tool-call events can still carry objectives and model-authored reasons in `function_args`. - - **Scope**: `replace` describes the successor Goal and does not settle the outgoing Goal. `pause` includes both user and automatic no-progress pauses without distinguishing their initiator. Outcome histograms include only `complete`, `blocked`, and `usage_limited`; they do not measure the final spend of every removed or paused Goal. - - **Attributes**: `cause` (string), `goal_id` (string), `revision` (int), `status` ("active", "paused", "blocked", "usage_limited", "complete"; absent on `clear`), `limit_kind` ("evidence_catalog", "checkpoint_request", "token_budget", "turn_budget", "time_budget"; optional), `turn_count` (int, optional), `tokens_used` (int, optional), `token_budget` (int, optional), `turn_budget` (int, optional), `active_time_ms` (int, optional), `active_time_budget_ms` (int, optional), `objective_length` (int, optional; code points) + - **Scope**: `replace` describes the successor Goal and does not settle the outgoing Goal. `pause` includes both user and automatic no-progress pauses. `no_progress_turns` carries the raw consecutive no-progress count when available; it does not classify the stop or add a metric dimension. Outcome histograms include only `complete`, `blocked`, and `usage_limited`; they do not measure the final spend of every removed or paused Goal. + - **Attributes**: `cause` (string), `goal_id` (string), `revision` (int), `status` ("active", "paused", "blocked", "usage_limited", "complete"; absent on `clear`), `limit_kind` ("evidence_catalog", "checkpoint_request", "token_budget", "turn_budget", "time_budget"; optional), `turn_count` (int, optional), `tokens_used` (int, optional; legacy transcripts without spend tracking restore this as 0, not as an absent value), `no_progress_turns` (int, optional), `token_budget` (int, optional), `turn_budget` (int, optional), `active_time_ms` (int, optional), `active_time_budget_ms` (int, optional), `objective_length` (int, optional; code points) #### Arena Events @@ -830,12 +830,14 @@ Metrics are numerical measurements of behavior over time. Metric names use the ` - `qwen-code.goal.transition.count` (Counter, Int): Goal state transitions, one per `qwen-code.goal_state` event. - **Attributes**: `cause`, `status` (optional), `limit_kind` (optional) -- `qwen-code.goal.tokens_used` (Histogram, `{token}`): Tokens a Goal had spent when it completed, was blocked, or reached a usage limit. +- `qwen-code.goal.tokens_used` (Histogram, `{token}`): Cumulative tokens spent at each completion, blocking, or usage-limit stop. Legacy transcripts without spend tracking restore an initial spend of 0; unknown prior spend is not distinguishable from measured zero. - **Attributes**: `cause` ("complete", "blocked", "usage_limited"), `limit_kind` (optional) -- `qwen-code.goal.turn_count` (Histogram, `{turn}`): Turns a Goal had finished at the same three outcomes. +- `qwen-code.goal.turn_count` (Histogram, `{turn}`): Cumulative turns finished at each of the same three stops. - **Attributes**: `cause` ("complete", "blocked", "usage_limited"), `limit_kind` (optional) +A resumed Goal can contribute multiple stop observations, each containing its lifetime cumulative meters. Histogram `_count` counts stops, not distinct Goals, and `_sum` is not total Goal spend. Token buckets extend through 600 million and turn buckets through 50,000 to distinguish larger resumed runs. Values above those finite boundaries share the `+Inf` bucket; observation count and sum still retain those values. + #### Arena Metrics - `qwen-code.arena.session.count` (Counter, Int): Arena sessions by status. diff --git a/docs/users/features/goals.md b/docs/users/features/goals.md index 6b8ce637a52..408997774c6 100644 --- a/docs/users/features/goals.md +++ b/docs/users/features/goals.md @@ -93,6 +93,6 @@ The skill is instructed to be read-only, and only its non-mutating tools are aut Goal transitions are reported through two independent settings: [telemetry](../../developers/development/telemetry.md) enables OpenTelemetry events and metrics, while `privacy.usageStatisticsEnabled` controls usage statistics and is on by default. The OpenTelemetry event is named `qwen-code.goal_state`; usage statistics report the same transition data without the Goal id. -Reported transitions are set, replace, edit, pause, resume, clear, verifier rejection, completion, blocking, and usage limits. Events carry turn count, token spend, active time, and any configured budgets. A `clear` event identifies only the removed Goal and its revision, with no usage figures. A `replace` event describes the new Goal, not the removed Goal's final spend. User pauses and automatic no-progress pauses share the same `pause` cause. Only completion, blocking, and usage limits contribute to the outcome histograms. A resumed session does not report its recovered Goal again. +Reported transitions are set, replace, edit, pause, resume, clear, verifier rejection, completion, blocking, and usage limits. Events carry turn count, token spend, active time, and any configured budgets. A `clear` event identifies only the removed Goal and its revision, with no usage figures. A `replace` event describes the new Goal, not the removed Goal's final spend. User pauses and automatic no-progress pauses share the same `pause` cause; events include the raw no-progress streak when available. Only completion, blocking, and usage limits contribute to the outcome histograms. A resumed session does not re-report the transition its Goal was recovered from. A new stop committed during recovery, including a replayed checkpoint reaching a limit, is reported normally. The Goal event itself contains no objective text or stop reasons, only the objective's length in code points. Other telemetry can contain that text: tool-call telemetry records the arguments of `propose_goal` and `update_goal`, including the objective or model-authored reason, even when `telemetry.logPrompts` is off. diff --git a/packages/core/src/goals/goal-runtime.test.ts b/packages/core/src/goals/goal-runtime.test.ts index b2ace8502d1..19355322f2d 100644 --- a/packages/core/src/goals/goal-runtime.test.ts +++ b/packages/core/src/goals/goal-runtime.test.ts @@ -3366,6 +3366,8 @@ describe('goal runtime', () => { verifier, checkpointVerifier, }); + const causes: Array = []; + runtime.subscribe((_snapshot, cause) => causes.push(cause)); runtime.bindHost(host); await runtime.dispatch({ action: 'create', objective: 'deliver result' }); const permit = host.started[0]!; @@ -3382,6 +3384,13 @@ describe('goal runtime', () => { await runtime.finishTurn(permit); + expect(causes).toEqual([ + 'create', + undefined, + 'turn_finished', + 'verifier_reject', + 'checkpoint', + ]); expect(checkpointVerifier).toHaveBeenCalledOnce(); expect(journal.appended.map((payload) => payload.cause)).toEqual([ 'create', diff --git a/packages/core/src/telemetry/goal-events.test.ts b/packages/core/src/telemetry/goal-events.test.ts index 739e0e91dc1..f9e99dd9b10 100644 --- a/packages/core/src/telemetry/goal-events.test.ts +++ b/packages/core/src/telemetry/goal-events.test.ts @@ -138,6 +138,36 @@ describe('goalStateEventFromSnapshot', () => { } }); + it('carries the raw no-progress streak without adding a stop classification', () => { + expect( + goalStateEventFromSnapshot( + snapshot(goal({ noProgressTurns: 3 })), + 'pause', + NOW, + ), + ).toMatchObject({ cause: 'pause', no_progress_turns: 3 }); + expect( + goalStateEventFromSnapshot(snapshot(goal()), 'pause', NOW), + ).not.toHaveProperty('no_progress_turns'); + expect( + goalStateEventFromSnapshot( + snapshot( + goal({ + status: 'usage_limited', + limitKind: 'token_budget', + noProgressTurns: 3, + }), + ), + 'usage_limited', + NOW, + ), + ).toMatchObject({ + cause: 'usage_limited', + limit_kind: 'token_budget', + no_progress_turns: 3, + }); + }); + it('preserves zero figures on a newly created Goal', () => { const event = goalStateEventFromSnapshot( snapshot( diff --git a/packages/core/src/telemetry/goal-events.ts b/packages/core/src/telemetry/goal-events.ts index 2c5a61b09c7..d42f5998056 100644 --- a/packages/core/src/telemetry/goal-events.ts +++ b/packages/core/src/telemetry/goal-events.ts @@ -56,6 +56,7 @@ export function goalStateEventFromSnapshot( limit_kind: goal.limitKind, turn_count: goal.turnCount, tokens_used: goal.tokensUsed, + no_progress_turns: goal.noProgressTurns, token_budget: goal.tokenBudget, turn_budget: goal.turnBudget, active_time_ms: elapsedActiveTime(goal, now), diff --git a/packages/core/src/telemetry/metrics.test.ts b/packages/core/src/telemetry/metrics.test.ts index fdaaca76d31..150ec950664 100644 --- a/packages/core/src/telemetry/metrics.test.ts +++ b/packages/core/src/telemetry/metrics.test.ts @@ -211,6 +211,18 @@ describe('Telemetry Metrics', () => { }); describe('recordGoalStateMetrics', () => { + const histogramSpies = new Map(); + beforeEach(() => { + histogramSpies.clear(); + mockCreateHistogramFn.mockImplementation((name: string) => { + const record = vi.fn((...args: Parameters) => + mockHistogramRecordFn(...args), + ); + histogramSpies.set(name, record); + return { record } as Histogram; + }); + }); + const goalEvent = (fields: Partial): GoalStateEvent => ({ 'event.name': 'goal_state', 'event.timestamp': '2025-01-01T00:00:00.000Z', @@ -244,14 +256,22 @@ describe('Telemetry Metrics', () => { advice: { explicitBucketBoundaries: [ 1_000, 10_000, 100_000, 500_000, 1_000_000, 5_000_000, 10_000_000, - 30_000_000, + 30_000_000, 100_000_000, 300_000_000, 600_000_000, ], }, }), ); expect(mockCreateHistogramFn).toHaveBeenCalledWith( 'qwen-code.goal.turn_count', - expect.objectContaining({ unit: '{turn}' }), + expect.objectContaining({ + unit: '{turn}', + advice: { + explicitBucketBoundaries: [ + 1, 5, 10, 25, 50, 100, 250, 500, 1_000, 5_000, 10_000, 25_000, + 50_000, + ], + }, + }), ); }); @@ -307,17 +327,73 @@ describe('Telemetry Metrics', () => { status: cause, ...limitAttributes, }); - expect(mockHistogramRecordFn).toHaveBeenCalledWith(45_000, { + expect( + histogramSpies.get('qwen-code.goal.tokens_used'), + ).toHaveBeenCalledWith(45_000, { cause, ...limitAttributes, }); - expect(mockHistogramRecordFn).toHaveBeenCalledWith(12, { + expect( + histogramSpies.get('qwen-code.goal.turn_count'), + ).toHaveBeenCalledWith(12, { cause, ...limitAttributes, }); }, ); + it.each([ + 'create', + 'replace', + 'edit', + 'pause', + 'resume', + 'clear', + 'verifier_reject', + ] as const)('records no outcome figure on %s', (cause) => { + const config = makeFakeConfig({}); + initializeMetricsModule(config); + mockCounterAddFn.mockClear(); + recordGoalStateMetricsModule( + config, + goalEvent({ cause, tokens_used: 45_000, turn_count: 12 }), + ); + expect(mockCounterAddFn).toHaveBeenCalledWith(1, { cause }); + expect(mockHistogramRecordFn).not.toHaveBeenCalled(); + }); + + it('records cumulative observations on each stop of a resumed Goal', () => { + const config = makeFakeConfig({}); + initializeMetricsModule(config); + for (const [tokens_used, turn_count] of [ + [30_000_000, 2], + [60_000_000, 4], + ]) { + recordGoalStateMetricsModule( + config, + goalEvent({ + cause: 'usage_limited', + limit_kind: 'token_budget', + tokens_used, + turn_count, + }), + ); + } + const attributes = { cause: 'usage_limited', limit_kind: 'token_budget' }; + expect( + histogramSpies.get('qwen-code.goal.tokens_used')?.mock.calls, + ).toEqual([ + [30_000_000, attributes], + [60_000_000, attributes], + ]); + expect( + histogramSpies.get('qwen-code.goal.turn_count')?.mock.calls, + ).toEqual([ + [2, attributes], + [4, attributes], + ]); + }); + it('records zero spend and turns on an outcome', () => { const config = makeFakeConfig({}); initializeMetricsModule(config); diff --git a/packages/core/src/telemetry/metrics.ts b/packages/core/src/telemetry/metrics.ts index 20ce313cdb7..675c843540e 100644 --- a/packages/core/src/telemetry/metrics.ts +++ b/packages/core/src/telemetry/metrics.ts @@ -48,8 +48,13 @@ type GoalOutcomeCause = Extract< GoalStateEventCause, 'complete' | 'blocked' | 'usage_limited' >; -const GOAL_OUTCOME_CAUSES: ReadonlySet = - new Set(['complete', 'blocked', 'usage_limited']); +function isGoalOutcomeCause( + cause: GoalStateEventCause, +): cause is GoalOutcomeCause { + return ( + cause === 'complete' || cause === 'blocked' || cause === 'usage_limited' + ); +} // Arena Metrics const ARENA_SESSION_COUNT = `${SERVICE_NAME}.arena.session.count`; @@ -281,7 +286,7 @@ const HISTOGRAM_DEFINITIONS = { advice: { explicitBucketBoundaries: [ 1_000, 10_000, 100_000, 500_000, 1_000_000, 5_000_000, 10_000_000, - 30_000_000, + 30_000_000, 100_000_000, 300_000_000, 600_000_000, ] as number[], }, assign: (h: Histogram) => (goalTokensUsedHistogram = h), @@ -295,6 +300,11 @@ const HISTOGRAM_DEFINITIONS = { 'Turns a Goal had finished when it completed, was blocked, or reached a usage limit.', unit: '{turn}', valueType: ValueType.INT, + advice: { + explicitBucketBoundaries: [ + 1, 5, 10, 25, 50, 100, 250, 500, 1_000, 5_000, 10_000, 25_000, 50_000, + ] as number[], + }, assign: (h: Histogram) => (goalTurnCountHistogram = h), attributes: {} as { cause: GoalOutcomeCause; @@ -706,7 +716,7 @@ export function recordGoalStateMetrics( ...(event.status ? { status: event.status } : {}), ...limitKind, }); - if (!GOAL_OUTCOME_CAUSES.has(event.cause)) return; + if (!isGoalOutcomeCause(event.cause)) return; const outcome = { ...common, cause: event.cause, ...limitKind }; if (event.tokens_used !== undefined) { goalTokensUsedHistogram?.record(event.tokens_used, outcome); diff --git a/packages/core/src/telemetry/qwen-logger/qwen-logger.test.ts b/packages/core/src/telemetry/qwen-logger/qwen-logger.test.ts index f86911a66b5..6442c1bbab0 100644 --- a/packages/core/src/telemetry/qwen-logger/qwen-logger.test.ts +++ b/packages/core/src/telemetry/qwen-logger/qwen-logger.test.ts @@ -469,6 +469,7 @@ describe('QwenLogger', () => { status: 'blocked', turn_count: 7, tokens_used: 9_000, + no_progress_turns: 3, }), ); @@ -483,6 +484,7 @@ describe('QwenLogger', () => { status: 'blocked', turn_count: 7, tokens_used: 9_000, + no_progress_turns: 3, }, }); const keys = Object.keys(rumEvent.properties ?? {}); @@ -504,6 +506,7 @@ describe('QwenLogger', () => { limit_kind: 'time_budget', turn_count: 7, tokens_used: 9_000, + no_progress_turns: 3, token_budget: 80_000, turn_budget: 50, active_time_ms: 60_000, @@ -520,6 +523,7 @@ describe('QwenLogger', () => { limit_kind: 'time_budget', turn_count: 7, tokens_used: 9_000, + no_progress_turns: 3, token_budget: 80_000, turn_budget: 50, active_time_ms: 60_000, diff --git a/packages/core/src/telemetry/qwen-logger/qwen-logger.ts b/packages/core/src/telemetry/qwen-logger/qwen-logger.ts index 87fa91ae650..11e0bc4e167 100644 --- a/packages/core/src/telemetry/qwen-logger/qwen-logger.ts +++ b/packages/core/src/telemetry/qwen-logger/qwen-logger.ts @@ -632,6 +632,7 @@ export class QwenLogger { 'limit_kind', 'turn_count', 'tokens_used', + 'no_progress_turns', 'token_budget', 'turn_budget', 'active_time_ms', diff --git a/packages/core/src/telemetry/types.ts b/packages/core/src/telemetry/types.ts index ab569fb737f..b06c9a72249 100644 --- a/packages/core/src/telemetry/types.ts +++ b/packages/core/src/telemetry/types.ts @@ -1148,6 +1148,7 @@ export interface GoalStateEvent extends BaseTelemetryEvent { limit_kind?: GoalLimitKind; turn_count?: number; tokens_used?: number; + no_progress_turns?: number; token_budget?: number; turn_budget?: number; active_time_ms?: number;