mirror of
https://github.com/deepseek-ai/deepseek-harness
synced 2026-08-15 21:04:50 +00:00
refactor(telemetry): remove the OTel backend's flush forwarding
Three review rounds each found a new silent-loss path in the same wrapper state (dispose racing an in-flight flush, overlapping hints displacing the retained promise, the provider's fixed 30s flush timeout rejecting while the processor still drains). Every path exists only because forwarding the seam's turn-boundary hint to forceFlush() made this backend the process's second flusher against undocumented SDK internals from the upstream experimental tree. The backend now implements no flush(): the batch processor is the only flusher, its scheduledDelayMillis (already deployment-tunable through the processor passthrough) governs export cadence, and shutdown()'s drain is complete by construction. The two race-pin tests collapse into one dispose-during-in-flight-batch drain pin; the seam's optional flush() contract now tells implementers they own the concurrent-flush/ shutdown interaction. Removal rationale and the reinstatement trigger (a stated turn-boundary latency requirement scheduledDelayMillis cannot meet — and then via the processor's own forceFlush(), never the provider's timeout-wrapped one) are recorded in the revival Agent Note, both languages.
This commit is contained in:
kingwl
@@ -2,5 +2,5 @@
|
||||
# side as of the last confirmed-consistent state. Both languages carry equal authority;
|
||||
# after editing either side, bring the other along and re-record with:
|
||||
# pnpm run verify-translation-pairing --write
|
||||
2026-07-23-session-telemetry-otel-revival.md: 28a88218566dcfe34a3b99b682a4c21d22e00ce2
|
||||
2026-07-23-session-telemetry-otel-revival.zh.md: 79428c5fbb76bdd8f3c2d0b856edd712b6a650d0
|
||||
2026-07-23-session-telemetry-otel-revival.md: 476073751a52989434798d4efa0013fc9908d6fa
|
||||
2026-07-23-session-telemetry-otel-revival.zh.md: 78372554bc57ef298d399b7f01ba8a122964d5d5
|
||||
|
||||
@@ -28,6 +28,8 @@ The boundary axiom holds: the harness's aspect ends at `emit()`. Batching, retry
|
||||
|
||||
**Map onto OTel spans (GenAI semantic conventions) instead of logs.** Rejected for this revival: the branch implementation's log mapping is reviewed and shipped-shaped; the span model is lossy for forkable, interruptible sessions and belongs to a future consumer with real span queries to serve.
|
||||
|
||||
**Forwarding the seam's turn-boundary `flush()` hint to the OTel provider's `forceFlush()`.** Shipped in the first revival round, then removed after three review rounds each found a new silent-loss path in the same wrapper state: a dispose racing an in-flight flush (the SDK's concurrent-flush guard makes shutdown's internal drain skip), overlapping hints displacing the retained promise, and the provider's fixed 30-second flush timeout rejecting while the processor still drains. Every path exists only because the forwarding made this backend the process's second flusher against undocumented SDK internals from the upstream experimental tree; with no `flush()` implemented, the batch processor is the only flusher, its `scheduledDelayMillis` (already deployment-tunable through the `processor` passthrough) governs export cadence, and `shutdown()`'s drain is complete by construction. Reinstate only if a deployment states a turn-boundary latency requirement `scheduledDelayMillis` cannot meet — and then by calling the retained `BatchLogRecordProcessor`'s own `forceFlush()`, never the provider's timeout-wrapped one.
|
||||
|
||||
## Consequences
|
||||
|
||||
A deployment adds one `cordis.yml` entry with an OTLP endpoint and gets its session stream in any OTel-compatible stack; removing the entry is the opt-out, with no residual state. A rule-free deployment exports records exactly as captured — including any credentials embedded in file contents or command output — so a deployment crossing a trust boundary must mount `telemetry/redact` listeners, and both READMEs state this plainly. Where rules are mounted, exported bodies can differ from canonical log bytes, so receivers must not treat telemetry as a byte-exact replica; the log remains the source of truth. Crash durability is explicitly out of scope until the outbox decision above is revisited.
|
||||
|
||||
@@ -28,6 +28,8 @@ Status: implemented
|
||||
|
||||
**映射到 OTel span（GenAI 语义约定）而非日志。** 本次复活否决：分支实现的日志映射已经过评审、形态可交付；span 模型对可 fork、可中断的会话有损，留给将来真正有 span 查询需求的消费者。
|
||||
|
||||
**将 seam 的轮次边界 `flush()` 提示转发到 OTel provider 的 `forceFlush()`。** 首轮复活曾交付此转发，其后移除：三轮评审在同一份包装层状态中各发现一条新的静默丢失路径——dispose 与进行中的 flush 之间的竞态（SDK 的并发 flush 防护会令 shutdown 的内部排空被跳过）、相互重叠的提示顶掉留存的 promise、以及 provider 固定的 30 秒 flush 超时在批处理器仍在排空时便 reject。这些路径存在的唯一原因，是该转发让这个后端成为进程内第二个执行 flush 的组件，面对的还是上游实验性（experimental）源码树中未见诸文档的 SDK 内部行为；不实现 `flush()` 时，批处理器就是唯一执行 flush 的组件，其 `scheduledDelayMillis`（已可由部署方经 `processor` passthrough 调优）决定导出节奏，`shutdown()` 的排空从构造上就是完整的。仅当某个部署提出 `scheduledDelayMillis` 无法满足的轮次边界延迟要求时才恢复此转发——且届时应调用留存的 `BatchLogRecordProcessor` 自身的 `forceFlush()`，绝不调用 provider 那个带超时包装的版本。
|
||||
|
||||
## Consequences
|
||||
|
||||
部署方在 `cordis.yml` 加一个带 OTLP endpoint 的条目即可把会话流接入任何 OTel 兼容体系；删除条目即退出，无残留状态。未挂载规则的部署导出的记录与捕获时完全一致——包括文件内容与命令输出中内嵌的任何凭据——因此跨信任边界的部署必须挂载 `telemetry/redact` 监听器，两个 README 对此如实陈述。挂载规则后，导出的 body 可能与 canonical log 字节不同，接收端不得把遥测当作字节精确副本；日志仍是唯一事实源。崩溃持久性在上述 outbox 决定重启前明确不在范围内。
|
||||
|
||||
@@ -1717,7 +1717,7 @@ flush?(): void
|
||||
abstract shutdown(): Promise<void>
|
||||
```
|
||||
|
||||
Source: [`packages/telemetry/session-telemetry/src/index.ts:129`](../../packages/telemetry/session-telemetry/src/index.ts)
|
||||
Source: [`packages/telemetry/session-telemetry/src/index.ts:134`](../../packages/telemetry/session-telemetry/src/index.ts)
|
||||
|
||||
## `ctx.tokenMeter` — `TokenMeterService`
|
||||
|
||||
|
||||
@@ -2,5 +2,5 @@
|
||||
# side as of the last confirmed-consistent state. Both languages carry equal authority;
|
||||
# after editing either side, bring the other along and re-record with:
|
||||
# pnpm run verify-translation-pairing --write
|
||||
README.md: 2e0c902e7b16726829319c852eab3f26a68847b3
|
||||
README.zh.md: 4917ee1fcff91f07d29bbcb1b6957b80d9e73197
|
||||
README.md: 28fffc5f43f960de1a44700aa70050d792b81d4f
|
||||
README.zh.md: 821969fea09487d9d4450e981a0d791a66dad3a1
|
||||
|
||||
@@ -17,7 +17,7 @@ The OpenTelemetry backend for [the telemetry seam](../session-telemetry/) — th
|
||||
processor: {} # optional; passed verbatim to BatchLogRecordProcessor
|
||||
```
|
||||
|
||||
`exporter.url` is the one field this package validates itself — required, no default, must parse as `http(s)` — so a missing endpoint fails at plugin load. Everything else is the SDK's option shape, owned and documented by the SDK, and both blocks pass through whole: every `OTLPExporterNodeConfigBase` field (`headers`, `timeoutMillis`, `compression`, `keepAlive`, …) reaches the exporter, and batching, retry, queue bounds, and loss policy under sustained failure are the SDK's documented behavior, tuned through the `processor` passthrough. Removing this block from `cordis.yml` is the opt-out: no residual state, no `enabled` flag.
|
||||
`exporter.url` is the one field this package validates itself — required, no default, must parse as `http(s)` — so a missing endpoint fails at plugin load. Everything else is the SDK's option shape, owned and documented by the SDK, and both blocks pass through whole: every `OTLPExporterNodeConfigBase` field (`headers`, `timeoutMillis`, `compression`, `keepAlive`, …) reaches the exporter, and batching, export cadence (`scheduledDelayMillis`), retry, queue bounds, and loss policy under sustained failure are the SDK's documented behavior, tuned through the `processor` passthrough. The backend deliberately implements no `flush()`: the batch processor is the only flusher in the process, which is what makes `shutdown()`'s drain complete. Removing this block from `cordis.yml` is the opt-out: no residual state, no `enabled` flag.
|
||||
|
||||
## What leaves the machine
|
||||
|
||||
|
||||
@@ -17,7 +17,7 @@
|
||||
processor: {} # optional; passed verbatim to BatchLogRecordProcessor
|
||||
```
|
||||
|
||||
`exporter.url` 是本包唯一自行校验的字段：必填、无默认值、必须能解析为 `http(s)`，因此缺失端点会在插件加载时失败。其余全部是 SDK 自己的选项形态，由 SDK 拥有并在 SDK 文档中说明，两个配置块都整体透传（passthrough）：`OTLPExporterNodeConfigBase` 的每个字段（`headers`、`timeoutMillis`、`compression`、`keepAlive` 等）都会到达导出器；批处理、重试、队列上限，以及持续失败下的丢失策略，都是 SDK 的文档化行为，经 `processor` 透传调优。从 `cordis.yml` 中删除该配置块即为退出方式：无残留状态，也没有 `enabled` 开关。
|
||||
`exporter.url` 是本包唯一自行校验的字段：必填、无默认值、必须能解析为 `http(s)`，因此缺失端点会在插件加载时失败。其余全部是 SDK 自己的选项形态，由 SDK 拥有并在 SDK 文档中说明，两个配置块都整体透传（passthrough）：`OTLPExporterNodeConfigBase` 的每个字段（`headers`、`timeoutMillis`、`compression`、`keepAlive` 等）都会到达导出器；批处理、导出节奏（`scheduledDelayMillis`）、重试、队列上限，以及持续失败下的丢失策略，都是 SDK 的文档化行为，经 `processor` 透传调优。该后端刻意不实现 `flush()`：批处理器是进程内唯一执行 flush 的组件，`shutdown()` 的排空正因如此才是完整的。从 `cordis.yml` 中删除该配置块即为退出方式：无残留状态，也没有 `enabled` 开关。
|
||||
|
||||
## 哪些数据会离开本机
|
||||
|
||||
|
||||
@@ -147,36 +147,26 @@ export class TelemetryOtel extends Telemetry {
|
||||
})
|
||||
}
|
||||
|
||||
/** Every not-yet-settled turn-boundary flush, retained so {@link shutdown} can order behind ALL of them. */
|
||||
private inflightFlush: Promise<void> = Promise.resolve()
|
||||
|
||||
/** Forward the turn-boundary hint to the SDK's flush, fire-and-forget. */
|
||||
override flush(): void {
|
||||
// Best-effort hint: the SDK resolves forceFlush even when exports fail
|
||||
// (failures go to its own diagnostics), and the coordinator stops calling
|
||||
// this once the fiber is disposed — a rejection would be SDK drift. The
|
||||
// settled promise is retained (not awaited): the SDK's concurrent-flush
|
||||
// guard makes a flush that overlaps another return WITHOUT draining, so
|
||||
// an overlapping hint resolves instantly and must JOIN the outstanding
|
||||
// one, not displace it — shutdown orders behind the whole set.
|
||||
/* v8 ignore next -- unreachable guard: forceFlush does not reject while the provider is alive */
|
||||
const flush = this.provider.forceFlush().catch(() => {})
|
||||
this.inflightFlush = Promise.all([this.inflightFlush, flush]).then(() => undefined)
|
||||
}
|
||||
// The seam's optional flush() hint is deliberately NOT implemented. The
|
||||
// batch processor exports on its own cadence (`processor.scheduledDelayMillis`,
|
||||
// the SDK's documented knob), and this backend is the SDK pipeline's only
|
||||
// caller — forwarding the hint to `forceFlush()` was the sole source of
|
||||
// concurrent flushes, whose undocumented interactions with shutdown's
|
||||
// internal drain (concurrent-flush guard, provider-level flush timeout)
|
||||
// silently dropped tail records. Removal history and the revival trigger:
|
||||
// the revival Agent Note.
|
||||
|
||||
/**
|
||||
* Delegate disposal to the SDK's shutdown contract: flush the queue and
|
||||
* quiesce. Orders behind every outstanding turn-boundary flush first —
|
||||
* shutdown's internal flush is a no-op while one is in flight (the SDK's
|
||||
* concurrent-flush guard), which would silently drop everything enqueued
|
||||
* after that flush snapshot, including the coordinator's dispose-time
|
||||
* `shutdown` markers. Awaited (and error-contained) by the coordinator's
|
||||
* disposer.
|
||||
* Delegate disposal to the SDK's shutdown contract: drain the queue and
|
||||
* quiesce. With no concurrent `forceFlush()` in the process (see above),
|
||||
* shutdown's internal drain is complete — everything emitted before this
|
||||
* call, including the coordinator's dispose-time `shutdown` markers, is
|
||||
* exported before the exporter closes. Awaited (and error-contained) by
|
||||
* the coordinator's disposer.
|
||||
* @returns resolves when the SDK pipeline has quiesced.
|
||||
*/
|
||||
async shutdown(): Promise<void> {
|
||||
await this.inflightFlush
|
||||
await this.provider.shutdown()
|
||||
shutdown(): Promise<void> {
|
||||
return this.provider.shutdown()
|
||||
}
|
||||
}
|
||||
|
||||
|
||||
@@ -123,12 +123,14 @@ describe('TelemetryOtel wire', () => {
|
||||
expect(ops[0]!.record.attributes).toContainEqual({ key: 'telemetry.op', value: { stringValue: 'shutdown' } })
|
||||
})
|
||||
|
||||
it('delivers records enqueued while a turn-boundary flush is in flight (flush/shutdown race)', async () => {
|
||||
// Hold the collector's response to the flush-triggered export open until
|
||||
// after disposal has begun: the SDK's concurrent-flush guard makes the
|
||||
// shutdown-internal flush return early while another flush is running, so
|
||||
// without ordering in the backend the coordinator's dispose-time shutdown
|
||||
// marker (enqueued after the flush snapshot) would be dropped silently.
|
||||
it('drains records enqueued after a timer export began: dispose during an in-flight batch', async () => {
|
||||
// The backend implements NO flush() — the batch processor exports on its
|
||||
// own cadence, and shutdown's internal drain is complete exactly because
|
||||
// nothing in the process calls forceFlush() concurrently (the SDK's
|
||||
// concurrent-flush guard skips draining otherwise). Pin that: hold the
|
||||
// collector's response to the timer-triggered export open across
|
||||
// disposal, and the dispose-time shutdown marker (enqueued after that
|
||||
// batch's snapshot) must still arrive.
|
||||
const gate = Promise.withResolvers<boolean>()
|
||||
const arrived = Promise.withResolvers<boolean>()
|
||||
const { url, captures } = await mockCollector(async (index) => {
|
||||
@@ -137,10 +139,14 @@ describe('TelemetryOtel wire', () => {
|
||||
await gate.promise
|
||||
}
|
||||
})
|
||||
const { ctx, fiber } = await boot(url)
|
||||
const session = ctx.sessions.create(SessionId('race'), { meta: {} })
|
||||
const ctx = new Context()
|
||||
await ctx.plugin(SessionStore)
|
||||
const fiber = await ctx.plugin(TelemetryOtel, {
|
||||
exporter: { url },
|
||||
processor: { scheduledDelayMillis: 10 },
|
||||
})
|
||||
const session = ctx.sessions.create(SessionId('drain'), { meta: {} })
|
||||
session.append('turn/start', { turn: 1, trigger: { kind: 'message', source: { kind: 'user' } } })
|
||||
ctx.telemetry.flush!()
|
||||
await arrived.promise
|
||||
|
||||
const disposal = fiber.dispose()
|
||||
@@ -149,40 +155,6 @@ describe('TelemetryOtel wire', () => {
|
||||
gate.resolve(true)
|
||||
await disposal
|
||||
|
||||
const records = allRecords(captures)
|
||||
const ops = records.filter(r => r.scope === '@deepseek-ai/dsh-session-telemetry-otel/ops')
|
||||
expect(ops).toHaveLength(1)
|
||||
expect(ops[0]!.record.attributes).toContainEqual({ key: 'telemetry.op', value: { stringValue: 'shutdown' } })
|
||||
})
|
||||
|
||||
it('orders shutdown behind the OLDEST in-flight flush when hints overlap', async () => {
|
||||
// The SDK's concurrent-flush guard resolves an overlapping forceFlush()
|
||||
// immediately; if the backend RETAINS only the latest flush promise, two
|
||||
// back-to-back turn flushes leave shutdown awaiting the instantly-resolved
|
||||
// second one while the first still exports — reopening the same silent
|
||||
// drop the single-flush race test pins.
|
||||
const gate = Promise.withResolvers<boolean>()
|
||||
const arrived = Promise.withResolvers<boolean>()
|
||||
const { url, captures } = await mockCollector(async (index) => {
|
||||
if (index === 0) {
|
||||
arrived.resolve(true)
|
||||
await gate.promise
|
||||
}
|
||||
})
|
||||
const { ctx, fiber } = await boot(url)
|
||||
const session = ctx.sessions.create(SessionId('race2'), { meta: {} })
|
||||
session.append('turn/start', { turn: 1, trigger: { kind: 'message', source: { kind: 'user' } } })
|
||||
ctx.telemetry.flush!()
|
||||
await arrived.promise
|
||||
// Second hint while the first export is held open: resolves immediately
|
||||
// under the SDK's guard and must not displace the outstanding one.
|
||||
ctx.telemetry.flush!()
|
||||
|
||||
const disposal = fiber.dispose()
|
||||
await new Promise(resolve => setTimeout(resolve, 50))
|
||||
gate.resolve(true)
|
||||
await disposal
|
||||
|
||||
const ops = allRecords(captures).filter(r => r.scope === '@deepseek-ai/dsh-session-telemetry-otel/ops')
|
||||
expect(ops).toHaveLength(1)
|
||||
expect(ops[0]!.record.attributes).toContainEqual({ key: 'telemetry.op', value: { stringValue: 'shutdown' } })
|
||||
@@ -209,15 +181,14 @@ describe('TelemetryOtel wire', () => {
|
||||
expect(types).toContain('turn/start')
|
||||
})
|
||||
|
||||
it('maps the warn severity and forwards the flush hint to the SDK', async () => {
|
||||
it('maps the warn severity and leaves the seam flush hint unimplemented', async () => {
|
||||
const { url, captures } = await mockCollector()
|
||||
const { ctx, fiber } = await boot(url)
|
||||
const session = ctx.sessions.create(SessionId('warn'), { meta: {} })
|
||||
session.append('prompt/blocked', { content: [], source: { kind: 'user' }, reason: 'vetoed' })
|
||||
// The turn-boundary hint: safe, non-blocking, and enough to push the batch out.
|
||||
expect(() => {
|
||||
ctx.telemetry.flush!()
|
||||
}).not.toThrow()
|
||||
// No flush(): the coordinator's optional-call forwarding no-ops, and the
|
||||
// batch processor owns export cadence end to end (see the backend note).
|
||||
expect('flush' in ctx.telemetry && ctx.telemetry.flush !== undefined).toBe(false)
|
||||
await fiber.dispose()
|
||||
const blocked = allRecords(captures).find(r =>
|
||||
r.record.attributes?.some(a => a.key === 'event.type' && a.value.stringValue === 'prompt/blocked'))
|
||||
|
||||
@@ -2,5 +2,5 @@
|
||||
# side as of the last confirmed-consistent state. Both languages carry equal authority;
|
||||
# after editing either side, bring the other along and re-record with:
|
||||
# pnpm run verify-translation-pairing --write
|
||||
README.md: 73bc22053ad08725fecade43fb33fe944dfe3c60
|
||||
README.zh.md: 8e63e14bd8e099980133c9d6d864135fba7f39af
|
||||
README.md: df0384d0528f0b3a95ded414444e1b11ea7d52bf
|
||||
README.zh.md: d86fede206a4b2363f1deda86ff32d868d1db71d
|
||||
|
||||
@@ -6,7 +6,7 @@ The telemetry seam: the CAPTURE side of session-event reporting, behind a backen
|
||||
|
||||
## The backend contract
|
||||
|
||||
`TelemetryBackend` is three members: `emit(record)` (MUST be a non-blocking enqueue — it runs synchronously on the `session/event` hot path), optional `flush()` (a turn-boundary hint, fire-and-forget), and `shutdown()` (the lifecycle forward: flush-and-quiesce, awaited at dispose). `Telemetry` is its service-registered form under the `telemetry` context key — one implementation per context, duplicate load throws. A backend composes `TelemetryCoordinator` in its constructor.
|
||||
`TelemetryBackend` is three members: `emit(record)` (MUST be a non-blocking enqueue — it runs synchronously on the `session/event` hot path), optional `flush()` (a turn-boundary hint, fire-and-forget; most backends leave it unimplemented and let their SDK's batching cadence govern export timing — an implementer owns the interaction between concurrent flushes and `shutdown()`'s drain), and `shutdown()` (the lifecycle forward: drain-and-quiesce, awaited at dispose). `Telemetry` is its service-registered form under the `telemetry` context key — one implementation per context, duplicate load throws. A backend composes `TelemetryCoordinator` in its constructor.
|
||||
|
||||
## Capture points
|
||||
|
||||
|
||||
@@ -6,7 +6,7 @@
|
||||
|
||||
## 后端契约
|
||||
|
||||
`TelemetryBackend` 只有三个成员：`emit(record)`（必须是非阻塞入队；它在 `session/event` 热路径上同步执行）、可选的 `flush()`（轮次边界提示，触发后不等待结果）、以及 `shutdown()`（生命周期转发点：flush 并完全停稳，在 dispose（资源释放）时被等待）。`Telemetry` 是它注册在 `telemetry` 上下文键下的服务形态：每个上下文只允许一个实现，重复加载会抛出异常。后端在其构造函数中组合 `TelemetryCoordinator`。
|
||||
`TelemetryBackend` 只有三个成员：`emit(record)`（必须是非阻塞入队；它在 `session/event` 热路径上同步执行）、可选的 `flush()`（轮次边界提示，触发后不等待结果；多数后端不实现它，而由其 SDK 的批处理节奏决定导出时机；并发 flush 与 `shutdown()` 的排空之间的交互由实现方自行负责）、以及 `shutdown()`（生命周期转发点：排空并完全停稳，在 dispose（资源释放）时被等待）。`Telemetry` 是它注册在 `telemetry` 上下文键下的服务形态：每个上下文只允许一个实现，重复加载会抛出异常。后端在其构造函数中组合 `TelemetryCoordinator`。
|
||||
|
||||
## 捕获点
|
||||
|
||||
|
||||
@@ -103,7 +103,12 @@ export interface TelemetryBackend {
|
||||
* Optional hint that a natural boundary (turn end) passed — a backend may
|
||||
* forward it to its SDK's flush so records land at turn boundaries. Called
|
||||
* fire-and-forget; implementations must not block and must not throw
|
||||
* meaningfully (the coordinator contains exceptions).
|
||||
* meaningfully (the coordinator contains exceptions). Most backends should
|
||||
* leave this unimplemented and let their SDK's own batching cadence govern
|
||||
* export timing: a backend that does implement it owns the interaction
|
||||
* between its concurrent flushes and {@link shutdown}'s drain (the OTel
|
||||
* backend removed its implementation for exactly that hazard — see the
|
||||
* revival Agent Note).
|
||||
*/
|
||||
flush?(): void
|
||||
/**
|
||||
|
||||
Reference in New Issue
Block a user