Duplicated execution in node lambda function coldstar

Let the following lambda handler:

export const handler = async (event:any) => {

    console.log("[PROCESS] Starting process");

    return {status: "OK"};
}

And when executed from the AWS test console. The cloudWatch logs show the following.

As shown in the logs there is a duplication in the log info message, but the first one has an undefined request ID. This happens in coldstart, is this a normal behavior for lambda?

Just in case this is the esbuild command that I'm using for bundling the code of this lambda function.

esbuild ./src/my-lambda/index.ts --bundle --sourcemap --platform=node --target=es2020 --loader:.node=file --outfile=dist/lambda-functions/my-lambda/index.js

Solution

Yes, this is normal behavior for AWS Lambda during cold starts. The duplicate log with an undefined request ID occurs because:

Cold start initialization: When Lambda creates a new container, it runs your module-level code (imports, global variables) before the first invocation
Console.log timing: Your console.log statement executes during the handler invocation, but Lambda's logging infrastructure may not have fully initialized the request context yet
Request ID assignment: The request ID is assigned when the actual invocation begins, not during the initialization phase

Here is more about Cold starts and latency from AWS Lambda documentation.

You can the awsRequestId as it is always available so you can identify each invocation in your logs:

export const handler = async (event:any, context: any) => {
  console.log(`[PROCESS] Starting process ${context.awsRequestId}`);
  
  return {status: "OK"};
}