diff --git a/.changeset/browser-pay-intercept-diagnostics.md b/.changeset/browser-pay-intercept-diagnostics.md new file mode 100644 index 000000000..993d7d9e7 --- /dev/null +++ b/.changeset/browser-pay-intercept-diagnostics.md @@ -0,0 +1,5 @@ +--- +"@sapiom/browser-pay": patch +--- + +Better debug logging for browser-pay: an optional logger now receives browser step failures, and CDP errors name the method. diff --git a/packages/browser-pay/README.md b/packages/browser-pay/README.md index d8727932d..c3c6ca0e1 100644 --- a/packages/browser-pay/README.md +++ b/packages/browser-pay/README.md @@ -55,7 +55,7 @@ Refusal, nothing forwarded: The `refused` event and logger pass through only these known reasons: `unknown_injection`, `injection_expired`, `payment_released`, `key_rotated`, `already_relayed`, `relay_in_progress`, `card_removed`, `payment_not_authorized`, `total_changed`, `destination_not_allowed`, `card_fields_invalid`, `merchant_mismatch`, and `provider_unavailable`. Any other reason becomes `unrecognized`. `relay_in_progress` is not terminal. The paused request stays open and the same idempotency key is posted again until the outcome is terminal or the deadline passes. -Event `url` is origin-only (`scheme://host[:port]`), with any held placeholder masked. An opaque origin uses its scheme (for example, `about:`); an unparseable URL is `""`. Paths, queries, fragments, and userinfo are never included. Attach errors use fixed messages and do not include transport details. CDP command failures and timeouts use the generic messages `CDP command failed` and `CDP command timed out`. +Event `url` is origin-only (`scheme://host[:port]`), with any held placeholder masked. An opaque origin uses its scheme (for example, `about:`); an unparseable URL is `""`. Paths, queries, fragments, and userinfo are never included. Attach errors use fixed messages and do not include transport details. CDP command failures and timeouts name the method that was sent (`CDP command failed: Target.setAutoAttach`, `CDP command timed out: Target.setAutoAttach`) and do not include the browser's error text. No answer after the send: @@ -87,6 +87,8 @@ const handle = await attachInterceptor(cdpUrl, { Call `handle.on` after `attachInterceptor` resolves. Events emitted while attach was running, including a target that could not arm Fetch, are delivered to that first subscriber. +An optional `logger` receives `browser step failed` when arming `Fetch.enable` fails, and when a nested auto-attach, resume, `Target.getTargets`, existing-frame attach, or close fails. + A request is relayed when the held placeholder number appears in the URL or body. An exact match counts, and so do digits split by spaces or dashes, including the URL-encoded and JSON-escaped forms of those separators. `placeholder` is `{ number, injectionRef }`. `injectionRef` is a UUID. The backend's `checkPlaceholderUse` decides whether the number is valid. A paused request that does not hold the placeholder is continued. A relayed response fails the paused request only when that response contains the held placeholder number. diff --git a/packages/browser-pay/src/cdp.test.ts b/packages/browser-pay/src/cdp.test.ts index ab4b7d331..c4783ba72 100644 --- a/packages/browser-pay/src/cdp.test.ts +++ b/packages/browser-pay/src/cdp.test.ts @@ -2,7 +2,7 @@ import crypto from "node:crypto"; import http from "node:http"; import type { AddressInfo } from "node:net"; import type { Duplex } from "node:stream"; -import { CdpConnection } from "./cdp"; +import { CdpCommandError, CdpConnection } from "./cdp"; function acceptKey(key: string): string { return crypto @@ -109,6 +109,25 @@ describe("CdpConnection", () => { } }); + it("rejects Fetch.enable with timedOut when the browser never replies", async () => { + const stub = await listen(); + try { + const connection = await CdpConnection.connect(stub.url); + await stub.onceSocket; + const pending = connection.send("Fetch.enable", {}, undefined, 20); + await expect(pending).rejects.toBeInstanceOf(CdpCommandError); + await expect(pending).rejects.toHaveProperty("timedOut", true); + await expect(pending).rejects.toHaveProperty("method", "Fetch.enable"); + await expect(pending).rejects.toHaveProperty( + "message", + "CDP command timed out: Fetch.enable", + ); + connection.close(); + } finally { + await stub.close(); + } + }); + it("rejects pending calls when a frame claims to exceed the size cap", async () => { const stub = await listen(); try { diff --git a/packages/browser-pay/src/cdp.ts b/packages/browser-pay/src/cdp.ts index f8ae53cc9..04ae95ec6 100644 --- a/packages/browser-pay/src/cdp.ts +++ b/packages/browser-pay/src/cdp.ts @@ -21,8 +21,33 @@ type Pending = { resolve: (value: unknown) => void; reject: (error: Error) => void; timer: NodeJS.Timeout; + method: string; }; +const PLAIN_CDP_METHOD = /^[A-Za-z]+\.[A-Za-z]+$/; + +export class CdpCommandError extends Error { + readonly method: string | undefined; + readonly code: number | undefined; + readonly timedOut: boolean; + + constructor(method: string, timedOut: boolean, code?: number) { + const safe = PLAIN_CDP_METHOD.test(method) ? method : undefined; + const label = timedOut ? "CDP command timed out" : "CDP command failed"; + super(safe === undefined ? label : `${label}: ${safe}`); + this.name = "CdpCommandError"; + this.method = safe; + this.timedOut = timedOut; + this.code = + typeof code === "number" && Number.isInteger(code) ? code : undefined; + } +} + +function readErrorCode(error: unknown): number | undefined { + if (!isRecord(error) || typeof error.code !== "number") return undefined; + return Number.isInteger(error.code) ? error.code : undefined; +} + function parseCdpMessage(value: unknown): | { id?: number; @@ -31,6 +56,7 @@ function parseCdpMessage(value: unknown): sessionId?: string; result?: unknown; failed?: true; + code?: number; } | undefined { if (!isRecord(value)) return undefined; @@ -40,6 +66,7 @@ function parseCdpMessage(value: unknown): const params = isRecord(value.params) ? value.params : {}; const sessionId = typeof value.sessionId === "string" ? value.sessionId : undefined; + const code = value.error ? readErrorCode(value.error) : undefined; // The remote error text is dropped here so it can never reach a caller. return { ...(id !== undefined ? { id } : {}), @@ -47,7 +74,9 @@ function parseCdpMessage(value: unknown): params, ...(sessionId ? { sessionId } : {}), result: value.result, - ...(value.error ? { failed: true as const } : {}), + ...(value.error + ? { failed: true as const, ...(code !== undefined ? { code } : {}) } + : {}), }; } @@ -339,7 +368,9 @@ export class CdpConnection { this.pending.delete(message.id); clearTimeout(pending.timer); if (message.failed) { - pending.reject(new Error("CDP command failed")); + pending.reject( + new CdpCommandError(pending.method, false, message.code), + ); } else { pending.resolve(message.result); } @@ -390,12 +421,13 @@ export class CdpConnection { } const timer = setTimeout(() => { this.pending.delete(id); - reject(new Error("CDP command timed out")); + reject(new CdpCommandError(method, true)); }, timeoutMs); this.pending.set(id, { resolve, reject, timer, + method, }); try { this.socket.send( diff --git a/packages/browser-pay/src/interceptor.event-redaction.test.ts b/packages/browser-pay/src/interceptor.event-redaction.test.ts index 1464c3cfd..5b3f74833 100644 --- a/packages/browser-pay/src/interceptor.event-redaction.test.ts +++ b/packages/browser-pay/src/interceptor.event-redaction.test.ts @@ -597,7 +597,7 @@ describe("interceptor event redaction", () => { attachOptions(stubPaymentRelay(async () => success())), ); handle.on((event) => events.push(event)); - expect(events).toEqual([ + expect(events).toStrictEqual([ { type: "failed", url: ORIGIN, @@ -680,7 +680,9 @@ describe("interceptor event redaction", () => { attachOptions(stubPaymentRelay(async () => success())), ), ); - expect(protocolError.message).toBe("CDP command failed"); + expect(protocolError.message).toBe( + "CDP command failed: Target.setAutoAttach", + ); assertSafeError(protocolError); } finally { await stub.close(); @@ -702,6 +704,9 @@ describe("interceptor event redaction", () => { ); expect(error.message).toBe("CDP command failed"); expect(error.message).not.toContain("SYNTHETIC_METHOD_SECRET"); + expect( + JSON.stringify(error, Object.getOwnPropertyNames(error)), + ).not.toContain("SYNTHETIC_METHOD_SECRET"); } finally { errorConnection.close(); await errorStub.close(); @@ -715,6 +720,9 @@ describe("interceptor event redaction", () => { ); expect(error.message).toBe("CDP command timed out"); expect(error.message).not.toContain("SYNTHETIC_METHOD_SECRET"); + expect( + JSON.stringify(error, Object.getOwnPropertyNames(error)), + ).not.toContain("SYNTHETIC_METHOD_SECRET"); } finally { timeoutConnection.close(); await timeoutStub.close(); diff --git a/packages/browser-pay/src/interceptor.protocol.test.ts b/packages/browser-pay/src/interceptor.protocol.test.ts index 1bbe10b5e..976a71fe3 100644 --- a/packages/browser-pay/src/interceptor.protocol.test.ts +++ b/packages/browser-pay/src/interceptor.protocol.test.ts @@ -2,6 +2,7 @@ import crypto from "node:crypto"; import http from "node:http"; import type { AddressInfo } from "node:net"; import type { Duplex } from "node:stream"; +import { CdpCommandError } from "./cdp"; import { attachInterceptor, type InterceptorEvent } from "./interceptor"; import type { HeldPlaceholder, RelayRequest, RelayResponse } from "./index"; import { stubPaymentRelay } from "../test/stub-relay"; @@ -27,9 +28,17 @@ interface Command { sessionId?: string; } +const REMOTE_STEP = "REMOTE_STEP_TEXT"; + interface StubOptions { failAutoAttach?: boolean; + failChildAutoAttach?: boolean; + failResume?: boolean; + failAttachToTarget?: boolean; + failCloseTarget?: boolean; failFetch?: boolean; + fetchErrorCode?: number; + fetchErrorMessage?: string; failFulfill?: boolean; holdFulfill?: boolean; postData?: string; @@ -63,7 +72,11 @@ async function startStub(options: StubOptions = {}): Promise<{ const chunks: Buffer[] = []; let buffered = 0; - const reply = (id: number, result: unknown, error?: { message: string }) => { + const reply = ( + id: number, + result: unknown, + error?: { message: string; code?: number }, + ) => { const message = error ? { id, error } : { id, result }; socket?.write(serverFrame(JSON.stringify(message))); }; @@ -121,8 +134,32 @@ async function startStub(options: StubOptions = {}): Promise<{ reply(message.id, undefined, { message: "auto-attach refused" }); return; } + if ( + message.method === "Target.setAutoAttach" && + message.sessionId && + options.failChildAutoAttach + ) { + reply(message.id, undefined, { message: REMOTE_STEP, code: -32000 }); + return; + } + if ( + message.method === "Runtime.runIfWaitingForDebugger" && + options.failResume + ) { + reply(message.id, undefined, { message: REMOTE_STEP, code: -32000 }); + return; + } + if (message.method === "Target.closeTarget" && options.failCloseTarget) { + reply(message.id, undefined, { message: REMOTE_STEP, code: -32000 }); + return; + } if (message.method === "Fetch.enable" && options.failFetch) { - reply(message.id, undefined, { message: "Fetch is unsupported" }); + reply(message.id, undefined, { + message: options.fetchErrorMessage ?? "Fetch is unsupported", + ...(options.fetchErrorCode !== undefined + ? { code: options.fetchErrorCode } + : {}), + }); return; } if (message.method === "Target.getTargets") { @@ -130,6 +167,10 @@ async function startStub(options: StubOptions = {}): Promise<{ return; } if (message.method === "Target.attachToTarget") { + if (options.failAttachToTarget) { + reply(message.id, undefined, { message: REMOTE_STEP, code: -32000 }); + return; + } reply(message.id, { sessionId: options.attachedSessionId ?? "iframe-existing", }); @@ -300,18 +341,275 @@ function header( return headers[name.toLowerCase()]; } +type StepWarning = { + message: string; + fields?: Readonly>; +}; + +function stepLogger(warnings: StepWarning[]) { + return { + warn( + message: string, + fields?: Readonly>, + ) { + warnings.push(fields ? { message, fields } : { message }); + }, + }; +} + describe("interceptor CDP decisions", () => { it("closes the CDP connection when start fails", async () => { const stub = await startStub({ failAutoAttach: true }); try { - await expect( - attachInterceptor(stub.url, { + const caught = await attachInterceptor(stub.url, { + relay: stubPaymentRelay(async () => success()), + placeholder: HELD, + profileId: "shopify-card-vault", + }).catch((error: unknown) => error); + expect(caught).toBeInstanceOf(CdpCommandError); + expect(caught).toMatchObject({ + method: "Target.setAutoAttach", + message: "CDP command failed: Target.setAutoAttach", + }); + expect( + JSON.stringify(caught, Object.getOwnPropertyNames(caught as object)), + ).not.toContain("auto-attach refused"); + await waitFor(() => stub.sawClose(), "websocket close"); + } finally { + await stub.close(); + } + }); + + it("logs a nested setAutoAttach failure and still arms Fetch", async () => { + const stub = await startStub({ failChildAutoAttach: true }); + const events: InterceptorEvent[] = []; + const warnings: StepWarning[] = []; + try { + const handle = await attachInterceptor(stub.url, { + relay: stubPaymentRelay(async () => success()), + placeholder: HELD, + profileId: "shopify-card-vault", + logger: stepLogger(warnings), + }); + handle.on((event) => events.push(event)); + attachPage(stub.emit); + await waitFor( + () => + stub.commands.some((command) => command.method === "Fetch.enable"), + "Fetch.enable", + ); + expect(events).toEqual([]); + expect(stub.commands.map((command) => command.method)).not.toContain( + "Target.closeTarget", + ); + expect(warnings).toStrictEqual([ + { + message: "browser step failed", + fields: { + method: "Target.setAutoAttach", + code: -32000, + timedOut: false, + targetType: "page", + origin: "https://shop.example", + }, + }, + ]); + expect(JSON.stringify(warnings)).not.toContain(REMOTE_STEP); + expect(JSON.stringify(warnings)).not.toContain("checkout"); + await handle.detach(); + } finally { + await stub.close(); + } + }); + + it("a throwing logger leaves a nested setAutoAttach failure unchanged", async () => { + const options: StubOptions = { + failChildAutoAttach: true, + targets: [ + { + targetId: "target-card", + type: "iframe", + url: "https://checkout.pci.shopifyinc.com/sessions", + }, + ], + attachedSessionId: "iframe-card", + }; + const run = async (logger?: { + warn(message: string): void; + }): Promise<{ events: InterceptorEvent[]; commands: Command[] }> => { + const stub = await startStub(options); + const events: InterceptorEvent[] = []; + try { + const handle = await attachInterceptor(stub.url, { relay: stubPaymentRelay(async () => success()), placeholder: HELD, profileId: "shopify-card-vault", + ...(logger ? { logger } : {}), + }); + handle.on((event) => events.push(event)); + await handle.detach(); + return { events: [...events], commands: [...stub.commands] }; + } finally { + await stub.close(); + } + }; + const silent = await run(); + let warned = 0; + const throwing = await run({ + warn() { + warned += 1; + throw new Error("logger boom"); + }, + }); + expect(warned).toBeGreaterThan(0); + expect(silent.commands.map((command) => command.method)).toContain( + "Fetch.enable", + ); + expect(throwing.events).toEqual(silent.events); + expect(throwing.commands).toEqual(silent.commands); + }); + + it("logs a resume failure and still leaves the target armed", async () => { + const stub = await startStub({ failResume: true }); + const events: InterceptorEvent[] = []; + const warnings: StepWarning[] = []; + try { + const handle = await attachInterceptor(stub.url, { + relay: stubPaymentRelay(async () => success()), + placeholder: HELD, + profileId: "shopify-card-vault", + logger: stepLogger(warnings), + }); + handle.on((event) => events.push(event)); + attachPage(stub.emit); + await waitFor(() => warnings.length === 1, "resume warning"); + expect(events).toEqual([]); + expect(stub.commands.map((command) => command.method)).toContain( + "Fetch.enable", + ); + expect(stub.commands.map((command) => command.method)).not.toContain( + "Target.closeTarget", + ); + expect(warnings).toStrictEqual([ + { + message: "browser step failed", + fields: { + method: "Runtime.runIfWaitingForDebugger", + code: -32000, + timedOut: false, + targetType: "page", + origin: "https://shop.example", + }, + }, + ]); + expect(JSON.stringify(warnings)).not.toContain(REMOTE_STEP); + await handle.detach(); + } finally { + await stub.close(); + } + }); + + it("logs an attachToTarget failure and leaves that iframe unarmed", async () => { + const stub = await startStub({ + failAttachToTarget: true, + targets: [ + { + targetId: "target-card", + type: "iframe", + url: "https://checkout.pci.shopifyinc.com/sessions?card=1", + }, + ], + }); + const events: InterceptorEvent[] = []; + const warnings: StepWarning[] = []; + try { + const handle = await attachInterceptor(stub.url, { + relay: stubPaymentRelay(async () => success()), + placeholder: HELD, + profileId: "shopify-card-vault", + logger: stepLogger(warnings), + }); + handle.on((event) => events.push(event)); + expect(events).toEqual([]); + expect(stub.commands.map((command) => command.method)).not.toContain( + "Fetch.enable", + ); + expect(stub.commands.map((command) => command.method)).not.toContain( + "Target.closeTarget", + ); + expect(warnings).toStrictEqual([ + { + message: "browser step failed", + fields: { + method: "Target.attachToTarget", + code: -32000, + timedOut: false, + targetType: "iframe", + origin: "https://checkout.pci.shopifyinc.com", + }, + }, + ]); + expect(JSON.stringify(warnings)).not.toContain(REMOTE_STEP); + expect(JSON.stringify(warnings)).not.toContain("sessions"); + await handle.detach(); + } finally { + await stub.close(); + } + }); + + it("logs a closeTarget failure and still emits intercept_unavailable", async () => { + const stub = await startStub({ failFetch: true, failCloseTarget: true }); + const events: InterceptorEvent[] = []; + const warnings: StepWarning[] = []; + try { + const handle = await attachInterceptor(stub.url, { + relay: stubPaymentRelay(async () => success()), + placeholder: HELD, + profileId: "shopify-card-vault", + logger: stepLogger(warnings), + }); + handle.on((event) => events.push(event)); + attachPage(stub.emit); + await waitFor(() => warnings.length === 2, "close warning"); + expect(events).toStrictEqual([ + { + type: "failed", + url: "https://shop.example", + reason: "intercept_unavailable", + }, + ]); + expect(stub.commands).toContainEqual( + expect.objectContaining({ + method: "Target.closeTarget", + params: { targetId: "target-page" }, }), - ).rejects.toThrow("CDP command failed"); - await waitFor(() => stub.sawClose(), "websocket close"); + ); + expect(stub.commands.map((command) => command.method)).not.toContain( + "Runtime.runIfWaitingForDebugger", + ); + expect(warnings).toStrictEqual([ + { + message: "browser step failed", + fields: { + method: "Fetch.enable", + timedOut: false, + targetType: "page", + origin: "https://shop.example", + }, + }, + { + message: "browser step failed", + fields: { + method: "Target.closeTarget", + code: -32000, + timedOut: false, + targetType: "page", + origin: "https://shop.example", + }, + }, + ]); + expect(JSON.stringify(warnings)).not.toContain(REMOTE_STEP); + await handle.detach(); } finally { await stub.close(); } @@ -320,11 +618,13 @@ describe("interceptor CDP decisions", () => { it("does not resume a target whose Fetch.enable failed", async () => { const stub = await startStub({ failFetch: true }); const events: InterceptorEvent[] = []; + const warnings: StepWarning[] = []; try { const handle = await attachInterceptor(stub.url, { relay: stubPaymentRelay(async () => success()), placeholder: HELD, profileId: "shopify-card-vault", + logger: stepLogger(warnings), }); handle.on((event) => events.push(event)); attachPage(stub.emit); @@ -344,12 +644,339 @@ describe("interceptor CDP decisions", () => { params: { targetId: "target-page" }, }), ); - expect(events).toContainEqual({ + expect(events).toStrictEqual([ + { + type: "failed", + url: "https://shop.example", + reason: "intercept_unavailable", + }, + ]); + expect(warnings).toStrictEqual([ + { + message: "browser step failed", + fields: { + method: "Fetch.enable", + timedOut: false, + targetType: "page", + origin: "https://shop.example", + }, + }, + ]); + await handle.detach(); + } finally { + await stub.close(); + } + }); + + it("reports the CDP code when Fetch.enable fails and still closes the target", async () => { + const remote = "REMOTE_CDP_TEXT_SHOULD_NOT_LEAK"; + const stub = await startStub({ + failFetch: true, + fetchErrorCode: -32000, + fetchErrorMessage: remote, + }); + const events: InterceptorEvent[] = []; + const warnings: StepWarning[] = []; + try { + const handle = await attachInterceptor(stub.url, { + relay: stubPaymentRelay(async () => success()), + placeholder: HELD, + profileId: "shopify-card-vault", + logger: stepLogger(warnings), + }); + handle.on((event) => events.push(event)); + stub.emit({ + method: "Target.attachedToTarget", + params: { + sessionId: "page-1", + waitingForDebugger: true, + targetInfo: { + targetId: "target-page", + type: "page", + url: "https://shop.example/checkout?q=1#frag", + }, + }, + }); + await waitFor( + () => + stub.commands.some( + (command) => command.method === "Target.closeTarget", + ), + "closeTarget", + ); + expect(stub.commands).toContainEqual( + expect.objectContaining({ + method: "Target.closeTarget", + params: { targetId: "target-page" }, + }), + ); + expect(events).toStrictEqual([ + { + type: "failed", + url: "https://shop.example", + reason: "intercept_unavailable", + }, + ]); + expect(warnings).toStrictEqual([ + { + message: "browser step failed", + fields: { + method: "Fetch.enable", + code: -32000, + timedOut: false, + targetType: "page", + origin: "https://shop.example", + }, + }, + ]); + expect(JSON.stringify(events)).not.toContain(remote); + expect(JSON.stringify(warnings)).not.toContain(remote); + expect(JSON.stringify(warnings)).not.toContain("checkout"); + await handle.detach(); + } finally { + await stub.close(); + } + }); + + it("omits code when Fetch.enable returns a non-integer CDP code", async () => { + const stub = await startStub({ failFetch: true, fetchErrorCode: 1.5 }); + const events: InterceptorEvent[] = []; + const warnings: StepWarning[] = []; + try { + const handle = await attachInterceptor(stub.url, { + relay: stubPaymentRelay(async () => success()), + placeholder: HELD, + profileId: "shopify-card-vault", + logger: stepLogger(warnings), + }); + handle.on((event) => events.push(event)); + attachPage(stub.emit); + await waitFor( + () => events.some((event) => event.type === "failed"), + "non-integer code", + ); + expect(events).toStrictEqual([ + { + type: "failed", + url: "https://shop.example", + reason: "intercept_unavailable", + }, + ]); + expect(warnings).toStrictEqual([ + { + message: "browser step failed", + fields: { + method: "Fetch.enable", + timedOut: false, + targetType: "page", + origin: "https://shop.example", + }, + }, + ]); + await handle.detach(); + } finally { + await stub.close(); + } + }); + + it("logs about: for an about:blank target that cannot arm Fetch", async () => { + const stub = await startStub({ failFetch: true }); + const events: InterceptorEvent[] = []; + const warnings: StepWarning[] = []; + try { + const handle = await attachInterceptor(stub.url, { + relay: stubPaymentRelay(async () => success()), + placeholder: HELD, + profileId: "shopify-card-vault", + logger: stepLogger(warnings), + }); + handle.on((event) => events.push(event)); + stub.emit({ + method: "Target.attachedToTarget", + params: { + sessionId: "blank-1", + waitingForDebugger: true, + targetInfo: { + targetId: "target-blank", + type: "iframe", + url: "about:blank", + }, + }, + }); + await waitFor( + () => events.some((event) => event.type === "failed"), + "about blank", + ); + expect(events).toStrictEqual([ + { + type: "failed", + url: "about:", + reason: "intercept_unavailable", + }, + ]); + expect(warnings).toStrictEqual([ + { + message: "browser step failed", + fields: { + method: "Fetch.enable", + timedOut: false, + targetType: "iframe", + origin: "about:", + }, + }, + ]); + await handle.detach(); + } finally { + await stub.close(); + } + }); + + it("a throwing logger does not change a Fetch.enable failure", async () => { + const run = async (logger?: { + warn(message: string): void; + }): Promise<{ events: InterceptorEvent[]; commands: Command[] }> => { + const stub = await startStub({ failFetch: true }); + const events: InterceptorEvent[] = []; + try { + const handle = await attachInterceptor(stub.url, { + relay: stubPaymentRelay(async () => success()), + placeholder: HELD, + profileId: "shopify-card-vault", + ...(logger ? { logger } : {}), + }); + handle.on((event) => events.push(event)); + attachPage(stub.emit); + await waitFor( + () => + stub.commands.some( + (command) => command.method === "Target.closeTarget", + ), + "closeTarget", + ); + await handle.detach(); + return { events: [...events], commands: [...stub.commands] }; + } finally { + await stub.close(); + } + }; + const silent = await run(); + let warned = 0; + const throwing = await run({ + warn() { + warned += 1; + throw new Error("logger boom"); + }, + }); + expect(warned).toBeGreaterThan(0); + expect(silent.events).toStrictEqual([ + { type: "failed", url: "https://shop.example", reason: "intercept_unavailable", + }, + ]); + expect(throwing.events).toStrictEqual(silent.events); + expect(throwing.commands).toEqual(silent.commands); + expect(throwing.commands).toContainEqual( + expect.objectContaining({ + method: "Target.closeTarget", + params: { targetId: "target-page" }, + }), + ); + }); + + it("swallows a rejected async logger and still closes the target", async () => { + const stub = await startStub({ failFetch: true }); + const events: InterceptorEvent[] = []; + const unhandled: unknown[] = []; + const onUnhandled = (error: unknown) => { + unhandled.push(error); + }; + process.on("unhandledRejection", onUnhandled); + try { + const handle = await attachInterceptor(stub.url, { + relay: stubPaymentRelay(async () => success()), + placeholder: HELD, + profileId: "shopify-card-vault", + logger: { + async warn() { + throw new Error("ASYNC_LOGGER_REJECTION"); + }, + }, }); + handle.on((event) => events.push(event)); + attachPage(stub.emit); + await waitFor( + () => + stub.commands.some( + (command) => command.method === "Target.closeTarget", + ), + "closeTarget", + ); + await new Promise((resolve) => setImmediate(resolve)); + expect(unhandled).toEqual([]); + expect(events).toStrictEqual([ + { + type: "failed", + url: "https://shop.example", + reason: "intercept_unavailable", + }, + ]); + expect(stub.commands).toContainEqual( + expect.objectContaining({ + method: "Target.closeTarget", + params: { targetId: "target-page" }, + }), + ); await handle.detach(); + } finally { + process.off("unhandledRejection", onUnhandled); + await stub.close(); + } + }); + + it("logs Fetch.enable before a failed handler detaches", async () => { + const stub = await startStub({ failFetch: true }); + const events: InterceptorEvent[] = []; + const warnings: StepWarning[] = []; + try { + const handle = await attachInterceptor(stub.url, { + relay: stubPaymentRelay(async () => success()), + placeholder: HELD, + profileId: "shopify-card-vault", + logger: stepLogger(warnings), + }); + handle.on((event) => { + events.push(event); + if (event.type === "failed") void handle.detach(); + }); + attachPage(stub.emit); + await waitFor(() => warnings.length === 1, "Fetch.enable warning"); + expect(events).toStrictEqual([ + { + type: "failed", + url: "https://shop.example", + reason: "intercept_unavailable", + }, + ]); + expect(warnings).toStrictEqual([ + { + message: "browser step failed", + fields: { + method: "Fetch.enable", + timedOut: false, + targetType: "page", + origin: "https://shop.example", + }, + }, + ]); + await waitFor( + () => + stub.commands.some( + (command) => command.method === "Target.closeTarget", + ), + "closeTarget", + ); } finally { await stub.close(); } @@ -1557,11 +2184,13 @@ describe("interceptor CDP decisions", () => { ), ).toBe(true); handle.on((event) => events.push(event)); - expect(events).toContainEqual({ - type: "failed", - url: "https://checkout.example", - reason: "intercept_unavailable", - }); + expect(events).toStrictEqual([ + { + type: "failed", + url: "https://checkout.example", + reason: "intercept_unavailable", + }, + ]); await handle.detach(); } finally { await stub.close(); diff --git a/packages/browser-pay/src/interceptor.ts b/packages/browser-pay/src/interceptor.ts index cb435f73c..1bcd4faae 100644 --- a/packages/browser-pay/src/interceptor.ts +++ b/packages/browser-pay/src/interceptor.ts @@ -1,4 +1,4 @@ -import { CdpConnection, type CdpEvent } from "./cdp.js"; +import { CdpCommandError, CdpConnection, type CdpEvent } from "./cdp.js"; import { paymentIdempotencyKey, type RelayedHttpResponse, @@ -426,23 +426,69 @@ class PaymentInterceptor { } private async armOrClose(session: Session): Promise { - const armed = await armFetch(this.connection, session); - if (armed) return true; + const failure = await armFetch(this.connection, session); + if (!failure) return true; if (this.closed) return false; + this.logStepFailure("Fetch.enable", failure, session); this.emit({ type: "failed", url: session.url, reason: "intercept_unavailable", }); - await this.connection - .send("Target.closeTarget", { targetId: session.targetId }) - .catch(() => {}); + await this.swallowStep( + this.connection.send("Target.closeTarget", { + targetId: session.targetId, + }), + "Target.closeTarget", + session, + ); return false; } + private logStepFailure( + method: string, + error: unknown, + target?: { type: string; url: string }, + ): void { + if (this.closed) return; + const failed = error instanceof CdpCommandError ? error : undefined; + const targetType = + target?.type === "page" || target?.type === "iframe" + ? target.type + : undefined; + const code = failed?.code; + try { + void Promise.resolve( + this.logger.warn("browser step failed", { + method, + ...(code !== undefined ? { code } : {}), + timedOut: failed?.timedOut ?? false, + ...(targetType ? { targetType } : {}), + ...(target ? { origin: eventUrl(target.url, this.number) } : {}), + }), + ).catch(() => {}); + } catch { + // A logger must not change control flow. + } + } + + private async swallowStep( + pending: Promise, + method: string, + target?: { type: string; url: string }, + ): Promise { + try { + return await pending; + } catch (error) { + this.logStepFailure(method, error, target); + return undefined; + } + } + private async autoAttachChildren(sessionId: string): Promise { - await this.connection - .send( + const session = this.sessions.get(sessionId); + await this.swallowStep( + this.connection.send( "Target.setAutoAttach", { autoAttach: true, @@ -451,8 +497,10 @@ class PaymentInterceptor { filter: CHILD_FILTER, }, sessionId, - ) - .catch(() => {}); + ), + "Target.setAutoAttach", + session, + ); } private async resumeIfWaiting( @@ -460,24 +508,30 @@ class PaymentInterceptor { waitingForDebugger: boolean, ): Promise { if (!waitingForDebugger) return; - await this.connection - .send("Runtime.runIfWaitingForDebugger", {}, sessionId) - .catch(() => {}); + const session = this.sessions.get(sessionId); + await this.swallowStep( + this.connection.send("Runtime.runIfWaitingForDebugger", {}, sessionId), + "Runtime.runIfWaitingForDebugger", + session, + ); } private async attachExistingFrames(): Promise { - const listed = await this.connection - .send("Target.getTargets") - .catch(() => undefined); + const listed = await this.swallowStep( + this.connection.send("Target.getTargets"), + "Target.getTargets", + ); for (const info of parseTargetInfos(listed)) { if (info.type !== "iframe") continue; if (this.byTarget.has(info.targetId)) continue; - const attached = await this.connection - .send("Target.attachToTarget", { + const attached = await this.swallowStep( + this.connection.send("Target.attachToTarget", { targetId: info.targetId, flatten: true, - }) - .catch(() => undefined); + }), + "Target.attachToTarget", + { type: info.type, url: info.url }, + ); const sessionId = readAttachedSessionId(attached); if (!sessionId || this.sessions.has(sessionId)) continue; const session = this.trackSession({ @@ -1262,8 +1316,8 @@ function multipartOmitsFileBytes(body: string): boolean { async function armFetch( connection: CdpConnection, session: Session, -): Promise { - if (session.fetchEnabled) return true; +): Promise { + if (session.fetchEnabled) return; try { await connection .send("Network.enable", {}, session.sessionId) @@ -1273,11 +1327,10 @@ async function armFetch( { patterns: [{ urlPattern: "*", requestStage: "Request" }] }, session.sessionId, ); - } catch { - return false; + } catch (error) { + return error instanceof Error ? error : new Error("CDP command failed"); } session.fetchEnabled = true; - return true; } async function continueRequest( diff --git a/packages/browser-pay/src/logger.ts b/packages/browser-pay/src/logger.ts index 71b49ca46..6ec84fb27 100644 --- a/packages/browser-pay/src/logger.ts +++ b/packages/browser-pay/src/logger.ts @@ -1,7 +1,7 @@ export interface PayLogger { warn( message: string, - fields?: Readonly>, + fields?: Readonly>, ): void; }