From 6f336a6015dfc4df8984222180d44b04e8003e54 Mon Sep 17 00:00:00 2001 From: Pooya Paridel Date: Fri, 5 Sep 2025 13:28:39 -0700 Subject: [PATCH] refactor: replace Telemetry with typed contexts and modernize logger architecture - Remove Telemetry interface and StructuredLogger in favor of OperationContext pattern - Add StepContext, WaitForConditionContext, and WaitForCallbackContext as type aliases - Replace structured-logger with context-logger for better step-aware logging - Extract createDefaultLogger from durable-context to utils/logger/default-logger - Unify attempt numbering in wait-for-condition handler (remove duplicate variables) - Use step's built-in logger in wait-for-callback handler instead of manual creation - Update all function signatures from Telemetry to specific context types - Rename configureLogger to setCustomLogger for consistency - Add tests for new logger utilities --- .../bundle-size-history.json | 2 +- .../durable-context/durable-context.test.ts | 45 +++- .../durable-context/durable-context.ts | 25 +- .../step-handler/step-handler.test.ts | 15 +- .../src/handlers/step-handler/step-handler.ts | 36 +-- .../wait-for-callback-handler.test.ts | 9 + .../wait-for-callback-handler.ts | 13 +- .../wait-for-condition-handler.test.ts | 10 + .../wait-for-condition-handler.ts | 36 ++- .../src/index.ts | 5 - .../src/types/index.ts | 23 +- .../src/utils/logger/context-logger.test.ts | 212 +++++++++++++++++ .../src/utils/logger/context-logger.ts | 55 +++++ .../src/utils/logger/custom-logger.test.ts | 126 ---------- .../src/utils/logger/default-logger.test.ts | 80 +++++++ .../src/utils/logger/default-logger.ts | 15 ++ .../utils/logger/structured-logger.test.ts | 221 ------------------ .../src/utils/logger/structured-logger.ts | 89 ------- 18 files changed, 521 insertions(+), 496 deletions(-) create mode 100644 packages/lambda-durable-functions-sdk-js/src/utils/logger/context-logger.test.ts create mode 100644 packages/lambda-durable-functions-sdk-js/src/utils/logger/context-logger.ts delete mode 100644 packages/lambda-durable-functions-sdk-js/src/utils/logger/custom-logger.test.ts create mode 100644 packages/lambda-durable-functions-sdk-js/src/utils/logger/default-logger.test.ts create mode 100644 packages/lambda-durable-functions-sdk-js/src/utils/logger/default-logger.ts delete mode 100644 packages/lambda-durable-functions-sdk-js/src/utils/logger/structured-logger.test.ts delete mode 100644 packages/lambda-durable-functions-sdk-js/src/utils/logger/structured-logger.ts diff --git a/packages/lambda-durable-functions-sdk-js/bundle-size-history.json b/packages/lambda-durable-functions-sdk-js/bundle-size-history.json index bd99aeb6..ad749bb3 100644 --- a/packages/lambda-durable-functions-sdk-js/bundle-size-history.json +++ b/packages/lambda-durable-functions-sdk-js/bundle-size-history.json @@ -194,4 +194,4 @@ "size": 214426, "gitCommit": "9801dc79f2a4a980f971e2de1b85aa23b4c7a579" } -] \ No newline at end of file +] diff --git a/packages/lambda-durable-functions-sdk-js/src/context/durable-context/durable-context.test.ts b/packages/lambda-durable-functions-sdk-js/src/context/durable-context/durable-context.test.ts index 058ab941..23d581ad 100644 --- a/packages/lambda-durable-functions-sdk-js/src/context/durable-context/durable-context.test.ts +++ b/packages/lambda-durable-functions-sdk-js/src/context/durable-context/durable-context.test.ts @@ -136,7 +136,8 @@ describe("Durable Context", () => { mockExecutionContext, mockCheckpointHandler, mockParentContext, - expect.any(Function), + expect.any(Function), // createStepId + expect.any(Function), // createContextLogger ); expect(mockStepHandler).toHaveBeenCalledWith("test-step", stepFn, options); }); @@ -428,7 +429,7 @@ describe("Durable Context", () => { mockExecutionContext, mockParentContext, ); - expect(typeof durableContext.configureLogger).toBe("function"); + expect(typeof durableContext.setCustomLogger).toBe("function"); }); it("should configure custom logger through DurableContext", () => { @@ -446,13 +447,49 @@ describe("Durable Context", () => { }; // Configure custom logger - durableContext.configureLogger(mockCustomLogger); + durableContext.setCustomLogger(mockCustomLogger); // Verify that the custom logger was set by checking the setCustomLogger was called // Since the step handler is mocked, we can't test the full integration here // but we can verify the method exists and doesn't throw expect(() => - durableContext.configureLogger(mockCustomLogger), + durableContext.setCustomLogger(mockCustomLogger), ).not.toThrow(); }); + + it("should use default logger when no custom logger is set", () => { + const consoleSpy = jest.spyOn(console, "log").mockImplementation(); + + // Temporarily restore the real step handler to test actual logger usage + const originalCreateStepHandler = jest.requireActual( + "../../handlers/step-handler/step-handler", + ).createStepHandler; + (createStepHandler as jest.Mock).mockImplementationOnce( + originalCreateStepHandler, + ); + + const durableContext = createDurableContext( + mockExecutionContext, + mockParentContext, + ); + + // This will use the real step handler which will call the context logger + const stepFn = jest.fn().mockImplementation(async (ctx) => { + // Use all logger methods to ensure full coverage of createDefaultLogger + ctx.logger.log("custom", "test message"); + ctx.logger.info("info test"); + ctx.logger.error("error test", new Error("test")); + ctx.logger.warn("warn test"); + ctx.logger.debug("debug test"); + return "result"; + }); + + // This should trigger the default logger + durableContext.step("test-step", stepFn); + + // Verify console.log was called + expect(consoleSpy).toHaveBeenCalled(); + + consoleSpy.mockRestore(); + }); }); diff --git a/packages/lambda-durable-functions-sdk-js/src/context/durable-context/durable-context.ts b/packages/lambda-durable-functions-sdk-js/src/context/durable-context/durable-context.ts index f1b90316..d6ba43ea 100644 --- a/packages/lambda-durable-functions-sdk-js/src/context/durable-context/durable-context.ts +++ b/packages/lambda-durable-functions-sdk-js/src/context/durable-context/durable-context.ts @@ -29,7 +29,8 @@ import { createMapHandler } from "../../handlers/map-handler/map-handler"; import { createParallelHandler } from "../../handlers/parallel-handler/parallel-handler"; import { createPromiseHandler } from "../../handlers/promise-handler/promise-handler"; import { createConcurrentExecutionHandler } from "../../handlers/concurrent-execution-handler/concurrent-execution-handler"; -import { setCustomLogger } from "../../utils/logger/structured-logger"; +import { createContextLoggerFactory } from "../../utils/logger/context-logger"; +import { createDefaultLogger } from "../../utils/logger/default-logger"; export const createDurableContext = ( executionContext: ExecutionContext, @@ -37,6 +38,20 @@ export const createDurableContext = ( stepPrefix?: string, checkpointToken?: string, ): DurableContext => { + // Local logger state for this context instance + let contextLogger: Logger | null = null; + + // Local getter function for this context + const getLogger = (): Logger => { + return contextLogger || createDefaultLogger(); + }; + + // Create context logger factory + const createContextLogger = createContextLoggerFactory( + executionContext, + getLogger, + ); + let stepCounter = 0; const checkpoint = createCheckpoint(executionContext, checkpointToken || ""); @@ -55,6 +70,7 @@ export const createDurableContext = ( checkpoint, parentContext, createStepId, + createContextLogger, ); return stepHandler(nameOrFn, fnOrOptions, maybeOptions); }; @@ -153,8 +169,8 @@ export const createDurableContext = ( const promise = createPromiseHandler(step); - const configureLogger = (logger: Logger): void => { - setCustomLogger(logger); + const setCustomLogger = (logger: Logger): void => { + contextLogger = logger; }; return { @@ -168,6 +184,7 @@ export const createDurableContext = ( executionContext, checkpoint, createStepId, + createContextLogger, ), createCallback, waitForCallback, @@ -175,6 +192,6 @@ export const createDurableContext = ( parallel, executeConcurrently, promise, - configureLogger, + setCustomLogger, }; }; diff --git a/packages/lambda-durable-functions-sdk-js/src/handlers/step-handler/step-handler.test.ts b/packages/lambda-durable-functions-sdk-js/src/handlers/step-handler/step-handler.test.ts index 21dfd3cf..de82494c 100644 --- a/packages/lambda-durable-functions-sdk-js/src/handlers/step-handler/step-handler.test.ts +++ b/packages/lambda-durable-functions-sdk-js/src/handlers/step-handler/step-handler.test.ts @@ -67,25 +67,36 @@ describe("Step Handler", () => { mockCheckpoint = createMockCheckpoint(); mockParentContext = { awsRequestId: "mock-request-id" }; createStepId = jest.fn().mockReturnValue("test-step-id"); + + const mockLogger = { + log: jest.fn(), + info: jest.fn(), + error: jest.fn(), + warn: jest.fn(), + debug: jest.fn(), + }; + const createMockEnrichedLogger = () => mockLogger; + stepHandler = createStepHandler( mockExecutionContext, mockCheckpoint, mockParentContext, createStepId, + createMockEnrichedLogger, ); // Reset the mock for retryPresets.default (retryPresets.default as jest.Mock).mockReset(); }); - test("should execute step function with Telemetry", async () => { + test("should execute step function with StepContext", async () => { const stepFn = jest.fn().mockResolvedValue("step-result"); const result = await stepHandler("test-step", stepFn); expect(result).toBe("step-result"); expect(stepFn).toHaveBeenCalledTimes(1); - // Verify that Telemetry was passed to the step function + // Verify that StepContext was passed to the step function expect(stepFn.mock.calls[0].length).toBe(1); expect(stepFn.mock.calls[0][0]).toHaveProperty("logger"); }); diff --git a/packages/lambda-durable-functions-sdk-js/src/handlers/step-handler/step-handler.ts b/packages/lambda-durable-functions-sdk-js/src/handlers/step-handler/step-handler.ts index 40e5eacf..67f60c36 100644 --- a/packages/lambda-durable-functions-sdk-js/src/handlers/step-handler/step-handler.ts +++ b/packages/lambda-durable-functions-sdk-js/src/handlers/step-handler/step-handler.ts @@ -5,7 +5,8 @@ import { RetryDecision, StepSemantics, OperationSubType, - Telemetry, + StepContext, + Logger, } from "../../types"; import { Context } from "aws-lambda"; import { @@ -26,7 +27,6 @@ import { import { isUnrecoverableError } from "../../errors/unrecoverable-error/unrecoverable-error"; import { OperationInterceptor } from "../../mocks/operation-interceptor"; import { createErrorObjectFromError } from "../../utils/error-object/error-object"; -import { createStructuredLogger } from "../../utils/logger/structured-logger"; const waitForTimer = ( context: ExecutionContext, @@ -39,7 +39,7 @@ const waitForTimer = ( reason: TerminationReason.RETRY_SCHEDULED, message: `Retry scheduled for ${name || stepId}`, }); - return new Promise(() => { }); + return new Promise(() => {}); }; export const createStepHandler = ( @@ -47,6 +47,7 @@ export const createStepHandler = ( checkpoint: ReturnType, parentContext: Context, createStepId: () => string, + createContextLogger: (stepId: string, attempt?: number) => Logger, ) => { return async ( nameOrFn: string | undefined | StepFunc, @@ -158,7 +159,15 @@ export const createStepHandler = ( // READY: Timer completed, execute step function // STARTED: Retry after error (AtLeastOncePerRetry semantics), execute step function // undefined: First execution, execute step function - return executeStep(context, checkpoint, stepId, name, fn, options); + return executeStep( + context, + checkpoint, + stepId, + name, + fn, + createContextLogger, + options, + ); }; }; @@ -195,6 +204,7 @@ export const executeStep = async ( stepId: string, name: string | undefined, fn: StepFunc, + createContextLogger: (stepId: string, attempt?: number) => Logger, options?: StepConfig, ): Promise => { // Determine step semantics (default to AT_LEAST_ONCE_PER_RETRY if not specified) @@ -228,23 +238,19 @@ export const executeStep = async ( } try { - // Get current attempt number for logger + // Get current attempt number for logger enrichment const stepData = context.getStepData(stepId); const currentAttempt = stepData?.StepDetails?.Attempt || 0; - // Create telemetry with logger - const telemetry: Telemetry = { - logger: createStructuredLogger({ - stepId, - executionId: context.durableExecutionArn, - attempt: currentAttempt, - }), + // Create step context with enriched logger + const stepContext: StepContext = { + logger: createContextLogger(stepId, currentAttempt), }; - // Execute the step function with stepUtil + // Execute the step function with stepContext const result = await OperationInterceptor.forExecution( context.durableExecutionArn, - ).execute(name, () => fn(telemetry)); + ).execute(name, () => fn(stepContext)); // Serialize the result for consistency const serializedResult = await safeSerialize( @@ -309,7 +315,7 @@ export const executeStep = async ( }); // Return a never-resolving promise to ensure the execution doesn't continue - return new Promise(() => { }); + return new Promise(() => {}); } const stepData = context.getStepData(stepId); diff --git a/packages/lambda-durable-functions-sdk-js/src/handlers/wait-for-callback-handler/wait-for-callback-handler.test.ts b/packages/lambda-durable-functions-sdk-js/src/handlers/wait-for-callback-handler/wait-for-callback-handler.test.ts index 984749ba..d3b0f695 100644 --- a/packages/lambda-durable-functions-sdk-js/src/handlers/wait-for-callback-handler/wait-for-callback-handler.test.ts +++ b/packages/lambda-durable-functions-sdk-js/src/handlers/wait-for-callback-handler/wait-for-callback-handler.test.ts @@ -10,6 +10,15 @@ describe("waitForCallback handler", () => { let stepIdCounter: number; let mockRunInChildContext: jest.Mock; + const createMockLogger = () => ({ + log: jest.fn(), + info: jest.fn(), + error: jest.fn(), + warn: jest.fn(), + debug: jest.fn(), + }); + const createMockEnrichedLogger = () => createMockLogger(); + beforeEach(() => { stepIdCounter = 0; diff --git a/packages/lambda-durable-functions-sdk-js/src/handlers/wait-for-callback-handler/wait-for-callback-handler.ts b/packages/lambda-durable-functions-sdk-js/src/handlers/wait-for-callback-handler/wait-for-callback-handler.ts index c8283ea3..ebfce867 100644 --- a/packages/lambda-durable-functions-sdk-js/src/handlers/wait-for-callback-handler/wait-for-callback-handler.ts +++ b/packages/lambda-durable-functions-sdk-js/src/handlers/wait-for-callback-handler/wait-for-callback-handler.ts @@ -5,7 +5,9 @@ import { CreateCallbackConfig, DurableContext, OperationSubType, - Telemetry, + WaitForCallbackContext, + StepContext, + Logger, } from "../../types"; import { log } from "../../utils/logger/logger"; @@ -69,12 +71,17 @@ export const createWaitForCallbackHandler = ( }); // Execute the submitter step (submitter is now mandatory) - await childCtx.step(async (telemetry: Telemetry) => { + await childCtx.step(async (stepContext: StepContext) => { + // Use the step's built-in logger instead of creating a new one + const callbackContext: WaitForCallbackContext = { + logger: stepContext.logger, + }; + log(context.isVerbose, "📤", "Executing submitter:", { callbackId, name, }); - await submitter(callbackId, telemetry); + await submitter(callbackId, callbackContext); log(context.isVerbose, "✅", "Submitter completed:", { callbackId, name, diff --git a/packages/lambda-durable-functions-sdk-js/src/handlers/wait-for-condition-handler/wait-for-condition-handler.test.ts b/packages/lambda-durable-functions-sdk-js/src/handlers/wait-for-condition-handler/wait-for-condition-handler.test.ts index 145eb554..ea361fbb 100644 --- a/packages/lambda-durable-functions-sdk-js/src/handlers/wait-for-condition-handler/wait-for-condition-handler.test.ts +++ b/packages/lambda-durable-functions-sdk-js/src/handlers/wait-for-condition-handler/wait-for-condition-handler.test.ts @@ -67,10 +67,20 @@ describe("WaitForCondition Handler", () => { mockExecutionRunner, ); + const mockLogger = { + log: jest.fn(), + info: jest.fn(), + error: jest.fn(), + warn: jest.fn(), + debug: jest.fn(), + }; + const createMockEnrichedLogger = () => mockLogger; + waitForConditionHandler = createWaitForConditionHandler( mockExecutionContext, mockCheckpoint, createStepId, + createMockEnrichedLogger, ); }); diff --git a/packages/lambda-durable-functions-sdk-js/src/handlers/wait-for-condition-handler/wait-for-condition-handler.ts b/packages/lambda-durable-functions-sdk-js/src/handlers/wait-for-condition-handler/wait-for-condition-handler.ts index 96ac1ac7..2a461b14 100644 --- a/packages/lambda-durable-functions-sdk-js/src/handlers/wait-for-condition-handler/wait-for-condition-handler.ts +++ b/packages/lambda-durable-functions-sdk-js/src/handlers/wait-for-condition-handler/wait-for-condition-handler.ts @@ -4,7 +4,8 @@ import { WaitForConditionConfig, WaitForConditionDecision, OperationSubType, - Telemetry, + WaitForConditionContext, + Logger, } from "../../types"; import { Context } from "aws-lambda"; import { @@ -13,7 +14,6 @@ import { OperationType, } from "@amzn/dex-internal-sdk"; import { log } from "../../utils/logger/logger"; -import { createStructuredLogger } from "../../utils/logger/structured-logger"; import { createCheckpoint } from "../../utils/checkpoint/checkpoint"; import { TerminationReason } from "../../termination-manager/types"; import { defaultSerdes } from "../../utils/serdes/serdes"; @@ -35,13 +35,14 @@ const waitForTimer = ( reason: TerminationReason.RETRY_SCHEDULED, message: `Retry scheduled for ${name || stepId}`, }); - return new Promise(() => { }); + return new Promise(() => {}); }; export const createWaitForConditionHandler = ( context: ExecutionContext, checkpoint: ReturnType, createStepId: () => string, + createContextLogger: (stepId: string, attempt?: number) => Logger, ) => { return async ( nameOrCheck: string | undefined | WaitForConditionCheckFunc, @@ -109,6 +110,7 @@ export const createWaitForConditionHandler = ( name, check, config, + createContextLogger, ); }; }; @@ -147,6 +149,7 @@ export const executeWaitForCondition = async ( name: string | undefined, check: WaitForConditionCheckFunc, config: WaitForConditionConfig, + createContextLogger: (stepId: string, attempt?: number) => Logger, ): Promise => { const serdes = config.serdes || defaultSerdes; @@ -189,10 +192,8 @@ export const executeWaitForCondition = async ( currentState = config.initialState; } - // Get the current attempt number from the system (like step-handler does) - const currentAttemptForLogging = existingOperation?.StepDetails?.Attempt || 0; - const currentAttemptForWaitStrategy = - existingOperation?.StepDetails?.Attempt || 1; + // Get the current attempt number (1-based for wait strategy consistency) + const currentAttempt = existingOperation?.StepDetails?.Attempt || 1; // Checkpoint START for observability (fire and forget) - only if not already started const stepData = context.getStepData(stepId); @@ -208,18 +209,15 @@ export const executeWaitForCondition = async ( } try { - // Create Telemetry with logger for the check function - const logger = createStructuredLogger({ - executionId: context.durableExecutionArn, - stepId, - attempt: currentAttemptForLogging, - }); - const telemetry: Telemetry = { logger }; + // Create WaitForConditionContext with enriched logger for the check function + const waitForConditionContext: WaitForConditionContext = { + logger: createContextLogger(stepId, currentAttempt), + }; // Execute the check function const newState = await OperationInterceptor.forExecution( context.durableExecutionArn, - ).execute(name, () => check(currentState, telemetry)); + ).execute(name, () => check(currentState, waitForConditionContext)); // Serialize the new state for consistency const serializedState = await safeSerialize( @@ -246,13 +244,13 @@ export const executeWaitForCondition = async ( // Check if condition is met using the wait strategy const decision: WaitForConditionDecision = config.waitStrategy( deserializedState, - currentAttemptForWaitStrategy, + currentAttempt, ); log(context.isVerbose, "🔍", "waitForCondition check completed:", { stepId, name, - currentAttempt: currentAttemptForWaitStrategy, + currentAttempt: currentAttempt, shouldContinue: decision.shouldContinue, delaySeconds: decision.shouldContinue ? decision.delaySeconds : undefined, }); @@ -273,7 +271,7 @@ export const executeWaitForCondition = async ( stepId, name, result: deserializedState, - totalAttempts: currentAttemptForWaitStrategy, + totalAttempts: currentAttempt, }); return deserializedState; @@ -300,7 +298,7 @@ export const executeWaitForCondition = async ( stepId, name, error, - currentAttempt: currentAttemptForWaitStrategy, + currentAttempt: currentAttempt, }); // Mark as failed - waitForCondition doesn't have its own retry logic for errors diff --git a/packages/lambda-durable-functions-sdk-js/src/index.ts b/packages/lambda-durable-functions-sdk-js/src/index.ts index f25ef2ce..775e5477 100644 --- a/packages/lambda-durable-functions-sdk-js/src/index.ts +++ b/packages/lambda-durable-functions-sdk-js/src/index.ts @@ -19,7 +19,6 @@ export { WaitForConditionDecision, WaitForConditionWaitStrategyFunc, Logger, - Telemetry, } from "./types"; export { StepInterruptedError } from "./errors/step-errors/step-errors"; export { InvocationDefinition } from "./storage/record-definition-storage"; @@ -35,7 +34,3 @@ export { createWaitStrategy, WaitStrategyConfig, } from "./utils/wait-strategy/wait-strategy-config"; -export { - setCustomLogger, - StructuredLogger, -} from "./utils/logger/structured-logger"; diff --git a/packages/lambda-durable-functions-sdk-js/src/types/index.ts b/packages/lambda-durable-functions-sdk-js/src/types/index.ts index 1a80e43d..d6cf74be 100644 --- a/packages/lambda-durable-functions-sdk-js/src/types/index.ts +++ b/packages/lambda-durable-functions-sdk-js/src/types/index.ts @@ -1,5 +1,4 @@ import { Context } from "aws-lambda"; -import { StructuredLogger } from "../utils/logger/structured-logger"; import { TerminationManager } from "../termination-manager/termination-manager"; import { ExecutionState } from "../storage/storage-provider"; import { Serdes } from "../utils/serdes/serdes"; @@ -153,7 +152,7 @@ export interface DurableContext extends Context { executorOrConfig?: ConcurrentExecutor | ConcurrencyConfig, maybeConfig?: ConcurrencyConfig, ) => Promise>; - configureLogger: (logger: Logger) => void; + setCustomLogger: (logger: Logger) => void; } export interface ExecutionContext { @@ -208,7 +207,7 @@ export interface WaitForCallbackConfig { export type CreateCallbackResult = [Promise, string]; // [promise, callbackId] export type WaitForCallbackSubmitterFunc = ( callbackId: string, - telemetry: Telemetry, + context: WaitForCallbackContext, ) => Promise; // Generic logger interface for custom logger implementations @@ -220,11 +219,21 @@ export interface Logger { debug(message?: string, data?: any): void; } -export interface Telemetry { - logger: StructuredLogger; +/** + * Base interface for operation contexts. + * Do not use directly - use specific context types like StepContext, WaitForConditionContext, etc. + */ +export interface OperationContext { + logger: Logger; } -export type StepFunc = (telemetry: Telemetry) => Promise; +export type StepContext = OperationContext; + +export type WaitForConditionContext = OperationContext; + +export type WaitForCallbackContext = OperationContext; + +export type StepFunc = (context: StepContext) => Promise; export type ChildFunc = (context: DurableContext) => Promise; export type MapFunc = ( context: DurableContext, @@ -237,7 +246,7 @@ export type ParallelFunc = (context: DurableContext) => Promise; // Wait for condition types export type WaitForConditionCheckFunc = ( state: T, - telemetry: Telemetry, + context: WaitForConditionContext, ) => Promise; export type WaitForConditionWaitStrategyFunc = ( state: T, diff --git a/packages/lambda-durable-functions-sdk-js/src/utils/logger/context-logger.test.ts b/packages/lambda-durable-functions-sdk-js/src/utils/logger/context-logger.test.ts new file mode 100644 index 00000000..4a3864b7 --- /dev/null +++ b/packages/lambda-durable-functions-sdk-js/src/utils/logger/context-logger.test.ts @@ -0,0 +1,212 @@ +import { createContextLoggerFactory } from "./context-logger"; +import { Logger, ExecutionContext } from "../../types"; + +describe("Context Logger", () => { + let mockBaseLogger: Logger; + let mockGetLogger: () => Logger; + let mockExecutionContext: ExecutionContext; + + beforeEach(() => { + mockBaseLogger = { + log: jest.fn(), + info: jest.fn(), + error: jest.fn(), + warn: jest.fn(), + debug: jest.fn(), + }; + mockGetLogger = jest.fn().mockReturnValue(mockBaseLogger); + mockExecutionContext = { + durableExecutionArn: "test-execution-arn", + } as ExecutionContext; + }); + + test("should create context logger with enriched data", () => { + const factory = createContextLoggerFactory( + mockExecutionContext, + mockGetLogger, + ); + const logger = factory("test-step", 1); + + logger.info("test message", { key: "value" }); + + expect(mockBaseLogger.info).toHaveBeenCalledWith( + "test message", + expect.objectContaining({ + execution_arn: "test-execution-arn", + step_id: "test-step", + attempt: 1, + level: "info", + message: "test message", + data: { key: "value" }, + timestamp: expect.any(String), + }), + ); + }); + + test("should create context logger without attempt", () => { + const factory = createContextLoggerFactory( + mockExecutionContext, + mockGetLogger, + ); + const logger = factory("test-step"); + + logger.warn("warning"); + + expect(mockBaseLogger.warn).toHaveBeenCalledWith( + "warning", + expect.objectContaining({ + execution_arn: "test-execution-arn", + step_id: "test-step", + level: "warn", + message: "warning", + }), + ); + expect(mockBaseLogger.warn).toHaveBeenCalledWith( + "warning", + expect.not.objectContaining({ + attempt: expect.anything(), + }), + ); + }); + + test("should handle error logging with error object", () => { + const factory = createContextLoggerFactory( + mockExecutionContext, + mockGetLogger, + ); + const logger = factory("test-step"); + const testError = new Error("test error"); + + logger.error("error message", testError, { extra: "data" }); + + expect(mockBaseLogger.error).toHaveBeenCalledWith( + "error message", + testError, + expect.objectContaining({ + level: "error", + message: "error message", + data: { extra: "data" }, + error: { + name: "Error", + message: "test error", + stack: expect.any(String), + }, + }), + ); + }); + + test("should handle debug logging", () => { + const factory = createContextLoggerFactory( + mockExecutionContext, + mockGetLogger, + ); + const logger = factory("debug-step"); + + logger.debug("debug info"); + + expect(mockBaseLogger.debug).toHaveBeenCalledWith( + "debug info", + expect.objectContaining({ + level: "debug", + message: "debug info", + }), + ); + }); + + test("should handle generic log method", () => { + const factory = createContextLoggerFactory( + mockExecutionContext, + mockGetLogger, + ); + const logger = factory("generic-step"); + const testError = new Error("generic error"); + + logger.log("custom", "custom message", { custom: "data" }, testError); + + expect(mockBaseLogger.log).toHaveBeenCalledWith( + "custom", + "custom message", + expect.objectContaining({ + level: "custom", + message: "custom message", + data: { custom: "data" }, + error: { + name: "Error", + message: "generic error", + stack: expect.any(String), + }, + }), + testError, + ); + }); + + test("should work with default logger fallback", () => { + const consoleSpy = jest.spyOn(console, "log").mockImplementation(); + + // Create a default logger that mimics the one in durable-context + const createDefaultLogger = (): Logger => ({ + log: (level: string, message?: string, data?: any, error?: Error) => + console.log(level, message, data, error), + info: (message?: string, data?: any) => + console.log("info", message, data), + error: (message?: string, error?: Error, data?: any) => + console.log("error", message, error, data), + warn: (message?: string, data?: any) => + console.log("warn", message, data), + debug: (message?: string, data?: any) => + console.log("debug", message, data), + }); + + const defaultLogger = createDefaultLogger(); + const getDefaultLogger = () => defaultLogger; + + const factory = createContextLoggerFactory( + mockExecutionContext, + getDefaultLogger, + ); + const logger = factory("test-step"); + + // Test all logger methods to ensure coverage + logger.log( + "custom", + "log message", + { data: "test" }, + new Error("test error"), + ); + logger.info("info message", { info: "data" }); + logger.error("error message", new Error("test error"), { error: "data" }); + logger.warn("warn message", { warn: "data" }); + logger.debug("debug message", { debug: "data" }); + + // Verify console.log was called (default logger was used) + expect(consoleSpy).toHaveBeenCalledWith( + "custom", + "log message", + expect.any(Object), + expect.any(Error), + ); + expect(consoleSpy).toHaveBeenCalledWith( + "info", + "info message", + expect.any(Object), + ); + expect(consoleSpy).toHaveBeenCalledWith( + "error", + "error message", + expect.any(Error), + expect.any(Object), + ); + expect(consoleSpy).toHaveBeenCalledWith( + "warn", + "warn message", + expect.any(Object), + ); + expect(consoleSpy).toHaveBeenCalledWith( + "debug", + "debug message", + expect.any(Object), + ); + + consoleSpy.mockRestore(); + }); +}); diff --git a/packages/lambda-durable-functions-sdk-js/src/utils/logger/context-logger.ts b/packages/lambda-durable-functions-sdk-js/src/utils/logger/context-logger.ts new file mode 100644 index 00000000..23c7532b --- /dev/null +++ b/packages/lambda-durable-functions-sdk-js/src/utils/logger/context-logger.ts @@ -0,0 +1,55 @@ +import { Logger, ExecutionContext } from "../../types"; + +export const createContextLoggerFactory = ( + executionContext: ExecutionContext, + getLogger: () => Logger, +) => { + return (stepId: string, attempt?: number): Logger => { + const baseLogger = getLogger(); + + const createLogEntry = ( + level: string, + message?: string, + data?: any, + error?: Error, + ) => ({ + timestamp: new Date().toISOString(), + execution_arn: executionContext.durableExecutionArn, + step_id: stepId, + ...(attempt !== undefined && { attempt }), + level, + ...(message && { message }), + ...(data && { data }), + ...(error && { + error: { name: error.name, message: error.message, stack: error.stack }, + }), + }); + + return { + log: (level: string, message?: string, data?: any, error?: Error) => { + baseLogger.log( + level, + message, + createLogEntry(level, message, data, error), + error, + ); + }, + info: (message?: string, data?: any) => { + baseLogger.info(message, createLogEntry("info", message, data)); + }, + error: (message?: string, error?: Error, data?: any) => { + baseLogger.error( + message, + error, + createLogEntry("error", message, data, error), + ); + }, + warn: (message?: string, data?: any) => { + baseLogger.warn(message, createLogEntry("warn", message, data)); + }, + debug: (message?: string, data?: any) => { + baseLogger.debug(message, createLogEntry("debug", message, data)); + }, + }; + }; +}; diff --git a/packages/lambda-durable-functions-sdk-js/src/utils/logger/custom-logger.test.ts b/packages/lambda-durable-functions-sdk-js/src/utils/logger/custom-logger.test.ts deleted file mode 100644 index 1629536d..00000000 --- a/packages/lambda-durable-functions-sdk-js/src/utils/logger/custom-logger.test.ts +++ /dev/null @@ -1,126 +0,0 @@ -import { createStructuredLogger, setCustomLogger } from "./structured-logger"; -import { Logger } from "../../types"; - -describe("Custom Logger Integration", () => { - let mockCustomLogger: jest.Mocked; - let consoleSpy: jest.SpyInstance; - - beforeEach(() => { - consoleSpy = jest.spyOn(console, "log").mockImplementation(); - mockCustomLogger = { - log: jest.fn(), - error: jest.fn(), - warn: jest.fn(), - info: jest.fn(), - debug: jest.fn(), - }; - }); - - afterEach(() => { - consoleSpy.mockRestore(); - setCustomLogger(null); // Reset custom logger - }); - - it("should use default JSON logging when no custom logger is set", () => { - const logger = createStructuredLogger({ - executionId: "test-execution", - stepId: "test-step", - attempt: 1, - }); - - logger.info("Test message", { key: "value" }); - - expect(consoleSpy).toHaveBeenCalledWith( - expect.stringContaining('"level":"info"'), - ); - expect(consoleSpy).toHaveBeenCalledWith( - expect.stringContaining('"message":"Test message"'), - ); - }); - - it("should use custom logger when configured", () => { - setCustomLogger(mockCustomLogger); - - const logger = createStructuredLogger({ - executionId: "test-execution", - stepId: "test-step", - attempt: 1, - }); - - logger.info("Test message", { key: "value" }); - - expect(mockCustomLogger.info).toHaveBeenCalledWith("Test message", { - key: "value", - }); - expect(consoleSpy).not.toHaveBeenCalled(); - }); - - it("should use custom logger for error logging", () => { - setCustomLogger(mockCustomLogger); - - const logger = createStructuredLogger({ - executionId: "test-execution", - stepId: "test-step", - attempt: 1, - }); - - const testError = new Error("Test error"); - logger.error("Error occurred", testError, { context: "test" }); - - expect(mockCustomLogger.error).toHaveBeenCalledWith( - "Error occurred", - testError, - { context: "test" }, - ); - expect(consoleSpy).not.toHaveBeenCalled(); - }); - - it("should use custom logger for all log levels", () => { - setCustomLogger(mockCustomLogger); - - const logger = createStructuredLogger({ - executionId: "test-execution", - stepId: "test-step", - attempt: 1, - }); - - logger.debug("Debug message", { debug: true }); - logger.info("Info message", { info: true }); - logger.warn("Warn message", { warn: true }); - logger.error("Error message", new Error("test"), { error: true }); - - expect(mockCustomLogger.debug).toHaveBeenCalledWith("Debug message", { - debug: true, - }); - expect(mockCustomLogger.info).toHaveBeenCalledWith("Info message", { - info: true, - }); - expect(mockCustomLogger.warn).toHaveBeenCalledWith("Warn message", { - warn: true, - }); - expect(mockCustomLogger.error).toHaveBeenCalledWith( - "Error message", - new Error("test"), - { error: true }, - ); - expect(consoleSpy).not.toHaveBeenCalled(); - }); - - it("should revert to default logging when custom logger is removed", () => { - setCustomLogger(mockCustomLogger); - setCustomLogger(null); // Remove custom logger - - const logger = createStructuredLogger({ - executionId: "test-execution", - stepId: "test-step", - attempt: 1, - }); - - logger.info("Test message"); - - expect(mockCustomLogger.info).not.toHaveBeenCalled(); - expect(consoleSpy).toHaveBeenCalledWith( - expect.stringContaining('"level":"info"'), - ); - }); -}); diff --git a/packages/lambda-durable-functions-sdk-js/src/utils/logger/default-logger.test.ts b/packages/lambda-durable-functions-sdk-js/src/utils/logger/default-logger.test.ts new file mode 100644 index 00000000..3a46b12c --- /dev/null +++ b/packages/lambda-durable-functions-sdk-js/src/utils/logger/default-logger.test.ts @@ -0,0 +1,80 @@ +import { createDefaultLogger } from "./default-logger"; + +describe("Default Logger", () => { + let consoleSpy: jest.SpyInstance; + + beforeEach(() => { + consoleSpy = jest.spyOn(console, "log").mockImplementation(); + }); + + afterEach(() => { + consoleSpy.mockRestore(); + }); + + it("should create a logger with all required methods", () => { + const logger = createDefaultLogger(); + + expect(logger).toHaveProperty("log"); + expect(logger).toHaveProperty("info"); + expect(logger).toHaveProperty("error"); + expect(logger).toHaveProperty("warn"); + expect(logger).toHaveProperty("debug"); + }); + + it("should log with custom level and all parameters", () => { + const logger = createDefaultLogger(); + const testData = { key: "value" }; + const testError = new Error("test error"); + + logger.log("custom", "test message", testData, testError); + + expect(consoleSpy).toHaveBeenCalledWith( + "custom", + "test message", + testData, + testError, + ); + }); + + it("should log info messages", () => { + const logger = createDefaultLogger(); + const testData = { info: "data" }; + + logger.info("info message", testData); + + expect(consoleSpy).toHaveBeenCalledWith("info", "info message", testData); + }); + + it("should log error messages", () => { + const logger = createDefaultLogger(); + const testError = new Error("test error"); + const testData = { error: "data" }; + + logger.error("error message", testError, testData); + + expect(consoleSpy).toHaveBeenCalledWith( + "error", + "error message", + testError, + testData, + ); + }); + + it("should log warn messages", () => { + const logger = createDefaultLogger(); + const testData = { warn: "data" }; + + logger.warn("warn message", testData); + + expect(consoleSpy).toHaveBeenCalledWith("warn", "warn message", testData); + }); + + it("should log debug messages", () => { + const logger = createDefaultLogger(); + const testData = { debug: "data" }; + + logger.debug("debug message", testData); + + expect(consoleSpy).toHaveBeenCalledWith("debug", "debug message", testData); + }); +}); diff --git a/packages/lambda-durable-functions-sdk-js/src/utils/logger/default-logger.ts b/packages/lambda-durable-functions-sdk-js/src/utils/logger/default-logger.ts new file mode 100644 index 00000000..6e219c47 --- /dev/null +++ b/packages/lambda-durable-functions-sdk-js/src/utils/logger/default-logger.ts @@ -0,0 +1,15 @@ +import { Logger } from "../../types"; + +/** + * Creates a default logger that outputs to console. + * Used as fallback when no custom logger is provided. + */ +export const createDefaultLogger = (): Logger => ({ + log: (level: string, message?: string, data?: any, error?: Error) => + console.log(level, message, data, error), + info: (message?: string, data?: any) => console.log("info", message, data), + error: (message?: string, error?: Error, data?: any) => + console.log("error", message, error, data), + warn: (message?: string, data?: any) => console.log("warn", message, data), + debug: (message?: string, data?: any) => console.log("debug", message, data), +}); diff --git a/packages/lambda-durable-functions-sdk-js/src/utils/logger/structured-logger.test.ts b/packages/lambda-durable-functions-sdk-js/src/utils/logger/structured-logger.test.ts deleted file mode 100644 index 060fe033..00000000 --- a/packages/lambda-durable-functions-sdk-js/src/utils/logger/structured-logger.test.ts +++ /dev/null @@ -1,221 +0,0 @@ -import { createStructuredLogger, setCustomLogger } from "./structured-logger"; -import { hashId } from "../step-id-utils/step-id-utils"; - -describe("StructuredLogger", () => { - let consoleSpy: jest.SpyInstance; - - beforeEach(() => { - consoleSpy = jest.spyOn(console, "log").mockImplementation(); - setCustomLogger(null); // Reset custom logger before each test - }); - - afterEach(() => { - consoleSpy.mockRestore(); - setCustomLogger(null); // Clean up after each test - }); - - it("should log with basic context", () => { - const logger = createStructuredLogger({ - executionId: "test-execution-123", - }); - - logger.info("Test message", { key: "value" }); - - expect(consoleSpy).toHaveBeenCalledTimes(1); - const loggedData = JSON.parse(consoleSpy.mock.calls[0][0]); - - expect(loggedData).toMatchObject({ - level: "info", - message: "Test message", - execution_id: "test-execution-123", - data: { key: "value" }, - }); - expect(loggedData.timestamp).toBeDefined(); - expect(loggedData.stepId).toBeUndefined(); - expect(loggedData.attempt).toBeUndefined(); - }); - - it("should log with stepId and attempt", () => { - const logger = createStructuredLogger({ - executionId: "test-execution-123", - stepId: "step-1", - attempt: 2, - }); - - logger.error("Error occurred", new Error("Test error")); - - expect(consoleSpy).toHaveBeenCalledTimes(1); - const loggedData = JSON.parse(consoleSpy.mock.calls[0][0]); - - expect(loggedData).toMatchObject({ - level: "error", - message: "Error occurred", - execution_id: "test-execution-123", - step_id: hashId("step-1"), - attempt: 2, - }); - expect(loggedData.error).toMatchObject({ - name: "Error", - message: "Test error", - }); - expect(loggedData.error.stack).toBeDefined(); - expect(loggedData.timestamp).toBeDefined(); - }); - - it("should omit undefined fields", () => { - const logger = createStructuredLogger({ - executionId: "test-execution-123", - stepId: undefined, - attempt: undefined, - }); - - logger.warn("Warning message"); - - expect(consoleSpy).toHaveBeenCalledTimes(1); - const loggedData = JSON.parse(consoleSpy.mock.calls[0][0]); - - expect(loggedData).toMatchObject({ - level: "warn", - message: "Warning message", - execution_id: "test-execution-123", - }); - expect(loggedData.timestamp).toBeDefined(); - expect(loggedData).not.toHaveProperty("stepId"); - expect(loggedData).not.toHaveProperty("attempt"); - expect(loggedData).not.toHaveProperty("data"); - }); - - it("should handle all log levels", () => { - const logger = createStructuredLogger({ - executionId: "test-execution-123", - }); - - logger.debug("Debug message"); - logger.info("Info message"); - logger.warn("Warn message"); - logger.error("Error message"); - logger.log("Log message"); - - expect(consoleSpy).toHaveBeenCalledTimes(5); - - const logs = consoleSpy.mock.calls.map((call) => JSON.parse(call[0])); - expect(logs[0].level).toBe("debug"); - expect(logs[1].level).toBe("info"); - expect(logs[2].level).toBe("warn"); - expect(logs[3].level).toBe("error"); - expect(logs[4].level).toBe("info"); // log() maps to info level - }); - - it("should log with only data (no message)", () => { - const consoleSpy = jest.spyOn(console, "log").mockImplementation(); - const logger = createStructuredLogger({ - executionId: "test-execution", - stepId: "test-step", - attempt: 1, - }); - - logger.info(undefined, { key: "value", count: 42 }); - - expect(consoleSpy).toHaveBeenCalledTimes(1); - const loggedData = JSON.parse(consoleSpy.mock.calls[0][0]); - - expect(loggedData).toEqual({ - timestamp: expect.any(String), - level: "info", - execution_id: "test-execution", - step_id: hashId("test-step"), - attempt: 1, - data: { key: "value", count: 42 }, - }); - - // Verify that message field is not present - expect(loggedData).not.toHaveProperty("message"); - - consoleSpy.mockRestore(); - }); - - it("should use custom logger when set for all methods", () => { - const mockCustomLogger = { - log: jest.fn(), - error: jest.fn(), - warn: jest.fn(), - info: jest.fn(), - debug: jest.fn(), - }; - - setCustomLogger(mockCustomLogger); - - const logger = createStructuredLogger({ - executionId: "test-execution", - stepId: "test-step", - attempt: 1, - }); - - // Test log method (maps to info) - logger.log("Test log message", { data: "test" }); - expect(mockCustomLogger.info).toHaveBeenCalledWith("Test log message", { - data: "test", - }); - - // Test error method - const testError = new Error("Test error"); - logger.error("Error message", testError, { context: "test" }); - expect(mockCustomLogger.error).toHaveBeenCalledWith( - "Error message", - testError, - { context: "test" }, - ); - - // Test warn method - logger.warn("Warning message", { warning: true }); - expect(mockCustomLogger.warn).toHaveBeenCalledWith("Warning message", { - warning: true, - }); - - // Test info method - logger.info("Info message", { info: true }); - expect(mockCustomLogger.info).toHaveBeenCalledWith("Info message", { - info: true, - }); - - // Test debug method - logger.debug("Debug message", { debug: true }); - expect(mockCustomLogger.debug).toHaveBeenCalledWith("Debug message", { - debug: true, - }); - - // Ensure console.log was not called - expect(consoleSpy).not.toHaveBeenCalled(); - }); - - it("should use custom logger for logWithContext internal calls", () => { - const mockCustomLogger = { - log: jest.fn(), - error: jest.fn(), - warn: jest.fn(), - info: jest.fn(), - debug: jest.fn(), - }; - - setCustomLogger(mockCustomLogger); - - const logger = createStructuredLogger({ - executionId: "test-execution", - stepId: "test-step", - attempt: 1, - }); - - // This will trigger the logWithContext function with custom logger - logger.error("Error message", new Error("Test error"), { context: "test" }); - - // Verify the custom logger's log method was called through logWithContext - expect(mockCustomLogger.error).toHaveBeenCalledWith( - "Error message", - expect.any(Error), - { context: "test" }, - ); - - // Ensure console.log was not called (testing the return path) - expect(consoleSpy).not.toHaveBeenCalled(); - }); -}); diff --git a/packages/lambda-durable-functions-sdk-js/src/utils/logger/structured-logger.ts b/packages/lambda-durable-functions-sdk-js/src/utils/logger/structured-logger.ts deleted file mode 100644 index 3799a6dc..00000000 --- a/packages/lambda-durable-functions-sdk-js/src/utils/logger/structured-logger.ts +++ /dev/null @@ -1,89 +0,0 @@ -import { hashId } from "../step-id-utils/step-id-utils"; -import { Logger } from "../../types"; - -export interface LogContext { - stepId?: string; - executionId: string; - attempt?: number; -} - -export interface StructuredLogger { - log(message?: string, data?: any): void; - error(message?: string, error?: Error, data?: any): void; - warn(message?: string, data?: any): void; - info(message?: string, data?: any): void; - debug(message?: string, data?: any): void; -} - -// Global custom logger instance -let customLogger: Logger | null = null; - -export const setCustomLogger = (logger: Logger | null): void => { - customLogger = logger; -}; - -export const createStructuredLogger = ( - context: LogContext, -): StructuredLogger => { - const logWithContext = ( - level: string, - message?: string, - data?: any, - error?: Error, - ) => { - const logEntry = { - timestamp: new Date().toISOString(), - level, - ...(message && { message }), - execution_id: context.executionId, - ...(context.stepId && { step_id: hashId(context.stepId) }), - ...(context.attempt !== undefined && { - attempt: context.attempt, - }), - ...(data && { data }), - ...(error && { - error: { name: error.name, message: error.message, stack: error.stack }, - }), - }; - - console.log(JSON.stringify(logEntry)); - }; - - return { - log: (message?: string, data?: any) => { - if (customLogger) { - customLogger.info(message, data); - return; - } - logWithContext("info", message, data); - }, - error: (message?: string, error?: Error, data?: any) => { - if (customLogger) { - customLogger.error(message, error, data); - return; - } - logWithContext("error", message, data, error); - }, - warn: (message?: string, data?: any) => { - if (customLogger) { - customLogger.warn(message, data); - return; - } - logWithContext("warn", message, data); - }, - info: (message?: string, data?: any) => { - if (customLogger) { - customLogger.info(message, data); - return; - } - logWithContext("info", message, data); - }, - debug: (message?: string, data?: any) => { - if (customLogger) { - customLogger.debug(message, data); - return; - } - logWithContext("debug", message, data); - }, - }; -};