Bug: Exception instead of warning when log level doesn't match AWS log level

[deffer]

Expected Behaviour

Expect a following warning when the Application log level of AWS Lambda configuration is set to INFO while powertools level is set to DEBUG (via logLevel attribute of the ConstructorOptions)

Current log level (%s) does not match AWS Lambda Advanced Logging Controls minimum log level (%s). This can lead to data loss, consider adjusting them.

Current Behaviour

Lambda is failing with the following error:

{
    "timestamp": "2024-03-25T01:07:01.251Z",
    "level": "ERROR",
    "message": {
        "errorType": "TypeError",
        "errorMessage": "Cannot read properties of undefined (reading 'formatAttributes')",
        "stackTrace": [
            "TypeError: Cannot read properties of undefined (reading 'formatAttributes')",
            "    at Logger.createAndPopulateLogItem (file:///var/task/node_modules/@aws-lambda-powertools/logger/lib/esm/Logger.js:518:47)",
            "    at Logger.processLogItem (file:///var/task/node_modules/@aws-lambda-powertools/logger/lib/esm/Logger.js:651:42)",
            "    at Logger.warn (file:///var/task/node_modules/@aws-lambda-powertools/logger/lib/esm/Logger.js:437:14)",
            "    at Logger.awsLogLevelShortCircuit (file:///var/task/node_modules/@aws-lambda-powertools/logger/lib/esm/Logger.js:480:22)",
            "    at Logger.setInitialLogLevel (file:///var/task/node_modules/@aws-lambda-powertools/logger/lib/esm/Logger.js:709:18)",
            "    at Logger.setOptions (file:///var/task/node_modules/@aws-lambda-powertools/logger/lib/esm/Logger.js:806:14)",
            "    at new Logger (file:///var/task/node_modules/@aws-lambda-powertools/logger/lib/esm/Logger.js:134:14)",
            "    at file:///var/task/index.js:10:16",
            "    at ModuleJob.run (node:internal/modules/esm/module_job:218:25)",
            "    at async ModuleLoader.import (node:internal/modules/esm/loader:329:24)"
        ]
    }
}

Code snippet

Use the following constructor options in the Lambda, while Application log level of the Lambda Logging configuration is set to INFO (along with Log Format set to JSON).

Instantiate the logger outside of the handler function:

import { Logger } from '@aws-lambda-powertools/logger';
const logger = new Logger({
	logLevel: 'DEBUG', 
	serviceName: 'MyService',
	environment: 'test'
});

export const handler = async (event: LambdaEvent, context: Context ...

Steps to Reproduce

1. Create a Node.js 20.x lambda. In the Configuration -> Monitoring and operations tool, set Log Format set to JSON and Application log level to INFO
2. In the Lambda code instantiate the logger outside of the handler function:

import { Logger } from '@aws-lambda-powertools/logger';
const logger = new Logger({
	logLevel: 'DEBUG', 
	serviceName: 'MyService',
	environment: 'test'
});

3. Test the function my passing any object. The instantiation of the logger will fail with the following error

{
    "timestamp": "2024-03-25T01:07:01.251Z",
    "level": "ERROR",
    "message": {
        "errorType": "TypeError",
        "errorMessage": "Cannot read properties of undefined (reading 'formatAttributes')",
        "stackTrace": [
            "TypeError: Cannot read properties of undefined (reading 'formatAttributes')",
            "    at Logger.createAndPopulateLogItem (file:///var/task/node_modules/@aws-lambda-powertools/logger/lib/esm/Logger.js:518:47)",
            "    at Logger.processLogItem (file:///var/task/node_modules/@aws-lambda-powertools/logger/lib/esm/Logger.js:651:42)",
            "    at Logger.warn (file:///var/task/node_modules/@aws-lambda-powertools/logger/lib/esm/Logger.js:437:14)",
            "    at Logger.awsLogLevelShortCircuit (file:///var/task/node_modules/@aws-lambda-powertools/logger/lib/esm/Logger.js:480:22)",
            "    at Logger.setInitialLogLevel (file:///var/task/node_modules/@aws-lambda-powertools/logger/lib/esm/Logger.js:709:18)",
            "    at Logger.setOptions (file:///var/task/node_modules/@aws-lambda-powertools/logger/lib/esm/Logger.js:806:14)",
            "    at new Logger (file:///var/task/node_modules/@aws-lambda-powertools/logger/lib/esm/Logger.js:134:14)",
            "    at file:///var/task/index.js:10:16",
            "    at ModuleJob.run (node:internal/modules/esm/module_job:218:25)",
            "    at async ModuleLoader.import (node:internal/modules/esm/loader:329:24)"
        ]
    }
}

Possible Solution

In the private setOptions(...) method of the Logger, change the order of the initialization of initiaLogLevel and the logFormatter to make sure logFormatter is initialized before invoking this.setInitialLogLevel(logLevel);

    this.setInitialLogLevel(logLevel);
    this.setLogFormatter(logFormatter);  // move up

Reason:
The Logger's method awsLogLevelShortCircuit, which is invoked during the construction of the Logger with options, attempts to log a warning about mismatched log levels using this.warn(). The warn() method relies on the logFormatter been set, which has not happened yet.

Powertools for AWS Lambda (TypeScript) version

latest

AWS Lambda function runtime

20.x

Packaging format used

npm

Execution logs

No response

[boring-cyborg]

Thanks for opening your first issue here! We'll come back to you as soon as we can.
In the meantime, check out the #typescript channel on our Powertools for AWS Lambda Discord: Invite link

[dreamorosi]

Hi @deffer, thank you so much for opening this issue.

I was able to reproduce the behavior you described and identify a gap in our tests.

I'll be working on a fix and will open a PR as soon as I have it, together with some new tests.

[dreamorosi]

I have opened a PR that should fix the issue.

Instead of swapping the order of the methods during the setup phase I have modified the init logic so that the order of these actions shouldn't matter. I have also added a test case that matches the "steps to reproduce" indicated above.