Skip to content

Commit 7a2ff66

Browse files
committed
Capture privacy-scoped Docker startup failures after setup handoff
1 parent 5cfc6d1 commit 7a2ff66

10 files changed

Lines changed: 284 additions & 10 deletions

File tree

‎CHANGELOG.md‎

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -8,7 +8,7 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0
88
## [Unreleased]
99

1010
### Added
11-
- Added privacy-scoped setup wizard funnel telemetry with deployment identity handoff, Node.js 20.20.0 support, and cross-platform end-to-end test coverage. [#1653](https://github.com/sourcebot-dev/sourcebot/pull/1653)
11+
- Added privacy-scoped setup wizard funnel and Docker startup-failure telemetry with deployment identity handoff, Node.js 20.20.0 support, and cross-platform end-to-end test coverage. [#1653](https://github.com/sourcebot-dev/sourcebot/pull/1653)
1212

1313
## [5.1.13] - 2026-09-12
1414

Lines changed: 55 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,55 @@
1+
import { stripVTControlCharacters } from 'node:util';
2+
import type { Events } from './telemetryEvents.js';
3+
4+
type Reason = Events['start_failed']['failureReason'];
5+
6+
// Docker exposes an exit status, not structured error reasons, for compose up.
7+
// Recognize only specific CLI/daemon diagnostics locally. Never serialize output,
8+
// captures, paths, image names, container names or IDs into an event.
9+
export class DockerStartFailure {
10+
private pending = '';
11+
private detected: Reason = 'unknown';
12+
13+
write(chunk: Buffer): void {
14+
// Bound retained output even for a long-running foreground Compose process.
15+
const lines = (this.pending + chunk.toString()).split(/[\r\n]/);
16+
this.pending = (lines.pop() ?? '').slice(-8192);
17+
for (const line of lines) {
18+
this.classify(line.slice(-8192));
19+
}
20+
}
21+
22+
reason(): Reason {
23+
this.classify(this.pending);
24+
this.pending = '';
25+
return this.detected;
26+
}
27+
28+
private classify(raw: string): void {
29+
if (this.detected !== 'unknown') {
30+
return;
31+
}
32+
const line = stripVTControlCharacters(raw).trim();
33+
// Attached application logs are not Docker diagnostics.
34+
if (line.includes(' | ')) {
35+
return;
36+
}
37+
const daemon = /^Error response from daemon:/i.test(line);
38+
if (daemon && /container name .+ is already in use by container/i.test(line)) {
39+
this.detected = 'container_name_conflict';
40+
} else if (daemon && /port is already allocated|address already in use/i.test(line)) {
41+
this.detected = 'port_conflict';
42+
} else if (
43+
/^(?:Error response from daemon:|unable to get image|pull access denied|failed to resolve reference)/i.test(line) &&
44+
/pull access denied|manifest unknown|manifest for .+ not found|failed to resolve reference|no matching manifest|toomanyrequests|unauthorized: authentication required/i.test(line)
45+
) {
46+
this.detected = 'image_pull_failed';
47+
} else if (daemon && /invalid mount config|mounts denied|error while creating mount source path|invalid volume specification/i.test(line)) {
48+
this.detected = 'mount_failed';
49+
} else if (/^(?:Cannot connect to the Docker daemon|error during connect:|permission denied while trying to connect to the Docker daemon|docker: ['"]?compose['"]? is not a docker command)/i.test(line)) {
50+
this.detected = 'docker_unavailable';
51+
} else if (/^(?:validating .+:|no configuration file provided:|yaml: line \d+:|services\..+:|service .+ refers to undefined (?:volume|network) .+: invalid compose project)/i.test(line)) {
52+
this.detected = 'compose_configuration';
53+
}
54+
}
55+
}

‎packages/setupWizard/src/index.ts‎

Lines changed: 25 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -15,6 +15,7 @@ import {
1515
dockerOutcome,
1616
} from './telemetrySummary.js';
1717
import { Docker } from './docker.js';
18+
import { DockerStartFailure } from './dockerStartFailure.js';
1819
import type { CodeSourceSummary, Events } from './telemetryEvents.js';
1920
import net from 'node:net';
2021
import { existsSync, mkdirSync, readFileSync, writeFileSync } from 'fs';
@@ -891,7 +892,9 @@ async function main() {
891892
deploymentIdentityAction: deploymentIdentity.action,
892893
totalDurationMs: 0,
893894
};
894-
const complete = () => lifecycle.complete({ ...completion, totalDurationMs: lifecycle.telemetry.elapsed() });
895+
const complete = (keepTelemetryOpen = false) => lifecycle.complete(
896+
{ ...completion, totalDurationMs: lifecycle.telemetry.elapsed() }, keepTelemetryOpen,
897+
);
895898
if (downloadedCompose && !leftDeploymentRunning) {
896899
const startNow = await confirm({
897900
message: hasPortConflicts
@@ -910,10 +913,13 @@ async function main() {
910913
const readiness = new AbortController();
911914
const releaseReadiness = lifecycle.own(() => readiness.abort());
912915
let spawned = false;
916+
const startFailure = new DockerStartFailure();
913917
await new Promise<void>((resolve) => {
914918
const child = lifecycle.child(
915-
spawn('docker', ['compose', 'up'], { stdio: 'inherit', detached: process.platform !== 'win32' }),
919+
spawn('docker', ['compose', 'up'], { stdio: ['inherit', 'inherit', 'pipe'], detached: process.platform !== 'win32' }),
916920
);
921+
child.stderr?.pipe(process.stderr, { end: false });
922+
child.stderr?.on('data', (chunk: Buffer) => startFailure.write(chunk));
917923
child.once('spawn', () => {
918924
if (lifecycle.interrupted) {
919925
child.kill();
@@ -922,19 +928,34 @@ async function main() {
922928
spawned = true;
923929
completion.sourcebotStartOutcome = 'spawned';
924930
completion.completionMode = 'sourcebot_start_spawned';
925-
void complete();
931+
// Complete the setup handoff now, but keep diagnostics available
932+
// until Compose exits or the user interrupts it.
933+
void complete(true);
926934
void openBrowserWhenReady(
927935
SOURCEBOT_URL,
928936
AbortSignal.any([lifecycle.signal, readiness.signal]),
929937
).catch(() => {});
930938
});
931-
child.once('close', () => {
939+
child.once('close', (code, signal) => {
932940
readiness.abort();
941+
if (spawned && code !== 0 && signal !== 'SIGINT' && signal !== 'SIGTERM') {
942+
const reason = startFailure.reason();
943+
lifecycle.startFailed({
944+
failurePhase: 'compose_exit',
945+
failureCategory: reason === 'docker_unavailable' ? 'docker_unavailable' : 'docker_command',
946+
failureReason: reason,
947+
});
948+
}
933949
resolve();
934950
});
935951
child.once('error', (error: NodeJS.ErrnoException) => {
936952
readiness.abort();
937953
if (!lifecycle.interrupted) {
954+
lifecycle.startFailed({
955+
failurePhase: 'spawn',
956+
failureCategory: error.code === 'ENOENT' || error.code === 'EACCES' ? 'docker_unavailable' : 'process_spawn',
957+
failureReason: error.code === 'ENOENT' || error.code === 'EACCES' ? 'docker_unavailable' : 'unknown',
958+
});
938959
lifecycle.fail(
939960
error.code === 'ENOENT' || error.code === 'EACCES' ? 'docker_unavailable' : 'process_spawn',
940961
true,

‎packages/setupWizard/src/lifecycle.ts‎

Lines changed: 12 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -18,6 +18,7 @@ export class Lifecycle {
1818
terminal?: 'completed' | 'cancelled' | 'failed';
1919
interrupted = false;
2020
private installed = false;
21+
private startFailureCaptured = false;
2122
constructor(readonly telemetry = new Telemetry()) {}
2223
get signal(): AbortSignal {
2324
return this.controller.signal;
@@ -89,13 +90,22 @@ export class Lifecycle {
8990
recoverable,
9091
});
9192
}
92-
async complete(properties: Events['completed']): Promise<void> {
93+
startFailed(properties: Events['start_failed']): void {
94+
if (this.interrupted || this.startFailureCaptured || (this.terminal && this.terminal !== 'completed')) {
95+
return;
96+
}
97+
this.startFailureCaptured = true;
98+
this.telemetry.capture('start_failed', properties);
99+
}
100+
async complete(properties: Events['completed'], keepTelemetryOpen = false): Promise<void> {
93101
if (this.terminal || this.interrupted) {
94102
return;
95103
}
96104
this.terminal = 'completed';
97105
this.telemetry.capture('completed', properties);
98-
await this.telemetry.shutdown();
106+
if (!keepTelemetryOpen) {
107+
await this.telemetry.shutdown();
108+
}
99109
}
100110
async decline(reason: Events['cancelled']['reason']): Promise<void> {
101111
if (!this.terminal) {

‎packages/setupWizard/src/telemetryEvents.ts‎

Lines changed: 13 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -310,6 +310,19 @@ export const eventSchemas = {
310310
),
311311
},
312312
failed: { stage, failureCategory: category, recoverable: boolean },
313+
start_failed: {
314+
failurePhase: choice('spawn', 'compose_exit'),
315+
failureCategory: choice('docker_unavailable', 'process_spawn', 'docker_command'),
316+
failureReason: choice(
317+
'container_name_conflict',
318+
'port_conflict',
319+
'image_pull_failed',
320+
'mount_failed',
321+
'compose_configuration',
322+
'docker_unavailable',
323+
'unknown',
324+
),
325+
},
313326
};
314327
export type EventName = keyof typeof eventSchemas;
315328
export type Events = { [K in EventName]: Fields<(typeof eventSchemas)[K]> };

‎packages/setupWizard/tests/approvedSchema.json‎

Lines changed: 15 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -568,6 +568,21 @@
568568
]
569569
}
570570
},
571+
"start_failed": {
572+
"failurePhase": { "enum": ["spawn", "compose_exit"] },
573+
"failureCategory": { "enum": ["docker_unavailable", "process_spawn", "docker_command"] },
574+
"failureReason": {
575+
"enum": [
576+
"container_name_conflict",
577+
"port_conflict",
578+
"image_pull_failed",
579+
"mount_failed",
580+
"compose_configuration",
581+
"docker_unavailable",
582+
"unknown"
583+
]
584+
}
585+
},
571586
"failed": {
572587
"stage": {
573588
"enum": [

‎packages/setupWizard/tests/e2e/docker.test.mjs‎

Lines changed: 57 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -93,9 +93,66 @@ test('failed spawn offers manual steps and completes after recoverable failures'
9393
});
9494
assert.equal(p(result, 'completed').sourcebotStartOutcome, 'spawn_failed');
9595
assert.equal(p(result, 'completed').completionMode, 'sourcebot_start_failed');
96+
assert.equal(result.events.filter(e => e.event === 'setup_sourcebot_start_failed').length, 1);
97+
assert.deepEqual(
98+
['failurePhase', 'failureCategory', 'failureReason'].map(key => p(result, 'start_failed')[key]),
99+
['spawn', 'docker_unavailable', 'docker_unavailable'],
100+
);
96101
assert.ok(result.events.filter(e => e.event === 'setup_sourcebot_failed').every(e => e.properties.recoverable));
97102
});
98103

104+
for (const [reason, diagnostic] of [
105+
['container_name_conflict', 'Error response from daemon: Conflict. The container name "/canary-sensitive-container" is already in use by container "canary-sensitive-id".'],
106+
['port_conflict', 'Error response from daemon: driver failed programming external connectivity: Bind for canary-sensitive-address failed: port is already allocated'],
107+
['image_pull_failed', 'Error response from daemon: pull access denied for canary-sensitive-image, repository does not exist or may require docker login'],
108+
['mount_failed', 'Error response from daemon: invalid mount config for type "bind": bind source path does not exist: canary-sensitive-path'],
109+
['compose_configuration', 'validating canary-sensitive-path: services.sourcebot Additional property canary-sensitive is not allowed'],
110+
['docker_unavailable', 'Cannot connect to the Docker daemon at canary-sensitive-socket. Is the docker daemon running?'],
111+
['unknown', 'canary-sensitive-unrecognized-error'],
112+
['unknown', 'canary-sensitive-app | Error response from daemon: pull access denied for canary-sensitive-image'],
113+
]) {
114+
test(`post-handoff start failure: ${reason} (${diagnostic.slice(0, 24)})`, async () => {
115+
const result = await scenario(packed, { docker: { start: { stderrChunks: [diagnostic.slice(0, 17), diagnostic.slice(17)], delayMs: 1100 } } }, async d => {
116+
await initial(d);
117+
await d.answer('Start Sourcebot now?', 'y');
118+
await d.wait(diagnostic);
119+
});
120+
const failures = result.events.filter(e => e.event === 'setup_sourcebot_start_failed');
121+
assert.equal(failures.length, 1);
122+
assert.equal(failures[0].properties.failurePhase, 'compose_exit');
123+
assert.equal(failures[0].properties.failureReason, reason);
124+
assert.equal(failures[0].properties.failureCategory, reason === 'docker_unavailable' ? 'docker_unavailable' : 'docker_command');
125+
const completed = result.events.find(e => e.event === 'setup_sourcebot_completed');
126+
assert.ok(result.events.indexOf(completed) < result.events.indexOf(failures[0]));
127+
assert.equal(failures[0].distinct_id, completed.distinct_id);
128+
assert.equal(result.events.filter(e => e.event === 'setup_sourcebot_completed').length, 1);
129+
assert.equal(result.events.some(e => e.event === 'setup_sourcebot_cancelled'), false);
130+
assert.equal(result.exitCode, 0, 'Telemetry must not change existing CLI exit behavior');
131+
});
132+
}
133+
134+
for (const termination of [{ exitCode: 0 }, { signal: 'SIGINT' }, { signal: 'SIGTERM' }]) {
135+
test(`normal Compose termination is not a start failure: ${JSON.stringify(termination)}`, { skip: process.platform === 'win32' && !!termination.signal }, async () => {
136+
const result = await scenario(packed, { docker: { start: { ...termination, stderrChunks: ['Error response from daemon: pull access denied for canary-sensitive-image\n'] } } }, async d => {
137+
await initial(d);
138+
await d.answer('Start Sourcebot now?', 'y');
139+
});
140+
assert.equal(result.events.some(e => e.event === 'setup_sourcebot_start_failed'), false);
141+
assert.equal(p(result, 'completed').sourcebotStartOutcome, 'spawned');
142+
});
143+
}
144+
145+
test('start failure with unavailable PostHog still exits and retains generated files', async () => {
146+
const began = Date.now();
147+
const result = await scenario(packed, { telemetry: 'stall', docker: { start: { stderrChunks: ['canary-sensitive-error'] } } }, async d => {
148+
await initial(d);
149+
await d.answer('Start Sourcebot now?', 'y');
150+
});
151+
assert.equal(result.exitCode, 0);
152+
assert.ok(Date.now() - began < 7000);
153+
assert.deepEqual(Object.keys(result.files).sort(), ['.env', 'config.json', 'docker-compose.yml']);
154+
});
155+
99156
for (const stage of ['fetch', 'docker', 'after_failures']) {
100157
test(`Ctrl+C during ${stage} cancels outstanding work`, async () => {
101158
const result = await scenario(packed, {

‎packages/setupWizard/tests/e2e/fakeDocker.cjs‎

Lines changed: 15 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -4,11 +4,23 @@ fs.appendFileSync(process.env.TEST_DOCKER_LOG, JSON.stringify(args) + '\n');
44
const state = JSON.parse(fs.readFileSync(process.env.TEST_DOCKER_STATE, 'utf8'));
55
const command = args.slice(0, 2).join(' ');
66
fs.appendFileSync(process.env.TEST_DOCKER_PIDS, String(process.pid) + '\n');
7-
if (state.fail?.includes(command)) {
7+
if (command === 'compose up' && state.start) {
8+
let index = 0;
9+
const write = () => {
10+
if (index < (state.start.stderrChunks ?? []).length) {
11+
process.stderr.write(state.start.stderrChunks[index++]);
12+
setTimeout(write, 10);
13+
} else if (state.start.signal) {
14+
process.kill(process.pid, state.start.signal);
15+
} else {
16+
process.exit(state.start.exitCode ?? 1);
17+
}
18+
};
19+
setTimeout(write, state.start.delayMs ?? 0);
20+
} else if (state.fail?.includes(command)) {
821
console.error('canary-sensitive-error');
922
process.exit(1);
10-
}
11-
if (state.stall?.includes(command)) {
23+
} else if (state.stall?.includes(command)) {
1224
if (state.descendant) {
1325
const child = require('node:child_process').spawn(process.execPath, ['-e', "process.on('SIGINT', () => {}); setInterval(() => {}, 1000)"], { stdio: 'ignore' });
1426
fs.appendFileSync(process.env.TEST_DOCKER_PIDS, String(child.pid) + '\n');

‎packages/setupWizard/tests/e2e/runtime.test.mjs‎

Lines changed: 49 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -1,13 +1,62 @@
11
import assert from 'node:assert/strict';
22
import { test } from 'node:test';
33
import { randomUUID } from 'node:crypto';
4+
import { homedir } from 'node:os';
45
import { execFileSync } from 'node:child_process';
56
import { writeFileSync, mkdirSync } from 'node:fs';
67
import { join, resolve } from 'node:path';
78
import { fileURLToPath } from 'node:url';
89
import { artifact, scenario, minimal } from './harness.mjs';
910
import { INSTALL_ID_PATTERN } from '../../dist/telemetry.js';
1011

12+
test('real Docker name conflict emits a private diagnostic after setup completion', async () => {
13+
const packed = artifact();
14+
const docker = execFileSync('which', ['docker'], { encoding: 'utf8' }).trim();
15+
const image = process.env.SETUP_TEST_SOURCEBOT_IMAGE ?? 'docker.sourcebot.dev/sourcebot-dev/sourcebot:latest';
16+
const name = `setup-start-conflict-${randomUUID()}`;
17+
const project = `setup-start-${randomUUID()}`;
18+
let created = false;
19+
try {
20+
execFileSync(docker, ['create', '--name', name, '--label', `setup-start-test=${project}`, image], { stdio: 'pipe', timeout: 45000 });
21+
created = true;
22+
const host = execFileSync(docker, ['context', 'inspect', '--format', '{{.Endpoints.docker.Host}}'], { encoding: 'utf8' }).trim();
23+
const result = await scenario(packed, {
24+
realDocker: docker,
25+
compose: `services:\n sourcebot:\n image: ${image}\n container_name: ${name}\n pull_policy: never\n`,
26+
sensitiveValues: [name, project],
27+
assertLauncherHome(paths) {
28+
// Docker Desktop creates these empty parent directories itself.
29+
// Still reject files or any wizard-owned per-user state.
30+
const dockerDirectories = process.platform === 'darwin'
31+
? ['Library', 'Library/Containers', 'Library/Containers/com.docker.docker', 'Library/Containers/com.docker.docker/Data']
32+
: [];
33+
assert.deepEqual(paths.filter(path => !dockerDirectories.includes(path)), []);
34+
},
35+
environment: { COMPOSE_PROJECT_NAME: project, DOCKER_HOST: host, DOCKER_CONFIG: process.env.DOCKER_CONFIG ?? join(homedir(), '.docker') },
36+
async cleanupDeployment({ setup }) {
37+
execFileSync(docker, ['compose', '-p', project, 'down'], { cwd: setup, stdio: 'pipe', timeout: 45000 });
38+
},
39+
}, async d => {
40+
await minimal(d);
41+
await d.answer('Download docker-compose.yml?', 'y');
42+
await d.answer('Start Sourcebot now?', 'y');
43+
await d.wait('is already in use by container');
44+
});
45+
const failure = result.events.filter(e => e.event === 'setup_sourcebot_start_failed');
46+
assert.equal(failure.length, 1);
47+
assert.equal(failure[0].properties.failureReason, 'container_name_conflict');
48+
assert.equal(failure[0].properties.failurePhase, 'compose_exit');
49+
assert.equal(result.events.at(-1).event, 'setup_sourcebot_start_failed');
50+
assert.ok(result.events.some(e => e.event === 'setup_sourcebot_completed'));
51+
} finally {
52+
try {
53+
if (created) execFileSync(docker, ['rm', '-v', name], { stdio: 'pipe', timeout: 45000 });
54+
} finally {
55+
packed.cleanup();
56+
}
57+
}
58+
});
59+
1160
test('real Sourcebot containers: packed wizard identity survives first boot, restart, upgrade and opt-out', async () => {
1261
const packed = artifact();
1362
const image = process.env.SETUP_TEST_SOURCEBOT_IMAGE ?? 'docker.sourcebot.dev/sourcebot-dev/sourcebot:latest';

0 commit comments

Comments
 (0)