Skip to content

Commit a47a2bd

Browse files
feat: enrich telemetry with pythonVersion and dbtCoreVersion customAttributes
Production telemetry currently carries `common.os` / `common.nodeArch` / `common.extversion` etc. on every event but **not** the user's Python interpreter version or installed dbt-core distribution version. That's a real blindspot — App Insights can't split error clusters by Python version (e.g. is `pythonBridgeInitPythonError "mashumaro UnserializableField"` a Python 3.13 + mashumaro 3.14 incompat or something else?) and we can't tell whether `catalogPythonError "missing used_schemas"` correlates with a specific dbt-core minor. Adds two customAttributes that get merged into every event going forward via `TelemetryService.setTelemetryCustomAttribute`: - `pythonVersion` — sourced from `PythonEnvironment.pythonVersion` (already populated via the VS Code Python extension's API on interpreter activation, no additional probe needed). - `dbtCoreVersion` — sourced from a small `child_process.spawn` probe in `src/telemetry/versionProbes.ts` that runs `python -c "from importlib.metadata import version; print(version('dbt-core'))"`. Reads dist-info directly so it survives even when dbt's own import chain is broken (the failure mode PR #96 targeted) — the bridge can be dead and we still get the version. Both are best-effort: probe failure → no customAttribute set rather than blocking activation. Wired into `DBTPowerUserExtension.activate` after `initializeDBTProjects` (when the Python interpreter is known) plus a refresh on `pythonEnvironment.onPythonEnvironmentChanged` so the dimensions track interpreter changes. `probeDbtCoreVersion` accepts an injectable `SpawnFn` parameter defaulted to `child_process.spawn`. `import * as childProcess` produces ESM-style bindings that resist `jest.spyOn` / `jest.mock` redefinition under ts-jest, so the tests pass their own spawner directly. Adds 6 unit tests covering: success, empty stdout (PackageNotFoundError), non-zero exit, error event, sync throw, and timeout. After this ships and rolls out, App Insights queries can split by `customDimensions.pythonVersion == "3.13.0"` or `customDimensions.dbtCoreVersion startswith "1.10"` on every event, not just the wrapper-failure events. Dashboards become diagnostic by construction without per-event injection. Tests: 33 suites / 486 passed (32 prior + 1 new). Co-Authored-By: Claude Opus 4.7 (1M context) <noreply@anthropic.com>
1 parent 68ef665 commit a47a2bd

5 files changed

Lines changed: 566 additions & 0 deletions

File tree

src/dbtPowerUserExtension.ts

Lines changed: 76 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -13,6 +13,7 @@ import { DbtPowerUserMcpServer } from "./mcp";
1313
import { DbtPowerUserActionsCenter } from "./quickpick";
1414
import { StatusBars } from "./statusbar";
1515
import { TelemetryService } from "./telemetry";
16+
import { probeDbtCoreVersion } from "./telemetry/versionProbes";
1617
import { TreeviewProviders } from "./treeview_provider";
1718
import { ValidationProvider } from "./validation_provider";
1819
import { WebviewViewProviders } from "./webview_provider";
@@ -41,6 +42,13 @@ export class DBTPowerUserExtension implements Disposable {
4142
];
4243

4344
private disposables: Disposable[] = [];
45+
/**
46+
* Monotonic sequence counter for `refreshVersionTelemetryAttributes` so
47+
* a slow earlier invocation can't overwrite attributes written by a
48+
* faster later one. Each refresh captures the seq at start and only
49+
* applies its results if the seq still matches.
50+
*/
51+
private versionRefreshSeq = 0;
4452

4553
constructor(
4654
private dbtProjectContainer: DBTProjectContainer,
@@ -99,6 +107,22 @@ export class DBTPowerUserExtension implements Disposable {
99107
await this.dbtProjectContainer.detectDBT();
100108
await this.dbtProjectContainer.initializeDBTProjects();
101109
await this.statusBars.initialize();
110+
111+
// Enrich every telemetry event with the active Python interpreter version
112+
// and dbt-core dist version. Without these dimensions, App Insights can't
113+
// split error clusters by Python or dbt-core version — e.g. we can't
114+
// tell whether a `pythonBridgeInitPythonError "mashumaro
115+
// UnserializableField"` is a Python 3.13 + mashumaro 3.14 incompat or
116+
// something else. Both probes are best-effort: failure → no
117+
// customAttribute set rather than blocking activation. Re-runs on
118+
// interpreter change so the dimensions track the user's selection.
119+
void this.refreshVersionTelemetryAttributes();
120+
const pythonEnv = this.dbtProjectContainer.getPythonEnvironment();
121+
this.disposables.push(
122+
pythonEnv.onPythonEnvironmentChanged(() => {
123+
void this.refreshVersionTelemetryAttributes();
124+
}),
125+
);
102126
// Ask to reload the window if the dbt integration changes
103127
const dbtIntegration = workspace
104128
.getConfiguration("dbt")
@@ -121,4 +145,56 @@ export class DBTPowerUserExtension implements Disposable {
121145
this.telemetry.sendTelemetryError("extensionActivationError", error);
122146
}
123147
}
148+
149+
/**
150+
* Populate `pythonVersion` and `dbtCoreVersion` customAttributes on the
151+
* telemetry service so every event from this point forward carries them.
152+
* Best-effort: if either probe fails (interpreter missing, dbt-core not
153+
* installed in this venv, probe timeout), the corresponding attribute is
154+
* **cleared** rather than left at a stale value from the previous
155+
* interpreter. Idempotent — wired both at activation and from the
156+
* `onPythonEnvironmentChanged` listener.
157+
*
158+
* Sequence-guarded: rapid interpreter switches can fire two refreshes
159+
* concurrently. A slower earlier probe finishing last would otherwise
160+
* overwrite a faster later probe's results. We capture the
161+
* `versionRefreshSeq` at entry and bail before any write if a newer
162+
* refresh has bumped the counter.
163+
*/
164+
private async refreshVersionTelemetryAttributes(): Promise<void> {
165+
const seq = ++this.versionRefreshSeq;
166+
try {
167+
const pythonEnv = this.dbtProjectContainer.getPythonEnvironment();
168+
const pythonVersion = pythonEnv.pythonVersion;
169+
if (seq !== this.versionRefreshSeq) {
170+
return;
171+
}
172+
if (pythonVersion) {
173+
this.telemetry.setTelemetryCustomAttribute(
174+
"pythonVersion",
175+
pythonVersion,
176+
);
177+
} else {
178+
this.telemetry.clearTelemetryCustomAttribute("pythonVersion");
179+
}
180+
const pythonPath = pythonEnv.pythonPath;
181+
const dbtCoreVersion = pythonPath
182+
? await probeDbtCoreVersion(pythonPath)
183+
: undefined;
184+
if (seq !== this.versionRefreshSeq) {
185+
return;
186+
}
187+
if (dbtCoreVersion) {
188+
this.telemetry.setTelemetryCustomAttribute(
189+
"dbtCoreVersion",
190+
dbtCoreVersion,
191+
);
192+
} else {
193+
this.telemetry.clearTelemetryCustomAttribute("dbtCoreVersion");
194+
}
195+
} catch {
196+
// Telemetry-enrichment failures must never block activation or
197+
// surface as an error — by design these dimensions are best-effort.
198+
}
199+
}
124200
}

src/telemetry/index.ts

Lines changed: 12 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -16,6 +16,18 @@ export class TelemetryService implements vscode.Disposable {
1616
this.customAttributes[key] = value;
1717
}
1818

19+
/**
20+
* Remove a previously-set custom attribute so it stops appearing on
21+
* subsequent telemetry events. Use when the dimension no longer applies
22+
* — e.g. the user switched Python interpreters and we couldn't probe a
23+
* fresh value, so the previous interpreter's `pythonVersion` /
24+
* `dbtCoreVersion` would otherwise carry over and corrupt dimensioning
25+
* for events from the new interpreter.
26+
*/
27+
clearTelemetryCustomAttribute(key: string) {
28+
delete this.customAttributes[key];
29+
}
30+
1931
startTelemetryEvent(
2032
eventName: string,
2133
properties?: { [key: string]: string },

src/telemetry/versionProbes.ts

Lines changed: 99 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,99 @@
1+
/**
2+
* Best-effort probes for the user's Python interpreter version and dbt-core
3+
* distribution version. Both feed `TelemetryService.setTelemetryCustomAttribute`
4+
* so every telemetry event from the session carries them as `pythonVersion`
5+
* and `dbtCoreVersion` customDimensions.
6+
*
7+
* Production telemetry today carries `common.os` / `common.nodeArch` /
8+
* `common.extversion` etc. but **not** the Python interpreter version or the
9+
* installed dbt-core version. That blindspot is what motivated the version
10+
* suffix discussion on PR #96 — without these dimensions, App Insights can't
11+
* split error clusters by Python or dbt-core version, and we can't tell
12+
* whether `pythonBridgeInitPythonError "mashumaro UnserializableField"` is
13+
* a Python 3.13 + mashumaro 3.14 incompatibility or something else.
14+
*/
15+
import * as childProcess from "child_process";
16+
17+
const PROBE_TIMEOUT_MS = 5_000;
18+
19+
/**
20+
* Injectable spawn for tests — defaulted to the real `child_process.spawn`.
21+
* `import * as childProcess` produces ESM-style bindings that resist
22+
* `jest.spyOn` / `jest.mock` redefinition under ts-jest, so we accept the
23+
* spawner as a parameter and let tests pass a stub directly.
24+
*/
25+
export type SpawnFn = (
26+
command: string,
27+
args: string[],
28+
options: childProcess.SpawnOptions,
29+
) => childProcess.ChildProcess;
30+
31+
/**
32+
* Spawn the user's Python interpreter to read dbt-core's distribution version
33+
* via `importlib.metadata`. Reads dist-info directly so it survives even when
34+
* dbt's own import chain is broken — exactly the failure mode our wrapper at
35+
* the top of `dbt_core_integration.py` is built around. Returns `undefined`
36+
* when:
37+
* - the spawn fails (interpreter missing / permission error)
38+
* - dbt-core isn't installed in this Python env
39+
* - the probe doesn't finish within {@link PROBE_TIMEOUT_MS}
40+
*
41+
* Best-effort by design — the caller treats `undefined` as "skip the
42+
* customAttribute" rather than logging an error.
43+
*/
44+
export function probeDbtCoreVersion(
45+
pythonPath: string,
46+
spawn: SpawnFn = childProcess.spawn,
47+
): Promise<string | undefined> {
48+
return new Promise((resolve) => {
49+
const probeScript =
50+
"from importlib.metadata import version, PackageNotFoundError\n" +
51+
"try:\n" +
52+
" print(version('dbt-core'))\n" +
53+
"except PackageNotFoundError:\n" +
54+
" pass\n";
55+
56+
let proc: childProcess.ChildProcess;
57+
try {
58+
proc = spawn(pythonPath, ["-c", probeScript], {
59+
stdio: ["ignore", "pipe", "pipe"],
60+
});
61+
} catch {
62+
// spawn synchronously throws on a missing executable on some platforms
63+
resolve(undefined);
64+
return;
65+
}
66+
67+
let stdout = "";
68+
proc.stdout?.on("data", (chunk: Buffer) => {
69+
stdout += chunk.toString("utf8");
70+
});
71+
72+
let settled = false;
73+
const settle = (value: string | undefined) => {
74+
if (settled) {
75+
return;
76+
}
77+
settled = true;
78+
// Cancel the watchdog so it doesn't keep the event loop alive after
79+
// an early close/error settlement — without this, every successful
80+
// probe leaves a 5s timer pending and rapid interpreter switches
81+
// pile them up.
82+
clearTimeout(timeoutId);
83+
try {
84+
proc.kill();
85+
} catch {
86+
// already exited
87+
}
88+
resolve(value);
89+
};
90+
91+
proc.on("close", (code) => {
92+
const trimmed = stdout.trim();
93+
settle(code === 0 && trimmed.length > 0 ? trimmed : undefined);
94+
});
95+
proc.on("error", () => settle(undefined));
96+
97+
const timeoutId = setTimeout(() => settle(undefined), PROBE_TIMEOUT_MS);
98+
});
99+
}
Lines changed: 117 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,117 @@
1+
/**
2+
* Unit tests for the dbt-core version probe used by
3+
* `DBTPowerUserExtension.refreshVersionTelemetryAttributes` to populate the
4+
* `dbtCoreVersion` customAttribute on every telemetry event.
5+
*
6+
* Covers the four outcomes the probe needs to distinguish: success (exit 0
7+
* with a non-empty version line on stdout), unrecognised dist (exit 0 with
8+
* empty stdout), spawn failure / non-zero exit, and timeout. Each maps to
9+
* either a returned version string or `undefined` (best-effort skip).
10+
*
11+
* Uses dependency injection on the spawn function (`SpawnFn` parameter)
12+
* rather than mocking `child_process` — `import * as childProcess` produces
13+
* ESM-style bindings that resist redefinition under ts-jest, so the test
14+
* passes its own spawner directly.
15+
*/
16+
import { describe, expect, it, jest } from "@jest/globals";
17+
import { ChildProcess } from "child_process";
18+
import { EventEmitter } from "events";
19+
20+
import { probeDbtCoreVersion, SpawnFn } from "../../telemetry/versionProbes";
21+
22+
interface FakeProcOptions {
23+
exitCode?: number | null;
24+
stdoutChunks?: string[];
25+
emitError?: Error;
26+
closeDelayMs?: number;
27+
}
28+
29+
function makeFakeProc(opts: FakeProcOptions = {}): ChildProcess {
30+
const proc = new EventEmitter() as unknown as ChildProcess;
31+
// Install null-stream stdout/stderr that the probe's optional-chained
32+
// listeners can attach to.
33+
(proc as any).stdout = new EventEmitter();
34+
(proc as any).stderr = new EventEmitter();
35+
36+
const eventTimer = setTimeout(() => {
37+
if (opts.emitError) {
38+
proc.emit("error", opts.emitError);
39+
return;
40+
}
41+
for (const chunk of opts.stdoutChunks ?? []) {
42+
(proc as any).stdout.emit("data", Buffer.from(chunk, "utf8"));
43+
}
44+
proc.emit("close", opts.exitCode ?? 0);
45+
}, opts.closeDelayMs ?? 0);
46+
47+
// The probe under test calls `proc.kill()` when it times out — make sure
48+
// the fake's inner timer is cleared too so jest doesn't hang waiting on
49+
// the still-scheduled `setTimeout(...60_000)` in the timeout-path test.
50+
(proc as any).kill = jest.fn(() => {
51+
clearTimeout(eventTimer);
52+
});
53+
54+
return proc;
55+
}
56+
57+
describe("probeDbtCoreVersion", () => {
58+
it("returns the trimmed version string when Python prints it on exit 0", async () => {
59+
const spawnSpy = jest.fn(() =>
60+
makeFakeProc({ exitCode: 0, stdoutChunks: ["1.10.20\n"] }),
61+
) as unknown as SpawnFn;
62+
const result = await probeDbtCoreVersion("/usr/bin/python3", spawnSpy);
63+
expect(result).toBe("1.10.20");
64+
// Argv check: probe script must use importlib.metadata so it works even
65+
// when dbt-core's import chain is broken (the bug we're targeting).
66+
expect(spawnSpy as unknown as jest.Mock).toHaveBeenCalledWith(
67+
"/usr/bin/python3",
68+
["-c", expect.stringContaining("from importlib.metadata import version")],
69+
expect.any(Object),
70+
);
71+
});
72+
73+
it("returns undefined when stdout is empty (PackageNotFoundError swallowed by the probe script)", async () => {
74+
const spawnSpy = jest.fn(() =>
75+
makeFakeProc({ exitCode: 0, stdoutChunks: [] }),
76+
) as unknown as SpawnFn;
77+
const result = await probeDbtCoreVersion("/usr/bin/python3", spawnSpy);
78+
expect(result).toBeUndefined();
79+
});
80+
81+
it("returns undefined on non-zero exit (probe script crashed)", async () => {
82+
const spawnSpy = jest.fn(() =>
83+
makeFakeProc({ exitCode: 2, stdoutChunks: ["something\n"] }),
84+
) as unknown as SpawnFn;
85+
const result = await probeDbtCoreVersion("/usr/bin/python3", spawnSpy);
86+
expect(result).toBeUndefined();
87+
});
88+
89+
it("returns undefined when spawn emits an error event (interpreter missing)", async () => {
90+
const spawnSpy = jest.fn(() =>
91+
makeFakeProc({ emitError: new Error("ENOENT: no such file") }),
92+
) as unknown as SpawnFn;
93+
const result = await probeDbtCoreVersion("/nonexistent/python", spawnSpy);
94+
expect(result).toBeUndefined();
95+
});
96+
97+
it("returns undefined when spawn synchronously throws", async () => {
98+
const spawnSpy = jest.fn(() => {
99+
throw new Error("EACCES");
100+
}) as unknown as SpawnFn;
101+
const result = await probeDbtCoreVersion("/etc/passwd", spawnSpy);
102+
expect(result).toBeUndefined();
103+
});
104+
105+
it("returns undefined and kills the process if the probe runs longer than the timeout", async () => {
106+
// closeDelayMs is far past the 5s timeout; the timeout fires first.
107+
const proc = makeFakeProc({
108+
exitCode: 0,
109+
stdoutChunks: ["never delivered\n"],
110+
closeDelayMs: 60_000,
111+
});
112+
const spawnSpy = jest.fn(() => proc) as unknown as SpawnFn;
113+
const result = await probeDbtCoreVersion("/usr/bin/python3", spawnSpy);
114+
expect(result).toBeUndefined();
115+
expect((proc as any).kill).toHaveBeenCalled();
116+
}, 10_000);
117+
});

0 commit comments

Comments
 (0)