Skip to content

Commit 832d11a

Browse files
committed
docs(telemetry): add instrumentation conventions, snake_case attribute keys
Add src/instrumentation/CONVENTIONS.md documenting how telemetry is structured (explicit span threading, imperative setProperty, event/attribute naming, namespace grouping, properties vs measurements) and link it from CONTRIBUTING. Align existing instrumentation with the OTel naming convention: - rename caller-supplied property/measurement keys from camelCase to snake_case (auth, ssh, workspace, activation, websocket, cli.download); - strip unit suffixes from exported metric names into the OTLP unit field (latency_ms -> metric latency, unit ms) so Prometheus suffixes cleanly; - group the token-refresh span under its namespace (auth.token_refreshed -> auth.token_refresh.completed) next to auth.token_refresh.deduped. Framework-managed result/durationMs are left unchanged.
1 parent c9314a5 commit 832d11a

19 files changed

Lines changed: 272 additions & 132 deletions

CONTRIBUTING.md

Lines changed: 9 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -94,6 +94,15 @@ pnpm watch # Rebuild extension and webviews on changes
9494
Press F5 to launch the Extension Development Host. Use "Developer: Reload
9595
Webviews" to see webview changes.
9696

97+
## Telemetry
98+
99+
Local telemetry instrumentation follows a shared style: how spans are threaded,
100+
how events and properties are named, and properties vs measurements. Read this
101+
before adding new telemetry so it stays consistent across the codebase. It lives
102+
next to the code:
103+
104+
**[`src/instrumentation/CONVENTIONS.md`](src/instrumentation/CONVENTIONS.md)**
105+
97106
## Testing
98107

99108
There are a few ways you can test the "Open in VS Code" flow:

src/instrumentation/CONVENTIONS.md

Lines changed: 124 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,124 @@
1+
# Telemetry conventions
2+
3+
How to add telemetry so every instrumentation reads the same way. The framework
4+
lives in `src/telemetry`; the per-domain instrumentation business code talks to
5+
lives here in `src/instrumentation`. See `cli.ts` (spans + phases) and `ssh.ts`
6+
(point-in-time logs) as references.
7+
8+
## Checklist
9+
10+
- One instrumentation class per domain (`FooTelemetry`) wrapping
11+
`TelemetryService`; business code imports that, never a raw span.
12+
- Event name is `domain.snake_case`; point-in-time logs use past tense.
13+
- Event names and attribute keys follow OTel: lowercase, `.` for hierarchy, `_`
14+
to split words, never camelCase. Enumerated values are typed `snake_case`
15+
unions, never bare `string`.
16+
- Numbers go in `measurements` (raw), never pre-bucketed into string properties.
17+
- Set attributes imperatively with `setProperty`/`setMeasurement`; never add a
18+
return value that exists only to be logged.
19+
- No secrets, tokens, query strings, or unbounded values in properties; routes
20+
go through `normalizeRoute`.
21+
- Let the framework set `result`; add a domain `outcome` only when an operation
22+
has several success modes. Failures go to a typed union; non-error early exits
23+
call `markAborted`.
24+
25+
## Layers
26+
27+
- **Framework** (`src/telemetry`): `TelemetryService` (`trace`/`log`/`logError`)
28+
hands out `Span` handles and owns IDs, timing, `result`, level-gating, and the
29+
wire format. Telemetry-off is handled here (`NOOP_SPAN`), so instrumentation
30+
never checks whether telemetry is enabled.
31+
- **Instrumentation** (`src/instrumentation/*`): one typed class per domain, the
32+
only telemetry surface business code sees.
33+
34+
## Threading
35+
36+
Spans are passed **explicitly** as a callback argument; there is no
37+
ambient/active-span context. Two patterns keep telemetry out of business logic:
38+
39+
1. **Imperative attributes**`span.setProperty("outcome", "cache_hit")` at the
40+
point the value is known. This is the standard OpenTelemetry model.
41+
2. **Typed phases** — wrap an async step in `span.phase(...)` and read one
42+
property off its _natural_ return value, e.g.
43+
`trace.versionCheck(() => this.checkBinary(...))`. Extraction stays out of
44+
the business function.
45+
46+
Never return a value purely so a caller can log it; that couples the return type
47+
to observability. Returning is fine when the business uses the value too.
48+
49+
## Spans, phases, logs
50+
51+
- `trace(name, fn, props?, meas?)` — a span with framework-set `result` and
52+
`durationMs`. Use for an operation with a start and end.
53+
- `span.phase(name, fn, ...)` — the same, nested (composed as `parent.child`);
54+
child names cannot contain `.`.
55+
- `span.log(name, ...)` / `span.logError(name, error, ...)` — point-in-time
56+
events under a span, no `result`/`durationMs`. Use for discrete signals.
57+
58+
## Naming
59+
60+
| Thing | Convention | Examples |
61+
| -------------------------- | ------------------------------------------- | --------------------------------------------------------- |
62+
| Event name | `domain.snake_case` | `cli.resolve`, `remote.setup`, `connection.dropped` |
63+
| Point-in-time log | past tense | `connection.dropped`, `ssh.process.lost` |
64+
| Child phase | bare `snake_case` | `cache_lookup`, `version_check`, `connection_handoff` |
65+
| Property / measurement key | lowercase; `_` splits words, `.` for groups | `cache_source`, `failure_category`, `status.from` |
66+
| Enumerated value | typed `snake_case` union | `"cache_hit"`, `"session_token"`, `"unrecoverable_close"` |
67+
68+
This is the [OTel attribute convention](https://opentelemetry.io/docs/specs/semconv/general/naming/):
69+
`.` is the namespace delimiter, `_` joins words within a segment, never
70+
camelCase. Default to a flat `snake_case` key; use `.` only to group genuinely
71+
related attributes (a `status.from` / `status.to` pair). Keep phase names
72+
subject-first within a domain (`agent_resolve`, not `resolve_agent`).
73+
74+
**Grouping.** Group related events under a shared dotted namespace so a prefix
75+
query returns the whole family: `workspace.update.triggered` and
76+
`workspace.update.prompted` both sit under `workspace.update.*`, as do
77+
`auth.token_refresh.completed` / `.deduped` under `auth.token_refresh.*`. Keep
78+
the namespace node a pure prefix; don't also emit an event with that exact name,
79+
since dotted names otherwise read as span phases (`parent.child`). This is
80+
[OTel namespacing](https://opentelemetry.io/docs/specs/semconv/general/naming/),
81+
which exists precisely so related signals query together.
82+
83+
**Namespacing.** OTel suggests prefixing custom attributes (`com.acme.*`) to
84+
avoid clashing with future semconv. We don't namespace event-level attributes:
85+
each is already scoped by its (namespaced) event name and only flows into
86+
Coder's own pipeline, so a bare `cache_source` can't collide with a future OTel
87+
`cache.source`. Resource and provenance attributes stay namespaced
88+
(`coder.deployment.url`, `coder.event.*`).
89+
90+
## Properties vs measurements
91+
92+
- **Properties** are low-cardinality string dimensions (the framework stringifies
93+
`string | number | boolean`). Use them for what you group or filter by.
94+
- **Measurements** are raw numbers. Don't pre-bucket into string labels: both
95+
export as record attributes, and a query can bucket the raw number at read
96+
time. `result` and `durationMs` are framework-managed and cannot be set.
97+
- **Units.** There is no unit field at emit time, so put the unit in the
98+
measurement key as a `_ms` / `_mbits` suffix, the same way for every event.
99+
The OTLP exporter then resolves it per signal: for metric events
100+
(`http.requests`, `ssh.network.sampled`) it moves the suffix into the OTLP
101+
`unit` field and drops it from the metric name (`latency_ms` exports as metric
102+
`latency`, unit `ms`, which Prometheus then suffixes itself); log and span
103+
attributes keep the key as written. You always author `latency_ms`; only the
104+
exported metric name changes.
105+
106+
## Outcomes, failures, aborts
107+
108+
- The framework sets `result` (`success` / `error` / `aborted`) on every span;
109+
don't duplicate it.
110+
- Add a domain `outcome` property only when an operation has several success
111+
modes worth distinguishing (e.g. `cli.resolve`: `cache_hit`, `downloaded`).
112+
- Classify failures into a typed union (`failure_category`, or a domain
113+
`reason`) via a `categorize*Failure` helper rather than emitting raw error
114+
strings; the
115+
framework already captures the error block.
116+
- For a non-error early exit (cancelled, not-found), call `span.markAborted()`
117+
rather than throwing.
118+
119+
## Safety
120+
121+
Never put tokens, credentials, full URLs with query strings, or unbounded user
122+
input into properties. Routes go through `normalizeRoute`
123+
(`src/logging/routeNormalization.ts`). Prefer a closed union over a free-form
124+
string for any property a dashboard groups by.

src/instrumentation/activation.ts

Lines changed: 5 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -20,25 +20,25 @@ export interface ActivationTracer {
2020
}
2121

2222
/**
23-
* Emits `activation` with `authState`, plus a sibling `activation.deployment_init`
23+
* Emits `activation` with `auth_state`, plus a sibling `activation.deployment_init`
2424
* trace (sibling, not child, because deployment init outlives the activation span).
2525
*/
2626
export class ActivationTelemetry {
2727
public constructor(private readonly telemetry: TelemetryService) {}
2828

2929
public trace<T>(fn: (tracer: ActivationTracer) => Promise<T>): Promise<T> {
3030
return this.telemetry.trace("activation", async (span) => {
31-
span.setProperty("authState", "none");
31+
span.setProperty("auth_state", "none");
3232
return fn({
33-
setAuthState: (state) => span.setProperty("authState", state),
33+
setAuthState: (state) => span.setProperty("auth_state", state),
3434
traceDeploymentInit: (initFn) =>
3535
this.telemetry.trace(
3636
"activation.deployment_init",
3737
async (childSpan) => {
38-
childSpan.setProperty("authState", "unknown");
38+
childSpan.setProperty("auth_state", "unknown");
3939
const success = await initFn();
4040
childSpan.setProperty(
41-
"authState",
41+
"auth_state",
4242
success ? "valid_token" : "auth_failed",
4343
);
4444
return success;

src/instrumentation/auth.ts

Lines changed: 5 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -88,7 +88,9 @@ export class AuthTelemetry {
8888
trigger: AuthTokenRefreshTrigger,
8989
fn: () => Promise<T>,
9090
): Promise<T> {
91-
return this.telemetry.trace("auth.token_refreshed", fn, { trigger });
91+
return this.telemetry.trace("auth.token_refresh.completed", fn, {
92+
trigger,
93+
});
9294
}
9395

9496
/** Logged when a refresh call joins an in-flight refresh and emits no span of its own. */
@@ -110,9 +112,9 @@ export class AuthTelemetry {
110112
logReceived: () => span.log("received"),
111113
setRecovery: (recovery) => span.setProperty("recovery", recovery),
112114
setRefreshAttempted: (attempted) =>
113-
span.setProperty("refreshAttempted", attempted),
115+
span.setProperty("refresh_attempted", attempted),
114116
}),
115-
{ recovery: "none", refreshAttempted: false },
117+
{ recovery: "none", refresh_attempted: false },
116118
);
117119
}
118120

src/instrumentation/ssh.ts

Lines changed: 11 additions & 11 deletions
Original file line numberDiff line numberDiff line change
@@ -57,7 +57,7 @@ export class SshTelemetry {
5757
this.#telemetry.log(
5858
"ssh.process.lost",
5959
{ cause },
60-
{ uptimeMs: now - this.#processStartedAtMs },
60+
{ uptime_ms: now - this.#processStartedAtMs },
6161
);
6262
}
6363

@@ -68,7 +68,7 @@ export class SshTelemetry {
6868
this.#telemetry.log(
6969
"ssh.process.recovered",
7070
{},
71-
{ recoveryDurationMs: performance.now() - this.#processLostAtMs },
71+
{ recovery_duration_ms: performance.now() - this.#processLostAtMs },
7272
);
7373
this.#processLostAtMs = undefined;
7474
}
@@ -80,14 +80,14 @@ export class SshTelemetry {
8080
const now = performance.now();
8181
if (this.#processStartedAtMs !== undefined) {
8282
const measurements: Record<string, number> = {
83-
previousUptimeMs: now - this.#processStartedAtMs,
83+
previous_uptime_ms: now - this.#processStartedAtMs,
8484
};
8585
if (this.#processLostAtMs !== undefined) {
86-
measurements.lostDurationMs = now - this.#processLostAtMs;
86+
measurements.lost_duration_ms = now - this.#processLostAtMs;
8787
}
8888
this.#telemetry.log(
8989
"ssh.process.replaced",
90-
{ wasLost: this.#processLostAtMs !== undefined },
90+
{ was_lost: this.#processLostAtMs !== undefined },
9191
measurements,
9292
);
9393
}
@@ -105,8 +105,8 @@ export class SshTelemetry {
105105
const now = performance.now();
106106
this.#telemetry.log(
107107
"ssh.process.disposed",
108-
{ wasLost: this.#processLostAtMs !== undefined },
109-
{ uptimeMs: now - this.#processStartedAtMs },
108+
{ was_lost: this.#processLostAtMs !== undefined },
109+
{ uptime_ms: now - this.#processStartedAtMs },
110110
);
111111
this.#processStartedAtMs = undefined;
112112
this.#processLostAtMs = undefined;
@@ -130,12 +130,12 @@ export class SshTelemetry {
130130
"ssh.network.sampled",
131131
{
132132
p2p: network.p2p,
133-
preferredDerp: network.preferred_derp,
133+
preferred_derp: network.preferred_derp,
134134
},
135135
{
136-
latencyMs: network.latency,
137-
downloadMbits: bytesPerSecondToMbits(network.download_bytes_sec),
138-
uploadMbits: bytesPerSecondToMbits(network.upload_bytes_sec),
136+
latency_ms: network.latency,
137+
download_mbits: bytesPerSecondToMbits(network.download_bytes_sec),
138+
upload_mbits: bytesPerSecondToMbits(network.upload_bytes_sec),
139139
},
140140
);
141141
}

src/instrumentation/workspace.ts

Lines changed: 11 additions & 11 deletions
Original file line numberDiff line numberDiff line change
@@ -43,7 +43,7 @@ interface ObservedAgentState {
4343

4444
/**
4545
* Emits `workspace.state_transitioned` as a workspace progresses through
46-
* statuses, plus `observedBuildDurationMs` when a provisioner run resolves.
46+
* statuses, plus `observed_build_duration_ms` when a provisioner run resolves.
4747
* Construct one per workspace; `WorkspaceMonitor` is the sole call site.
4848
*/
4949
export class WorkspaceStateTelemetry {
@@ -73,7 +73,7 @@ export class WorkspaceStateTelemetry {
7373

7474
const now = performance.now();
7575
const measurements: Record<string, number> = previous
76-
? { observedDurationMs: now - previous.observedAtMs }
76+
? { observed_duration_ms: now - previous.observedAtMs }
7777
: {};
7878

7979
const wasProvisioning =
@@ -83,15 +83,15 @@ export class WorkspaceStateTelemetry {
8383
this.buildStartedAtMs ??= now;
8484
} else {
8585
if (wasProvisioning && this.buildStartedAtMs !== undefined) {
86-
measurements.observedBuildDurationMs = now - this.buildStartedAtMs;
86+
measurements.observed_build_duration_ms = now - this.buildStartedAtMs;
8787
}
8888
this.buildStartedAtMs = undefined;
8989
}
9090

9191
this.telemetry.log(
9292
"workspace.state_transitioned",
9393
{
94-
workspaceName: this.workspaceName,
94+
workspace_name: this.workspaceName,
9595
from: previous?.status ?? INITIAL_STATE,
9696
to: status,
9797
"build.transition": buildTransition,
@@ -135,14 +135,14 @@ export class WorkspaceAgentTelemetry {
135135
this.telemetry.log(
136136
"workspace.agent.state_transitioned",
137137
{
138-
workspaceName: this.workspaceName,
139-
agentName: agent.name,
138+
workspace_name: this.workspaceName,
139+
agent_name: agent.name,
140140
"status.from": previous?.status ?? INITIAL_STATE,
141141
"status.to": agent.status,
142142
"lifecycle_state.from": previous?.lifecycleState ?? INITIAL_STATE,
143143
"lifecycle_state.to": agent.lifecycle_state,
144144
},
145-
previous ? { observedDurationMs: now - previous.observedAtMs } : {},
145+
previous ? { observed_duration_ms: now - previous.observedAtMs } : {},
146146
);
147147
this.observed = {
148148
status: agent.status,
@@ -168,13 +168,13 @@ export class WorkspaceOperationTelemetry {
168168

169169
public traceUpdate<T>(fn: () => Promise<T>): Promise<T> {
170170
return this.telemetry.trace("workspace.update.triggered", fn, {
171-
workspaceName: this.workspaceName,
171+
workspace_name: this.workspaceName,
172172
});
173173
}
174174

175175
public traceStart<T>(fn: () => Promise<T>): Promise<T> {
176176
return this.telemetry.trace("workspace.start.triggered", fn, {
177-
workspaceName: this.workspaceName,
177+
workspace_name: this.workspaceName,
178178
});
179179
}
180180

@@ -193,7 +193,7 @@ export class WorkspaceOperationTelemetry {
193193
span.setProperty("action", action);
194194
return action;
195195
},
196-
{ workspaceName: this.workspaceName, update_offered: outdated },
196+
{ workspace_name: this.workspaceName, update_offered: outdated },
197197
);
198198
}
199199

@@ -246,7 +246,7 @@ export class WorkspaceOperationTelemetry {
246246
): Promise<T> {
247247
return this.telemetry.trace("workspace.update.prompted", fn, {
248248
prompt,
249-
workspaceName: this.workspaceName,
249+
workspace_name: this.workspaceName,
250250
});
251251
}
252252
}

0 commit comments

Comments
 (0)