History

[codex] Redact SSH tunnel diagnostics (#3412)

Julius Marminge committed 4 months ago

Commit 4e1cdad1 parent 1d53e193 files · +178 −36Browse files

Unified · Split

3 files
  1. packages/ssh/src/command.ts +4 −1
  2. packages/ssh/src/tunnel.test.ts +122 −11
  3. packages/ssh/src/tunnel.ts +52 −24
packages/ssh/src/command.ts+4−1
@@ -350,7 +350,10 @@ export const resolveSshTarget = Effect.fn("ssh/command.resolveSshTarget")(functi · 349 unmodified lines
350350 Effect.logDebug("ssh.target.resolve.succeeded", sshTargetLogFields(target)),
351351 ),
352352 Effect.catch((cause) =>
353− Effect.logDebug("ssh.target.resolve.fallback", { alias: trimmedAlias, cause }).pipe(
353+ Effect.logDebug("ssh.target.resolve.fallback", {
354+ alias: trimmedAlias,
355+ failureTag: cause._tag,
356+ }).pipe(
354357 Effect.as({
355358 alias: trimmedAlias,
356359 hostname: trimmedAlias,
packages/ssh/src/tunnel.test.ts+122−11
@@ -5,12 +5,14 @@ import * as Duration from "effect/Duration"; · 4 unmodified lines
55 import * as Effect from "effect/Effect";
66 import * as Fiber from "effect/Fiber";
77 import * as Layer from "effect/Layer";
8+import * as Logger from "effect/Logger";
89 import * as PlatformError from "effect/PlatformError";
910 import * as Result from "effect/Result";
1011 import * as Sink from "effect/Sink";
1112 import * as Stream from "effect/Stream";
1213 import * as TestClock from "effect/testing/TestClock";
1314 import * as HttpClient from "effect/unstable/http/HttpClient";
15+import * as HttpClientError from "effect/unstable/http/HttpClientError";
1416 import * as HttpClientResponse from "effect/unstable/http/HttpClientResponse";
1517 import * as ChildProcess from "effect/unstable/process/ChildProcess";
1618 import * as ChildProcessSpawner from "effect/unstable/process/ChildProcessSpawner";
@@ -21,6 +23,7 @@ import { · 4 unmodified lines
2123 SshHttpBridgeMissingUrlError,
2224 SshHttpBridgeNonLoopbackUrlError,
2325 SshPairingOutputParseError,
26+ SshReadinessProbeError,
2427 SshReadinessProbeTimeoutError,
2528 SshReadinessTimeoutError,
2629 } from "./errors.ts";
@@ -88,6 +91,14 @@ function commandArgs(command: ChildProcess.Command): ReadonlyArray<string> { · 61 unmodified lines
8891 return command._tag === "StandardCommand" ? command.args : [];
8992 }
9093
94+function flattenedLogText(value: unknown): string {
95+ if (typeof value === "string") return value;
96+ if (typeof value !== "object" || value === null) return String(value);
97+ return Object.entries(value)
98+ .flatMap(([key, nested]) => [key, flattenedLogText(nested)])
99+ .join("\n");
100+}
101+
91102 describe("ssh tunnel scripts", () => {
92103 it("builds the remote t3 runner with npx and npm fallbacks", () => {
93104 const script = SshTunnel.buildRemoteT3RunnerScript({ nodeEngineRange: TEST_NODE_ENGINE_RANGE });
@@ -255,13 +266,22 @@ describe("ssh tunnel scripts", () => { · 161 unmodified lines
255266 assert.include(SshTunnel.REMOTE_PICK_PORT_SCRIPT, 'const filePath = process.argv[2] ?? "";');
256267 });
257268
258− it.effect("bounds each HTTP readiness probe so retries cannot hang on one request", () =>
259− Effect.gen(function* () {
269+ it.effect("bounds each HTTP readiness probe so retries cannot hang on one request", () => {
270+ const baseUrl =
271+ "http://ssh-user:ssh-password@127.0.0.1:41773/private/base?token=base-secret#base-fragment";
272+ const path = "/ready/private?credential=request-secret#request-fragment";
273+ const requestUrl = new URL(path, baseUrl).toString();
274+ const capturedLogs: Array<ReadonlyArray<unknown>> = [];
275+ const logger = Logger.make(({ message }) => {
276+ capturedLogs.push(Array.isArray(message) ? message : [message]);
277+ });
278+
279+ return Effect.gen(function* () {
260280 const fiber = yield* Effect.forkChild(
261281 Effect.result(
262282 SshTunnel.waitForHttpReady({
263− baseUrl: "http://127.0.0.1:41773/?token=base-secret#fragment",
264− path: "/ready?credential=request-secret#fragment",
283+ baseUrl,
284+ path,
265285 timeoutMs: 1_000,
266286 intervalMs: 100,
267287 probeTimeoutMs: 250,
@@ -281,8 +301,8 @@ describe("ssh tunnel scripts", () => { · 13 unmodified lines
281301 protocol: "http:",
282302 hostname: "127.0.0.1",
283303 port: "41773",
284− urlLength: 50,
285− pathnameLength: 1,
304+ urlLength: baseUrl.length,
305+ pathnameLength: new TextEncoder().encode(new URL(baseUrl).pathname).length,
286306 hasQuery: true,
287307 hasFragment: true,
288308 });
@@ -290,8 +310,8 @@ describe("ssh tunnel scripts", () => { · 1 unmodified line
290310 protocol: "http:",
291311 hostname: "127.0.0.1",
292312 port: "41773",
293− urlLength: 63,
294− pathnameLength: 6,
313+ urlLength: requestUrl.length,
314+ pathnameLength: new TextEncoder().encode(new URL(requestUrl).pathname).length,
295315 hasQuery: true,
296316 hasFragment: true,
297317 });
@@ -311,13 +331,91 @@ describe("ssh tunnel scripts", () => { · 13 unmodified lines
311331 const probeTimeout = timeoutError.cause as SshReadinessProbeTimeoutError;
312332 assert.equal(probeTimeout.attempt, timeoutError.attempts);
313333 assert.isFalse("cause" in probeTimeout);
334+
335+ const logText = flattenedLogText(capturedLogs);
336+ assert.include(logText, "127.0.0.1");
337+ assert.notInclude(logText, "ssh-user");
338+ assert.notInclude(logText, "ssh-password");
339+ assert.notInclude(logText, "/private/base");
340+ assert.notInclude(logText, "base-secret");
341+ assert.notInclude(logText, "/ready/private");
342+ assert.notInclude(logText, "request-secret");
343+ assert.notInclude(logText, "base-fragment");
344+ assert.notInclude(logText, "request-fragment");
314345 }
315346 }).pipe(
316347 Effect.provide(
317− Layer.merge(TestClock.layer(), Layer.succeed(HttpClient.HttpClient, hangingHttpClient)),
348+ Layer.mergeAll(
349+ TestClock.layer(),
350+ Layer.succeed(HttpClient.HttpClient, hangingHttpClient),
351+ Logger.layer([logger], { mergeWithExisting: false }),
352+ ),
318353 ),
319− ),
320− );
354+ );
355+ });
356+
357+ it.effect("preserves the exact HTTP transport cause without logging request secrets", () => {
358+ const baseUrl =
359+ "http://transport-user:transport-password@127.0.0.1:41773/private?token=transport-secret#fragment";
360+ const transportCause = new Error("socket closed");
361+ const clientErrors: Array<HttpClientError.HttpClientError> = [];
362+ const failingHttpClient = HttpClient.make((request) => {
363+ const error = new HttpClientError.HttpClientError({
364+ reason: new HttpClientError.TransportError({ request, cause: transportCause }),
365+ });
366+ clientErrors.push(error);
367+ return Effect.fail(error);
368+ });
369+ const capturedLogs: Array<ReadonlyArray<unknown>> = [];
370+ const logger = Logger.make(({ message }) => {
371+ capturedLogs.push(Array.isArray(message) ? message : [message]);
372+ });
373+
374+ return Effect.gen(function* () {
375+ const fiber = yield* Effect.forkChild(
376+ Effect.result(
377+ SshTunnel.waitForHttpReady({
378+ baseUrl,
379+ timeoutMs: 300,
380+ intervalMs: 100,
381+ probeTimeoutMs: 250,
382+ }),
383+ ),
384+ );
385+ yield* Effect.yieldNow;
386+ yield* TestClock.adjust(Duration.millis(300));
387+
388+ const result = yield* Fiber.join(fiber);
389+ assert.isTrue(Result.isFailure(result));
390+ if (Result.isFailure(result)) {
391+ assert.instanceOf(result.failure, SshReadinessTimeoutError);
392+ const timeoutError = result.failure as SshReadinessTimeoutError;
393+ assert.instanceOf(timeoutError.cause, SshReadinessProbeError);
394+ const probeError = timeoutError.cause as SshReadinessProbeError;
395+ assert.strictEqual(probeError.cause, clientErrors.at(-1));
396+ assert.strictEqual(
397+ (probeError.cause as HttpClientError.HttpClientError).reason.cause,
398+ transportCause,
399+ );
400+
401+ const logText = flattenedLogText(capturedLogs);
402+ assert.include(logText, "HttpClientError");
403+ assert.include(logText, "TransportError");
404+ assert.notInclude(logText, "transport-user");
405+ assert.notInclude(logText, "transport-password");
406+ assert.notInclude(logText, "/private");
407+ assert.notInclude(logText, "transport-secret");
408+ }
409+ }).pipe(
410+ Effect.provide(
411+ Layer.mergeAll(
412+ TestClock.layer(),
413+ Layer.succeed(HttpClient.HttpClient, failingHttpClient),
414+ Logger.layer([logger], { mergeWithExisting: false }),
415+ ),
416+ ),
417+ );
418+ });
321419
322420 it.effect("preserves forwarded HTTP URL error messages", () =>
323421 Effect.gen(function* () {
@@ -363,6 +461,10 @@ describe("ssh tunnel scripts", () => { · 39 unmodified lines
363461 cause: { type: "string" },
364462 },
365463 );
464+
465+ const cyclicCause: { readonly _tag: string; cause?: unknown } = { _tag: "CyclicCause" };
466+ cyclicCause.cause = cyclicCause;
467+ assert.include(flattenedLogText(SshTunnel.describeReadinessCause(cyclicCause)), "truncated");
366468 });
367469
368470 it("preserves structured readiness attributes in diagnostic output", () => {
@@ -542,6 +644,10 @@ describe("ssh tunnel scripts", () => { · 173 unmodified lines
542644 const spawnedCommands: Array<ReadonlyArray<string>> = [];
543645 let tunnelKillCount = 0;
544646 let stopCommandCount = 0;
647+ const capturedLogs: Array<ReadonlyArray<unknown>> = [];
648+ const logger = Logger.make(({ message }) => {
649+ capturedLogs.push(Array.isArray(message) ? message : [message]);
650+ });
545651 const spawner = ChildProcessSpawner.make((command) =>
546652 Effect.sync(() => {
547653 const args = commandArgs(command);
@@ -568,6 +674,7 @@ describe("ssh tunnel scripts", () => { · 20 unmodified lines
568674 Layer.succeed(NetService.NetService, testNetService),
569675 SshAuth.disabledLayer,
570676 SshTunnel.layer(),
677+ Logger.layer([logger], { mergeWithExisting: false }),
571678 );
572679 const target = {
573680 alias: "devbox",
@@ -590,6 +697,10 @@ describe("ssh tunnel scripts", () => { · 16 unmodified lines
590697
591698 assert.equal(spawnedCommands.filter((args) => args.includes("-N")).length, 2);
592699 assert.equal(tunnelKillCount, 1);
700+
701+ const logText = flattenedLogText(capturedLogs);
702+ assert.include(logText, "httpBaseUrlDiagnostics");
703+ assert.notInclude(logText, "httpBaseUrl\nhttp://");
593704 }).pipe(Effect.provide(layer), Effect.scoped);
594705 });
595706 });
packages/ssh/src/tunnel.ts+52−24
@@ -5,6 +5,8 @@ import type { · 4 unmodified lines
55 import * as NetService from "@t3tools/shared/Net";
66 import { extractJsonObject, fromLenientJson } from "@t3tools/shared/schemaJson";
77 import { satisfiesSemverRange } from "@t3tools/shared/semver";
8+import { getUrlDiagnostics } from "@t3tools/shared/urlDiagnostics";
9+import * as Cause from "effect/Cause";
810 import * as Context from "effect/Context";
911 import * as Deferred from "effect/Deferred";
1012 import * as Duration from "effect/Duration";
@@ -243,7 +245,24 @@ function applyScriptPlaceholders( · 232 unmodified lines
243245 return result;
244246 }
245247
246−export function describeReadinessCause(cause: unknown): unknown {
248+const SSH_FAILURE_DIAGNOSTIC_DEPTH = 6;
249+
250+function describeReadinessCauseAtDepth(cause: unknown, depth: number): unknown {
251+ if (depth >= SSH_FAILURE_DIAGNOSTIC_DEPTH) return { truncated: true };
252+ const describeNested = (nested: unknown) => describeReadinessCauseAtDepth(nested, depth + 1);
253+ if (Cause.isCause(cause)) {
254+ return {
255+ reasons: cause.reasons.map((reason) => {
256+ if (Cause.isFailReason(reason)) {
257+ return { _tag: reason._tag, error: describeNested(reason.error) };
258+ }
259+ if (Cause.isDieReason(reason)) {
260+ return { _tag: reason._tag, defect: describeNested(reason.defect) };
261+ }
262+ return { _tag: reason._tag, fiberId: reason.fiberId };
263+ }),
264+ };
265+ }
247266 if (isSshReadinessError(cause)) {
248267 const { cause: nestedCause, ...attributes } = cause as SshReadinessError & {
249268 readonly cause?: unknown;
@@ -251,13 +270,15 @@ export function describeReadinessCause(cause: unknown): unknown { · 1 unmodified line
251270 return {
252271 ...attributes,
253272 message: cause.message,
254− ...(nestedCause === undefined ? {} : { cause: describeReadinessCause(nestedCause) }),
273+ ...(nestedCause === undefined ? {} : { cause: describeNested(nestedCause) }),
255274 };
256275 }
257276 if (cause instanceof Error) {
277+ const tagged = cause as Error & { readonly _tag?: unknown; readonly reason?: unknown };
258278 return {
259− name: cause.name,
260− ...(cause.cause === undefined ? {} : { cause: describeReadinessCause(cause.cause) }),
279+ ...(typeof tagged._tag === "string" ? { _tag: tagged._tag } : { name: cause.name }),
280+ ...(tagged.reason === undefined ? {} : { reason: describeNested(tagged.reason) }),
281+ ...(cause.cause === undefined ? {} : { cause: describeNested(cause.cause) }),
261282 };
262283 }
263284 if (typeof cause !== "object" || cause === null) {
@@ -267,17 +288,23 @@ export function describeReadinessCause(cause: unknown): unknown { · 3 unmodified lines
267288 const record = cause as Readonly<Record<string, unknown>>;
268289 return {
269290 ...(typeof record._tag === "string" ? { _tag: record._tag } : {}),
270− ...(record.reason === undefined ? {} : { reason: describeReadinessCause(record.reason) }),
271− ...(record.cause === undefined ? {} : { cause: describeReadinessCause(record.cause) }),
291+ ...(record.reason === undefined ? {} : { reason: describeNested(record.reason) }),
292+ ...(record.cause === undefined ? {} : { cause: describeNested(record.cause) }),
272293 };
273294 }
274295
275−function readinessUrlDiagnostics(url: URL, urlLength: number) {
296+export function describeReadinessCause(cause: unknown): unknown {
297+ return describeReadinessCauseAtDepth(cause, 0);
298+}
299+
300+function readinessUrlDiagnostics(input: string) {
301+ const url = new URL(input);
302+ const diagnostics = getUrlDiagnostics(input);
276303 return {
277− protocol: url.protocol,
278− hostname: url.hostname,
304+ protocol: diagnostics.protocol ?? url.protocol,
305+ hostname: diagnostics.hostname ?? url.hostname,
279306 ...(url.port === "" ? {} : { port: url.port }),
280− urlLength,
307+ urlLength: diagnostics.inputLength,
281308 pathnameLength: utf8ByteLength(url.pathname),
282309 hasQuery: url.search !== "",
283310 hasFragment: url.hash !== "",
@@ -900,8 +927,8 @@ export const waitForHttpReady = Effect.fn("ssh/tunnel.waitForHttpReady")(functio · 616 unmodified lines
900927 const baseUrl = new URL(input.baseUrl);
901928 const request = new URL(input.path ?? "/", baseUrl);
902929 const requestUrl = request.toString();
903− const base = readinessUrlDiagnostics(baseUrl, utf8ByteLength(input.baseUrl));
904− const requestDiagnostics = readinessUrlDiagnostics(request, utf8ByteLength(requestUrl));
930+ const base = readinessUrlDiagnostics(input.baseUrl);
931+ const requestDiagnostics = readinessUrlDiagnostics(requestUrl);
905932 const client = yield* HttpClient.HttpClient;
906933 const lastProbeFailure = yield* Ref.make<unknown>(null);
907934 let attempt = 0;
@@ -1088,6 +1115,7 @@ const startSshTunnel = Effect.fn("ssh/tunnel.startSshTunnel")(function* (input: · 180 unmodified lines
10881115 const sshCommand = yield* resolveSshCommand;
10891116 const spawner = yield* ChildProcessSpawner.ChildProcessSpawner;
10901117 const scope = yield* Scope.Scope;
1118+ const httpBaseUrlDiagnostics = getUrlDiagnostics(input.httpBaseUrl);
10911119 yield* Effect.logDebug("ssh.tunnel.spawn.start", {
10921120 ...sshTargetLogFields(input.resolvedTarget),
10931121 command: sshCommand,
@@ -1095,7 +1123,7 @@ const startSshTunnel = Effect.fn("ssh/tunnel.startSshTunnel")(function* (input: · 1 unmodified line
10951123 localPort: input.localPort,
10961124 remotePort: input.remotePort,
10971125 remoteServerKind: input.remoteServerKind,
1098− httpBaseUrl: input.httpBaseUrl,
1126+ httpBaseUrlDiagnostics,
10991127 });
11001128 const child = yield* spawner
11011129 .spawn(
@@ -1128,7 +1156,7 @@ const startSshTunnel = Effect.fn("ssh/tunnel.startSshTunnel")(function* (input: · 26 unmodified lines
11281156 pid: child.pid,
11291157 localPort: input.localPort,
11301158 remotePort: input.remotePort,
1131− httpBaseUrl: input.httpBaseUrl,
1159+ httpBaseUrlDiagnostics,
11321160 });
11331161 const tunnelEntry: SshTunnelEntry = {
11341162 key: input.key,
@@ -1171,7 +1199,7 @@ const startSshTunnel = Effect.fn("ssh/tunnel.startSshTunnel")(function* (input: · 36 unmodified lines
11711199 pid: child.pid,
11721200 localPort: input.localPort,
11731201 remotePort: input.remotePort,
1174− httpBaseUrl: input.httpBaseUrl,
1202+ httpBaseUrlDiagnostics,
11751203 exitCode,
11761204 stderrBytes: utf8ByteLength(stderr),
11771205 }).pipe(Effect.andThen(Effect.fail(error)));
@@ -1192,7 +1220,7 @@ const startSshTunnel = Effect.fn("ssh/tunnel.startSshTunnel")(function* (input: · 14 unmodified lines
11921220 pid: child.pid,
11931221 localPort: input.localPort,
11941222 remotePort: input.remotePort,
1195− httpBaseUrl: input.httpBaseUrl,
1223+ httpBaseUrlDiagnostics,
11961224 }),
11971225 ),
11981226 Effect.tapError((cause) =>
@@ -1220,19 +1248,19 @@ const startSshTunnel = Effect.fn("ssh/tunnel.startSshTunnel")(function* (input: · 21 unmodified lines
12201248 processRunning,
12211249 ...(Exit.isSuccess(processRunningExit)
12221250 ? {}
1223− : { processRunningError: processRunningExit.cause }),
1251+ : { processRunningFailure: describeReadinessCause(processRunningExit.cause) }),
12241252 localPort: input.localPort,
12251253 localPortListening: localPortAvailable === null ? null : !localPortAvailable,
12261254 remotePort: input.remotePort,
1227− httpBaseUrl: input.httpBaseUrl,
1255+ httpBaseUrlDiagnostics,
12281256 ...(Exit.isSuccess(localPortAvailableExit)
12291257 ? {}
1230− : { localPortProbeError: localPortAvailableExit.cause }),
1258+ : { localPortProbeFailure: describeReadinessCause(localPortAvailableExit.cause) }),
12311259 ...(remoteLogTail === null ? {} : { remoteLogTailBytes: utf8ByteLength(remoteLogTail) }),
12321260 ...(Exit.isSuccess(remoteLogTailExit)
12331261 ? {}
1234− : { remoteLogTailError: remoteLogTailExit.cause }),
1235− cause,
1262+ : { remoteLogTailFailure: describeReadinessCause(remoteLogTailExit.cause) }),
1263+ failure: describeReadinessCause(cause),
12361264 });
12371265 }),
12381266 ),
@@ -1370,7 +1398,7 @@ export const make = Effect.fn("ssh/tunnel.SshEnvironmentManager.make")(function* · 131 unmodified lines
13701398 ...sshTargetLogFields(input.target),
13711399 key: input.key,
13721400 promptCount: input.promptCount,
1373− cause: input.error,
1401+ failure: describeReadinessCause(input.error),
13741402 });
13751403 const promptService = yield* SshAuth.SshPasswordPrompt;
13761404 if (!promptService.isAvailable) {
@@ -1569,7 +1597,7 @@ export const make = Effect.fn("ssh/tunnel.SshEnvironmentManager.make")(function* · 192 unmodified lines
15691597 key,
15701598 localPort: entry.localPort,
15711599 remotePort: entry.remotePort,
1572− cause: readinessExit.cause,
1600+ failure: describeReadinessCause(readinessExit.cause),
15731601 });
15741602 yield* closeTunnelEntry(entry);
15751603 yield* cancelPendingTunnelEntry(key, resolvedTarget);
@@ -1597,7 +1625,7 @@ export const make = Effect.fn("ssh/tunnel.SshEnvironmentManager.make")(function* · 21 unmodified lines
15971625 Effect.logWarning("ssh.environment.tunnel.create.failed", {
15981626 ...sshTargetLogFields(resolvedTarget),
15991627 key,
1600− cause,
1628+ failure: describeReadinessCause(cause),
16011629 }),
16021630 ),
16031631 Effect.onExit((exit) =>

Keyboard shortcuts

General

Show keyboard shortcuts
?
Focus the current search
/

Issues and pull requests

Open filters
f

Issues, pull requests and Inbox

Select next item
j↓
Select previous item
k↑
Open selected item
Enter
Dismiss filters or clear selection
Esc

Repository code

Go to file
t