diff --git a/.changeset/pass-client-logger-to-request-handler.md b/.changeset/pass-client-logger-to-request-handler.md new file mode 100644 index 00000000000..64c906aae5e --- /dev/null +++ b/.changeset/pass-client-logger-to-request-handler.md @@ -0,0 +1,9 @@ +--- +"@smithy/core": minor +"@smithy/node-http-handler": minor +"@smithy/undici-http-handler": minor +--- + +feat: offer the client logger to request handlers as a fallback, without overwriting a handler's own logger. A NoOpLogger is not offered, so handlers keep their own console-based defaults. + +fix: `getHttpHandlerExtensionConfiguration` and `resolveHttpHandlerRuntimeConfig` now read and write `requestHandler` instead of `httpHandler`, which is the field clients actually populate. This changes the shape of the internal `HttpHandlerExtensionConfigType` and of the object returned by `resolveHttpHandlerRuntimeConfig`. diff --git a/packages/core/src/submodules/protocols/protocol-http/extensions/httpExtensionConfiguration.spec.ts b/packages/core/src/submodules/protocols/protocol-http/extensions/httpExtensionConfiguration.spec.ts new file mode 100644 index 00000000000..04db57020a3 --- /dev/null +++ b/packages/core/src/submodules/protocols/protocol-http/extensions/httpExtensionConfiguration.spec.ts @@ -0,0 +1,135 @@ +import { describe, expect, it, vi } from "vitest"; + +import { getHttpHandlerExtensionConfiguration, resolveHttpHandlerRuntimeConfig } from "./httpExtensionConfiguration"; + +/** + * The key under which a client offers its logger. Declared locally, as the + * handlers do: `Symbol.for` makes every copy of this key equal. + */ +const FALLBACK_LOGGER = Symbol.for("logger"); + +describe("getHttpHandlerExtensionConfiguration", () => { + const createMockHandler = () => ({ + metadata: { handlerProtocol: "http/1.1" }, + handle: vi.fn(), + updateHttpClientConfig: vi.fn(), + httpHandlerConfigs: vi.fn().mockReturnValue({}), + }); + + const createMockLogger = () => ({ + trace: vi.fn(), + debug: vi.fn(), + info: vi.fn(), + warn: vi.fn(), + error: vi.fn(), + }); + + /** + * Stands in for the client's NoOpLogger, which is detected by constructor + * name to avoid a cross-submodule import. + */ + class NoOpLogger { + public trace = vi.fn(); + public debug = vi.fn(); + public info = vi.fn(); + public warn = vi.fn(); + public error = vi.fn(); + } + + describe("client logger injection", () => { + it("offers the client logger to the handler under the fallback key", () => { + const handler = createMockHandler(); + const logger = createMockLogger(); + + getHttpHandlerExtensionConfiguration({ requestHandler: handler, logger } as any); + + expect(handler.updateHttpClientConfig).toHaveBeenCalledWith(FALLBACK_LOGGER, logger); + }); + + it("does not assign the public logger key, so an explicit handler logger is never overwritten", () => { + const handler = createMockHandler(); + const logger = createMockLogger(); + + getHttpHandlerExtensionConfiguration({ requestHandler: handler, logger } as any); + + expect(handler.updateHttpClientConfig).not.toHaveBeenCalledWith("logger", expect.anything()); + expect(handler.updateHttpClientConfig).toHaveBeenCalledTimes(1); + }); + + it("does not call updateHttpClientConfig when logger is not set", () => { + const handler = createMockHandler(); + + getHttpHandlerExtensionConfiguration({ requestHandler: handler } as any); + + expect(handler.updateHttpClientConfig).not.toHaveBeenCalled(); + }); + + it("does not offer a NoOpLogger, so handlers keep their console defaults", () => { + const handler = createMockHandler(); + + getHttpHandlerExtensionConfiguration({ requestHandler: handler, logger: new NoOpLogger() } as any); + + expect(handler.updateHttpClientConfig).not.toHaveBeenCalled(); + }); + + it("does not throw when no handler is present", () => { + const logger = createMockLogger(); + + // should not throw + getHttpHandlerExtensionConfiguration({ logger } as any); + }); + + it("does not throw for a handler that predates updateHttpClientConfig", () => { + const logger = createMockLogger(); + const legacyHandler = { metadata: {}, handle: vi.fn() }; + + // should not throw + getHttpHandlerExtensionConfiguration({ requestHandler: legacyHandler, logger } as any); + }); + }); + + describe("handler accessors read and write requestHandler", () => { + it("returns the handler that clients populate as requestHandler", () => { + const handler = createMockHandler(); + + const extension = getHttpHandlerExtensionConfiguration({ requestHandler: handler } as any); + + expect(extension.httpHandler()).toBe(handler); + }); + + it("setHttpHandler replaces the handler seen by the runtime config", () => { + const handler = createMockHandler(); + const replacement = createMockHandler(); + const runtimeConfig = { requestHandler: handler } as any; + + const extension = getHttpHandlerExtensionConfiguration(runtimeConfig); + extension.setHttpHandler(replacement as any); + + expect(runtimeConfig.requestHandler).toBe(replacement); + expect(extension.httpHandler()).toBe(replacement); + }); + + it("forwards updateHttpClientConfig and httpHandlerConfigs to the handler", () => { + const handler = createMockHandler(); + + const extension = getHttpHandlerExtensionConfiguration({ requestHandler: handler } as any); + extension.updateHttpClientConfig("requestTimeout" as any, 1000 as any); + extension.httpHandlerConfigs(); + + expect(handler.updateHttpClientConfig).toHaveBeenCalledWith("requestTimeout", 1000); + expect(handler.httpHandlerConfigs).toHaveBeenCalled(); + }); + }); +}); + +describe("resolveHttpHandlerRuntimeConfig", () => { + it("emits the handler under requestHandler, matching what clients read", () => { + const handler = { metadata: {}, handle: vi.fn() } as any; + + const runtimeConfig = resolveHttpHandlerRuntimeConfig({ + httpHandler: () => handler, + } as any); + + expect(runtimeConfig).toEqual({ requestHandler: handler }); + }); +}); diff --git a/packages/core/src/submodules/protocols/protocol-http/extensions/httpExtensionConfiguration.ts b/packages/core/src/submodules/protocols/protocol-http/extensions/httpExtensionConfiguration.ts index d5bb23f2a2e..46cdfcc1d35 100644 --- a/packages/core/src/submodules/protocols/protocol-http/extensions/httpExtensionConfiguration.ts +++ b/packages/core/src/submodules/protocols/protocol-http/extensions/httpExtensionConfiguration.ts @@ -1,3 +1,5 @@ +import type { Logger } from "@smithy/types"; + import type { HttpHandler } from "../httpHandler"; /** @@ -14,7 +16,7 @@ export interface HttpHandlerExtensionConfiguration = Partial<{ - httpHandler: HttpHandler; + requestHandler: HttpHandler; }>; /** @@ -22,21 +24,36 @@ export type HttpHandlerExtensionConfigType = * * @internal */ -export const getHttpHandlerExtensionConfiguration = ( - runtimeConfig: HttpHandlerExtensionConfigType +export const getHttpHandlerExtensionConfiguration = ( + runtimeConfig: HttpHandlerExtensionConfigType & { logger?: Logger } ) => { + // Offer the client's logger under `Symbol.for("logger")`. A symbol keeps this + // off the handlers' public options types, and being a symbol already + // distinguishes it from the `"logger"` string key. `Symbol.for` means each + // handler can declare its own copy of the key and still compare equal to it. + // + // Offered as a fallback only: the handler keeps its own logger if it has one. + // A NoOpLogger is not offered at all, so that handlers fall through to their + // own console-based defaults instead of being silenced. + if (runtimeConfig.logger && runtimeConfig.logger.constructor?.name !== "NoOpLogger") { + runtimeConfig.requestHandler?.updateHttpClientConfig?.( + Symbol.for("logger") as unknown as keyof HandlerConfig, + runtimeConfig.logger as HandlerConfig[keyof HandlerConfig] + ); + } + return { setHttpHandler(handler: HttpHandler): void { - runtimeConfig.httpHandler = handler; + runtimeConfig.requestHandler = handler; }, httpHandler(): HttpHandler { - return runtimeConfig.httpHandler!; + return runtimeConfig.requestHandler!; }, updateHttpClientConfig(key: keyof HandlerConfig, value: HandlerConfig[typeof key]): void { - runtimeConfig.httpHandler?.updateHttpClientConfig(key, value); + runtimeConfig.requestHandler?.updateHttpClientConfig(key, value); }, httpHandlerConfigs(): HandlerConfig { - return runtimeConfig.httpHandler!.httpHandlerConfigs(); + return runtimeConfig.requestHandler!.httpHandlerConfigs(); }, }; }; @@ -50,6 +67,6 @@ export const resolveHttpHandlerRuntimeConfig = ): HttpHandlerExtensionConfigType => { return { - httpHandler: httpHandlerExtensionConfiguration.httpHandler(), + requestHandler: httpHandlerExtensionConfiguration.httpHandler(), }; }; diff --git a/packages/node-http-handler/src/node-http-handler.spec.ts b/packages/node-http-handler/src/node-http-handler.spec.ts index 1867ee4b002..882936b94b3 100644 --- a/packages/node-http-handler/src/node-http-handler.spec.ts +++ b/packages/node-http-handler/src/node-http-handler.spec.ts @@ -1,12 +1,17 @@ import http from "node:http"; import https from "node:https"; import { HttpRequest } from "@smithy/core/protocols"; +import type { NodeHttpHandlerOptions } from "@smithy/types"; import { afterEach, beforeEach, describe, expect, test as it, vi } from "vitest"; import { NodeHttpHandler } from "./node-http-handler"; import * as setConnectionTimeoutModule from "./set-connection-timeout"; import * as setRequestTimeoutModule from "./set-request-timeout"; import * as setSocketTimeoutModule from "./set-socket-timeout"; + +// Matches the key the client offers its logger under. `Symbol.for` makes this +// the same symbol the handler compares against. +const FALLBACK_LOGGER = Symbol.for("logger") as unknown as keyof NodeHttpHandlerOptions; import { timing } from "./timing"; let { request: hRequest } = http; @@ -485,6 +490,94 @@ describe("NodeHttpHandler", () => { }); }); + describe("updateHttpClientConfig", () => { + const createLogger = () => ({ trace: vi.fn(), debug: vi.fn(), info: vi.fn(), warn: vi.fn(), error: vi.fn() }); + + /** + * @returns the logger the handler resolved for the request, observed via + * setRequestTimeout, which receives it as its last argument. + */ + const getEffectiveLogger = async (handler: NodeHttpHandler) => { + const spy = vi.spyOn(setRequestTimeoutModule, "setRequestTimeout"); + spy.mockClear(); + const request = new HttpRequest({ hostname: "localhost", method: "GET", protocol: "https:", path: "/" }); + try { + await handler.handle(request); + } catch { + // ignore request errors + } + return spy.mock.calls[0][4]; + }; + + it("updates non-logger keys", async () => { + const handler = new NodeHttpHandler({ requestTimeout: 1000 }); + handler.updateHttpClientConfig("requestTimeout", 5000); + + const request = new HttpRequest({ hostname: "localhost", method: "GET", protocol: "https:", path: "/" }); + try { + await handler.handle(request); + } catch { + // ignore request errors + } + + const configs = handler.httpHandlerConfigs(); + expect(configs.requestTimeout).toBe(5000); + }); + + it("uses the fallback logger when the handler has no logger of its own", async () => { + const handler = new NodeHttpHandler(); + const clientLogger = createLogger(); + + handler.updateHttpClientConfig(FALLBACK_LOGGER, clientLogger); + + expect(await getEffectiveLogger(handler)).toBe(clientLogger); + }); + + it("keeps the handler's explicit logger instead of the fallback logger", async () => { + const handlerLogger = createLogger(); + const handler = new NodeHttpHandler({ logger: handlerLogger }); + const clientLogger = createLogger(); + + handler.updateHttpClientConfig(FALLBACK_LOGGER, clientLogger); + + expect(await getEffectiveLogger(handler)).toBe(handlerLogger); + }); + + it("accepts the fallback logger synchronously while config resolves asynchronously", async () => { + let resolveOptions: (o: NodeHttpHandlerOptions) => void; + const handler = new NodeHttpHandler( + () => new Promise((resolve) => (resolveOptions = resolve)) + ); + const clientLogger = createLogger(); + + // Offered before the handler's own config has resolved. + handler.updateHttpClientConfig(FALLBACK_LOGGER, clientLogger); + resolveOptions!({}); + + expect(await getEffectiveLogger(handler)).toBe(clientLogger); + }); + + it("keeps an explicit logger that resolves asynchronously, over the fallback logger", async () => { + const handlerLogger = createLogger(); + const handler = new NodeHttpHandler(async () => ({ logger: handlerLogger })); + const clientLogger = createLogger(); + + handler.updateHttpClientConfig(FALLBACK_LOGGER, clientLogger); + + expect(await getEffectiveLogger(handler)).toBe(handlerLogger); + }); + + it("stores the fallback logger under the handler's own logger key", async () => { + const handler = new NodeHttpHandler(); + const clientLogger = createLogger(); + + handler.updateHttpClientConfig(FALLBACK_LOGGER, clientLogger); + await getEffectiveLogger(handler); + + expect(handler.httpHandlerConfigs().logger).toBe(clientLogger); + }); + }); + describe("checkSocketUsage", () => { beforeEach(() => { vi.spyOn(console, "warn").mockImplementation(vi.fn() as any); diff --git a/packages/node-http-handler/src/node-http-handler.ts b/packages/node-http-handler/src/node-http-handler.ts index 7990cd3addd..bb0de9a5f57 100644 --- a/packages/node-http-handler/src/node-http-handler.ts +++ b/packages/node-http-handler/src/node-http-handler.ts @@ -143,6 +143,7 @@ or increase socketAcquisitionWarningTimeout=(millis) in the NodeHttpHandler conf } const config = this.config!; + const logger = config.logger; // determine which http(s) client to use const isSSL = request.protocol === "https:"; @@ -208,11 +209,7 @@ or increase socketAcquisitionWarningTimeout=(millis) in the NodeHttpHandler conf // This warning will be cancelled if the request resolves. socketWarningTimeoutId = timing.setTimeout( () => { - this.socketWarningTimestamp = NodeHttpHandler.checkSocketUsage( - agent!, - this.socketWarningTimestamp, - config.logger - ); + this.socketWarningTimestamp = NodeHttpHandler.checkSocketUsage(agent!, this.socketWarningTimestamp, logger); }, config.socketAcquisitionWarningTimeout ?? (config.requestTimeout ?? 2000) + (config.connectionTimeout ?? 1000) ); @@ -298,7 +295,7 @@ or increase socketAcquisitionWarningTimeout=(millis) in the NodeHttpHandler conf reject, effectiveRequestTimeout, config.throwOnRequestTimeout, - config.logger ?? console + logger ?? console ); socketTimeoutId = setSocketTimeout(req, reject, config.socketTimeout); @@ -325,6 +322,14 @@ or increase socketAcquisitionWarningTimeout=(millis) in the NodeHttpHandler conf public updateHttpClientConfig(key: keyof NodeHttpHandlerOptions, value: NodeHttpHandlerOptions[typeof key]): void { this.config = undefined; this.configProvider = this.configProvider.then((config) => { + if ((key as unknown) === Symbol.for("logger")) { + // A client offers its logger under this key: take it only if this + // handler has no logger of its own. + return { + ...config, + logger: config.logger ?? (value as Logger), + }; + } return { ...config, [key]: value, diff --git a/packages/undici-http-handler/src/undici-http-handler.spec.ts b/packages/undici-http-handler/src/undici-http-handler.spec.ts index a11cc742c66..18d0d7325f5 100644 --- a/packages/undici-http-handler/src/undici-http-handler.spec.ts +++ b/packages/undici-http-handler/src/undici-http-handler.spec.ts @@ -4,7 +4,11 @@ import { HttpRequest } from "@smithy/core/protocols"; import { Agent, getGlobalDispatcher, setGlobalDispatcher, type Dispatcher } from "undici"; import { afterAll, afterEach, beforeAll, describe, expect, it, vi } from "vitest"; -import { UndiciHttpHandler } from "./undici-http-handler"; +import { UndiciHttpHandler, type UndiciHttpHandlerOptions } from "./undici-http-handler"; + +// Matches the key the client offers its logger under. `Symbol.for` makes this +// the same symbol the handler compares against. +const FALLBACK_LOGGER = Symbol.for("logger") as unknown as keyof UndiciHttpHandlerOptions; const { createServer } = http; @@ -561,17 +565,33 @@ describe("UndiciHttpHandler", () => { expect(configs.logger).toBe(logger); }); - it("updates config", async () => { + it("updates logger via updateHttpClientConfig", async () => { const logger = createMockLogger(); const updatedLogger = createMockLogger(); handler = new UndiciHttpHandler({ logger }); await handler.handle(createMockRequest()); handler.updateHttpClientConfig("logger", updatedLogger); - // Config is reset, need another request to resolve await handler.handle(createMockRequest()); expect(handler.httpHandlerConfigs().logger).toBe(updatedLogger); }); + it("does not overwrite an explicit logger with the fallback logger", async () => { + const logger = createMockLogger(); + const clientLogger = createMockLogger(); + handler = new UndiciHttpHandler({ logger }); + handler.updateHttpClientConfig(FALLBACK_LOGGER, clientLogger); + await handler.handle(createMockRequest()); + expect(handler.httpHandlerConfigs().logger).toBe(logger); + }); + + it("stores the fallback logger under the handler's own logger key", async () => { + handler = new UndiciHttpHandler(); + const clientLogger = createMockLogger(); + handler.updateHttpClientConfig(FALLBACK_LOGGER, clientLogger); + await handler.handle(createMockRequest()); + expect(handler.httpHandlerConfigs().logger).toBe(clientLogger); + }); + it("retains existing dispatcher if undefined is passed", () => { handler = new UndiciHttpHandler(); const configBefore = handler.httpHandlerConfigs(); diff --git a/packages/undici-http-handler/src/undici-http-handler.ts b/packages/undici-http-handler/src/undici-http-handler.ts index 0ad62a80adb..b3453452cbf 100644 --- a/packages/undici-http-handler/src/undici-http-handler.ts +++ b/packages/undici-http-handler/src/undici-http-handler.ts @@ -213,6 +213,13 @@ export class UndiciHttpHandler implements HttpHandler key: K, value: UndiciHttpHandlerOptions[K] ): void { + if ((key as unknown) === Symbol.for("logger")) { + // A client offers its logger under this key: take it only if this + // handler has no logger of its own. + this.config.logger ??= value as Logger; + return; + } + if (key !== "dispatcher") { (this.config as any)[key] = value; return;