From 2cb0778bf282f5967bc3cd454963741e49b55205 Mon Sep 17 00:00:00 2001 From: Andrea Amorosi Date: Tue, 7 Nov 2023 17:28:13 +0100 Subject: [PATCH 1/6] feat(logger): support advanced logging --- docs/core/logger.md | 2 +- docs/index.md | 2 +- .../src/config/EnvironmentVariablesService.ts | 16 +++++++- .../EnvironmentVariablesService.test.ts | 39 +++++++++++++++++++ 4 files changed, 55 insertions(+), 4 deletions(-) diff --git a/docs/core/logger.md b/docs/core/logger.md index 59f38cc6da..9f4298286c 100644 --- a/docs/core/logger.md +++ b/docs/core/logger.md @@ -394,7 +394,7 @@ The error will be logged with default key name `error`, but you can also pass yo ### Log levels -The default log level is `INFO` and can be set using the `logLevel` constructor option or by using the `LOG_LEVEL` environment variable. +The default log level is `INFO` and can be set using the `logLevel` constructor option or by using the `LOG_LEVEL` environment variable. The Logger integrates with the Lambda advanced logging feature, which allows you to set the log level in the function configuration. If you set the log level this way, the Logger will use the value unless you explicitly override it by using the `LOG_LEVEL` environment variable or the `logLevel` constructor option. Logger supports the following log levels: diff --git a/docs/index.md b/docs/index.md index 9ec4da8919..3a72ef871c 100644 --- a/docs/index.md +++ b/docs/index.md @@ -307,7 +307,7 @@ Core utilities such as Tracing, Logging, and Metrics will be available across al | **POWERTOOLS_LOGGER_LOG_EVENT** | Log incoming event | [Logger](core/logger.md) | `false` | | **POWERTOOLS_LOGGER_SAMPLE_RATE** | Debug log sampling | [Logger](core/logger.md) | `0` | | **POWERTOOLS_DEV** | Increase JSON indentation to ease debugging when running functions locally or in a non-production environment | [Logger](core/logger.md) | `false` | -| **LOG_LEVEL** | Set logging level | [Logger](core/logger.md) | `INFO` | +| **LOG_LEVEL** | Set logging level, always takes precedence over `AWS_LAMBDA_LOG_LEVEL` | [Logger](core/logger.md) | `INFO` | | **POWERTOOLS_PARAMETERS_MAX_AGE** | Adjust how long values are kept in cache (in seconds) | [Parameters](utilities/parameters.md) | `5` | | **POWERTOOLS_PARAMETERS_SSM_DECRYPT** | Set whether to decrypt or not values retrieved from AWS Systems Manager Parameters Store | [Parameters](utilities/parameters.md) | `false` | | **POWERTOOLS_IDEMPOTENCY_DISABLED** | Disable the Idempotency logic without changing your code, useful for testing | [Idempotency](utilities/idempotency.md) | `false` | diff --git a/packages/logger/src/config/EnvironmentVariablesService.ts b/packages/logger/src/config/EnvironmentVariablesService.ts index edace97de3..7af950499e 100644 --- a/packages/logger/src/config/EnvironmentVariablesService.ts +++ b/packages/logger/src/config/EnvironmentVariablesService.ts @@ -20,6 +20,7 @@ class EnvironmentVariablesService implements ConfigServiceInterface { // Reserved environment variables + private awsLogLevelVariable = 'AWS_LAMBDA_LOG_LEVEL'; private awsRegionVariable = 'AWS_REGION'; private currentEnvironmentVariable = 'ENVIRONMENT'; private functionNameVariable = 'AWS_LAMBDA_FUNCTION_NAME'; @@ -88,12 +89,23 @@ class EnvironmentVariablesService } /** - * It returns the value of the LOG_LEVEL environment variable. + * It returns the value of the `LOG_LEVEL` or `AWS_LAMBDA_LOG_LEVEL` environment variable. + * + * The `AWS_LAMBDA_LOG_LEVEL` environment variable is set by AWS Lambda when configuring + * the function's log level. The `LOG_LEVEL` environment variable always takes precedence + * over the `AWS_LAMBDA_LOG_LEVEL` environment variable. * * @returns {string} */ public getLogLevel(): string { - return this.get(this.logLevelVariable); + const logLevelVariable = this.get(this.logLevelVariable); + const awsLogLevelVariable = this.get(this.awsLogLevelVariable); + + return logLevelVariable !== '' + ? logLevelVariable + : awsLogLevelVariable === 'FATAL' + ? 'CRITICAL' + : awsLogLevelVariable; } /** diff --git a/packages/logger/tests/unit/config/EnvironmentVariablesService.test.ts b/packages/logger/tests/unit/config/EnvironmentVariablesService.test.ts index b5a212ab1a..e796e90c4a 100644 --- a/packages/logger/tests/unit/config/EnvironmentVariablesService.test.ts +++ b/packages/logger/tests/unit/config/EnvironmentVariablesService.test.ts @@ -137,6 +137,45 @@ describe('Class: EnvironmentVariablesService', () => { // Assess expect(value).toEqual('ERROR'); }); + + test('it returns the value of the environment variable AWS_LAMBDA_LOG_LEVEL if the LOG_LEVEL one is not set and aliases it as needed', () => { + // Prepare + process.env.LOG_LEVEL = undefined; + process.env.AWS_LAMBDA_LOG_LEVEL = 'FATAL'; + const service = new EnvironmentVariablesService(); + + // Act + const value = service.getLogLevel(); + + // Assess + expect(value).toEqual('CRITICAL'); + }); + + test('it returns the value of the environment variable LOG_LEVEL even if the AWS_LAMBDA_LOG_LEVEL one is not set', () => { + // Prepare + process.env.LOG_LEVEL = 'WARN'; + process.env.AWS_LAMBDA_LOG_LEVEL = 'FATAL'; + const service = new EnvironmentVariablesService(); + + // Act + const value = service.getLogLevel(); + + // Assess + expect(value).toEqual('WARN'); + }); + + test('it returns an empty value if neither AWS_LAMBDA_LOG_LEVEL nor LOG_LEVEL are set', () => { + // Prepare + process.env.LOG_LEVEL = undefined; + process.env.AWS_LAMBDA_LOG_LEVEL = undefined; + const service = new EnvironmentVariablesService(); + + // Act + const value = service.getLogLevel(); + + // Assess + expect(value).toEqual(''); + }); }); describe('Method: getSampleRateValue', () => { From 232a39624c92a93057d2551ab5f8ce7bfb42f7d9 Mon Sep 17 00:00:00 2001 From: Andrea Amorosi Date: Tue, 14 Nov 2023 23:32:32 +0100 Subject: [PATCH 2/6] docs(logger): add alc info --- docs/core/logger.md | 53 +++++++++++++++++++++++++++++++++++++------- docs/core/metrics.md | 4 ++++ docs/index.md | 2 +- 3 files changed, 50 insertions(+), 9 deletions(-) diff --git a/docs/core/logger.md b/docs/core/logger.md index 9f4298286c..66e5389812 100644 --- a/docs/core/logger.md +++ b/docs/core/logger.md @@ -46,12 +46,12 @@ The library requires two settings. You can set them as environment variables, or These settings will be used across all logs emitted: -| Setting | Description | Environment variable | Default Value | Allowed Values | Example Value | Constructor parameter | -| ---------------------- | ---------------------------------------------------------------------------------------------------------------- | ------------------------------- | ------------------- | ------------------------------------------ | ------------------- | --------------------- | -| **Service name** | Sets the name of service of which the Lambda function is part of, that will be present across all log statements | `POWERTOOLS_SERVICE_NAME` | `service_undefined` | Any string | `serverlessAirline` | `serviceName` | -| **Logging level** | Sets how verbose Logger should be, from the most verbose to the least verbose (no logs) | `LOG_LEVEL` | `info` | `DEBUG`, `INFO`, `WARN`, `ERROR`, `SILENT` | `ERROR` | `logLevel` | -| **Log incoming event** | Whether to log or not the incoming event when using the decorator or middleware | `POWERTOOLS_LOGGER_LOG_EVENT` | `false` | `true`, `false` | `false` | `logEvent` | -| **Debug log sampling** | Probability that a Lambda invocation will print all the log items regardless of the log level setting | `POWERTOOLS_LOGGER_SAMPLE_RATE` | `0` | `0.0` to `1` | `0.5` | `sampleRateValue` | +| Setting | Description | Environment variable | Default Value | Allowed Values | Example Value | Constructor parameter | +| ---------------------- | ---------------------------------------------------------------------------------------------------------------- | ------------------------------------- | ------------------- | ------------------------------------------------------ | ------------------- | --------------------- | +| **Service name** | Sets the name of service of which the Lambda function is part of, that will be present across all log statements | `POWERTOOLS_SERVICE_NAME` | `service_undefined` | Any string | `serverlessAirline` | `serviceName` | +| **Logging level** | Sets how verbose Logger should be, from the most verbose to the least verbose (no logs) | `POWERTOOLS_LOG_LEVEL` or `LOG_LEVEL` | `INFO` | `DEBUG`, `INFO`, `WARN`, `ERROR`, `CRITICAL`, `SILENT` | `ERROR` | `logLevel` | +| **Log incoming event** | Whether to log or not the incoming event when using the decorator or middleware | `POWERTOOLS_LOGGER_LOG_EVENT` | `false` | `true`, `false` | `false` | `logEvent` | +| **Debug log sampling** | Probability that a Lambda invocation will print all the log items regardless of the log level setting | `POWERTOOLS_LOGGER_SAMPLE_RATE` | `0` | `0.0` to `1` | `0.5` | `sampleRateValue` | #### Example using AWS Serverless Application Model (SAM) @@ -394,9 +394,9 @@ The error will be logged with default key name `error`, but you can also pass yo ### Log levels -The default log level is `INFO` and can be set using the `logLevel` constructor option or by using the `LOG_LEVEL` environment variable. The Logger integrates with the Lambda advanced logging feature, which allows you to set the log level in the function configuration. If you set the log level this way, the Logger will use the value unless you explicitly override it by using the `LOG_LEVEL` environment variable or the `logLevel` constructor option. +The default log level is `INFO` and can be set using the `logLevel` constructor option or by using the `POWERTOOLS_LOG_LEVEL` environment variable. -Logger supports the following log levels: +We support the following log levels: | Level | Numeric value | | ---------- | ------------- | @@ -426,6 +426,43 @@ By setting the log level to `SILENT`, which can be done either through the `logL !!! note Use the `SILENT` log level with care, as it can make it more challenging to monitor and debug your application. Therefore, we advise using this log level judiciously. +#### AWS Lambda Advanced Logging Controls (ALC) + +With [AWS Lambda Advanced Logging Controls (ALC)](...docs link), you can control the output format of your logs as either `TEXT` or `JSON` and specify the minimum accepted log level for your application. Regardless of the output format setting in Lambda, we will always output JSON formatted logging messages. + +When you have this feature enabled, log messages that don’t meet the configured log level are discarded by Lambda. For example, if you set the minimum log level to `WARN`, you will only receive `WARN` and `ERROR` messages in your AWS CloudWatch Logs, all other log levels will be discarded by Lambda. + +```mermaid +sequenceDiagram + title Lambda ALC allows WARN logs only + participant Lambda service + participant Lambda function + participant Application Logger + + Note over Lambda service: AWS_LAMBDA_LOG_LEVEL="WARN" + Lambda service->>Lambda function: Invoke (event) + Lambda function->>Lambda function: Calls handler + Lambda function->>Application Logger: logger.warn("Something happened") + Lambda function-->>Application Logger: logger.debug("Something happened") + Lambda function-->>Application Logger: logger.info("Something happened") + + Lambda service->>Lambda service: DROP INFO and DEBUG logs + + Lambda service->>CloudWatch Logs: Ingest error logs +``` + +**Priority of log level settings in Powertools for AWS Lambda** + +When the Advanced Logging Controls feature is enabled, we are unable to increase the minimum log level below the `AWS_LAMBDA_LOG_LEVEL` environment variable value, see [AWS Lambda service documentation](...docs link) for more details. + +We prioritise log level settings in this order: + +1. `AWS_LAMBDA_LOG_LEVEL` environment variable +2. Setting the log level in code using the `logLevel` constructor option, or by calling the `logger.setLogLevel()` method +3. `POWERTOOLS_LOG_LEVEL` environment variable + +In the event you have set a log level in Powertools to a level that is lower than the ACL setting, we will output a warning log message informing you that your messages will be discarded by Lambda. + ### Using multiple Logger instances across your code The `createChild` method allows you to create a child instance of the Logger, which inherits all of the attributes from its parent. You have the option to override any of the settings and attributes from the parent logger, including [its settings](#utility-settings), any [persistent attributes](#appending-persistent-additional-log-keys-and-values), and [the log formatter](#custom-log-formatter-bring-your-own-formatter). Once a child logger is created, the logger and its parent will act as separate instances of the Logger class, and as such any change to one won't be applied to the other. diff --git a/docs/core/metrics.md b/docs/core/metrics.md index 549571dc6e..78f550ad50 100644 --- a/docs/core/metrics.md +++ b/docs/core/metrics.md @@ -47,6 +47,10 @@ Install the library in your project: npm install @aws-lambda-powertools/metrics ``` +!!! warning "Caution" + + Using the Lambda [Advanced Logging Controls](...docs link) feature requires you to update your version of Powertools for AWS Lambda (TypeScript) to at least v1.15.0 to ensure metrics are reported correctly to Amazon CloudWatch Metrics. + ### Usage The `Metrics` utility must always be instantiated outside of the Lambda handler. In doing this, subsequent invocations processed by the same instance of your function can reuse these resources. This saves cost by reducing function run time. In addition, `Metrics` can track cold start and emit the appropriate metrics. diff --git a/docs/index.md b/docs/index.md index 3a72ef871c..b8f6f67199 100644 --- a/docs/index.md +++ b/docs/index.md @@ -307,7 +307,7 @@ Core utilities such as Tracing, Logging, and Metrics will be available across al | **POWERTOOLS_LOGGER_LOG_EVENT** | Log incoming event | [Logger](core/logger.md) | `false` | | **POWERTOOLS_LOGGER_SAMPLE_RATE** | Debug log sampling | [Logger](core/logger.md) | `0` | | **POWERTOOLS_DEV** | Increase JSON indentation to ease debugging when running functions locally or in a non-production environment | [Logger](core/logger.md) | `false` | -| **LOG_LEVEL** | Set logging level, always takes precedence over `AWS_LAMBDA_LOG_LEVEL` | [Logger](core/logger.md) | `INFO` | +| **POWERTOOLS_LOG_LEVEL** | Set the log level, alias for `LOG_LEVEL` and always overridden by `AWS_LAMBDA_LOG_LEVEL` | [Logger](core/logger.md) | `INFO` | | **POWERTOOLS_PARAMETERS_MAX_AGE** | Adjust how long values are kept in cache (in seconds) | [Parameters](utilities/parameters.md) | `5` | | **POWERTOOLS_PARAMETERS_SSM_DECRYPT** | Set whether to decrypt or not values retrieved from AWS Systems Manager Parameters Store | [Parameters](utilities/parameters.md) | `false` | | **POWERTOOLS_IDEMPOTENCY_DISABLED** | Disable the Idempotency logic without changing your code, useful for testing | [Idempotency](utilities/idempotency.md) | `false` | From 64ac7588cca93ec18e351ff18e1453c4f33070c6 Mon Sep 17 00:00:00 2001 From: Andrea Amorosi Date: Tue, 14 Nov 2023 23:32:45 +0100 Subject: [PATCH 3/6] feat(logger): support alc --- packages/logger/src/Logger.ts | 41 +++++++++++++++++-- .../src/config/ConfigServiceInterface.ts | 11 +++++ .../src/config/EnvironmentVariablesService.ts | 34 ++++++++++----- 3 files changed, 71 insertions(+), 15 deletions(-) diff --git a/packages/logger/src/Logger.ts b/packages/logger/src/Logger.ts index ec82ff066f..0289b1cd0a 100644 --- a/packages/logger/src/Logger.ts +++ b/packages/logger/src/Logger.ts @@ -1,5 +1,6 @@ import { randomInt } from 'node:crypto'; import { Console } from 'node:console'; +import { format } from 'node:util'; import type { Context, Handler } from 'aws-lambda'; import { Utility } from '@aws-lambda-powertools/commons'; import { LogFormatterInterface, PowertoolLogFormatter } from './formatter'; @@ -491,9 +492,13 @@ class Logger extends Utility implements ClassThatLogs { /** * Set the log level for this Logger instance. * + * If the log level is set using AWS Lambda Advanced Logging Controls, it sets it + * instead of the given log level to avoid data loss. + * * @param logLevel The log level to set, i.e. `error`, `warn`, `info`, `debug`, etc. */ public setLogLevel(logLevel: LogLevel): void { + if (this.awsLogLevelShortCircuit(logLevel)) return; if (this.isValidLogLevel(logLevel)) { this.logLevel = this.logLevelThresholds[logLevel]; } else { @@ -597,6 +602,30 @@ class Logger extends Utility implements ClassThatLogs { }); } + private awsLogLevelShortCircuit(selectedLogLevel?: string): boolean { + const awsLogLevel = this.getEnvVarsService().getAwsLogLevel(); + if (this.isValidLogLevel(awsLogLevel)) { + this.logLevel = this.logLevelThresholds[awsLogLevel]; + + if ( + this.isValidLogLevel(selectedLogLevel) && + this.logLevel > this.logLevelThresholds[selectedLogLevel] + ) { + this.warn( + format( + `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.`, + selectedLogLevel, + awsLogLevel + ) + ); + } + + return true; + } + + return false; + } + /** * It processes a particular log item so that it can be printed to stdout: * - Merges ephemeral log attributes with persistent log attributes (printed for all logs) and additional info; @@ -868,17 +897,21 @@ class Logger extends Utility implements ClassThatLogs { /** * Sets the initial Logger log level based on the following order: - * 1. If a log level is passed to the constructor, it sets it. - * 2. If a log level is set via custom config service, it sets it. - * 3. If a log level is set via env variables, it sets it. + * 1. If a log level is set using AWS Lambda Advanced Logging Controls, it sets it. + * 2. If a log level is passed to the constructor, it sets it. + * 3. If a log level is set via custom config service, it sets it. + * 4. If a log level is set via env variables, it sets it. * - * If none of the above is true, the default log level applies (INFO). + * If none of the above is true, the default log level applies (`INFO`). * * @private * @param {LogLevel} [logLevel] - Log level passed to the constructor */ private setInitialLogLevel(logLevel?: LogLevel): void { const constructorLogLevel = logLevel?.toUpperCase(); + + if (this.awsLogLevelShortCircuit(constructorLogLevel)) return; + if (this.isValidLogLevel(constructorLogLevel)) { this.logLevel = this.logLevelThresholds[constructorLogLevel]; diff --git a/packages/logger/src/config/ConfigServiceInterface.ts b/packages/logger/src/config/ConfigServiceInterface.ts index 29807eb138..9debaa22a7 100644 --- a/packages/logger/src/config/ConfigServiceInterface.ts +++ b/packages/logger/src/config/ConfigServiceInterface.ts @@ -14,6 +14,17 @@ interface ConfigServiceInterface { */ get(name: string): string; + /** + * It returns the value of the `AWS_LAMBDA_LOG_LEVEL` environment variable. + * + * The `AWS_LAMBDA_LOG_LEVEL` environment variable is set by AWS Lambda when configuring + * the function's log level using the Advanced Logging Controls feature. This value always + * takes precedence over other means of configuring the log level. + * + * @returns {string} + */ + getAwsLogLevel(): string; + /** * It returns the value of the ENVIRONMENT environment variable. * diff --git a/packages/logger/src/config/EnvironmentVariablesService.ts b/packages/logger/src/config/EnvironmentVariablesService.ts index 7af950499e..77fd297092 100644 --- a/packages/logger/src/config/EnvironmentVariablesService.ts +++ b/packages/logger/src/config/EnvironmentVariablesService.ts @@ -26,10 +26,26 @@ class EnvironmentVariablesService private functionNameVariable = 'AWS_LAMBDA_FUNCTION_NAME'; private functionVersionVariable = 'AWS_LAMBDA_FUNCTION_VERSION'; private logEventVariable = 'POWERTOOLS_LOGGER_LOG_EVENT'; - private logLevelVariable = 'LOG_LEVEL'; + private logLevelVariable = 'POWERTOOLS_LOG_LEVEL'; + private logLevelVariableAlias = 'LOG_LEVEL'; private memoryLimitInMBVariable = 'AWS_LAMBDA_FUNCTION_MEMORY_SIZE'; private sampleRateValueVariable = 'POWERTOOLS_LOGGER_SAMPLE_RATE'; + /** + * It returns the value of the `AWS_LAMBDA_LOG_LEVEL` environment variable. + * + * The `AWS_LAMBDA_LOG_LEVEL` environment variable is set by AWS Lambda when configuring + * the function's log level using the Advanced Logging Controls feature. This value always + * takes precedence over other means of configuring the log level. + * + * @returns {string} + */ + public getAwsLogLevel(): string { + const awsLogLevelVariable = this.get(this.awsLogLevelVariable); + + return awsLogLevelVariable === 'FATAL' ? 'CRITICAL' : awsLogLevelVariable; + } + /** * It returns the value of the AWS_REGION environment variable. * @@ -89,23 +105,19 @@ class EnvironmentVariablesService } /** - * It returns the value of the `LOG_LEVEL` or `AWS_LAMBDA_LOG_LEVEL` environment variable. + * It returns the value of the `POWERTOOLS_LOG_LEVEL, or `LOG_LEVEL` environment variables + * when the first one is not set. * - * The `AWS_LAMBDA_LOG_LEVEL` environment variable is set by AWS Lambda when configuring - * the function's log level. The `LOG_LEVEL` environment variable always takes precedence - * over the `AWS_LAMBDA_LOG_LEVEL` environment variable. + * @note The `LOG_LEVEL` environment variable is deprecated and will be removed in a future release. + * @note The `AWS_LAMBDA_LOG_LEVEL` environment variable always takes precedence over the ones above. * * @returns {string} */ public getLogLevel(): string { const logLevelVariable = this.get(this.logLevelVariable); - const awsLogLevelVariable = this.get(this.awsLogLevelVariable); + const logLevelVariableAlias = this.get(this.logLevelVariableAlias); - return logLevelVariable !== '' - ? logLevelVariable - : awsLogLevelVariable === 'FATAL' - ? 'CRITICAL' - : awsLogLevelVariable; + return logLevelVariable !== '' ? logLevelVariable : logLevelVariableAlias; } /** From 32ab3d503b2e19fae3a4e8a72257bc2a46aae94b Mon Sep 17 00:00:00 2001 From: Andrea Amorosi Date: Thu, 16 Nov 2023 10:27:09 +0100 Subject: [PATCH 4/6] docs: fix alc docs links --- docs/core/logger.md | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/docs/core/logger.md b/docs/core/logger.md index 66e5389812..1f07c31d88 100644 --- a/docs/core/logger.md +++ b/docs/core/logger.md @@ -428,7 +428,7 @@ By setting the log level to `SILENT`, which can be done either through the `logL #### AWS Lambda Advanced Logging Controls (ALC) -With [AWS Lambda Advanced Logging Controls (ALC)](...docs link), you can control the output format of your logs as either `TEXT` or `JSON` and specify the minimum accepted log level for your application. Regardless of the output format setting in Lambda, we will always output JSON formatted logging messages. +With [AWS Lambda Advanced Logging Controls (ALC)](https://docs.aws.amazon.com/lambda/latest/dg/monitoring-cloudwatchlogs.html#monitoring-cloudwatchlogs-advanced), you can control the output format of your logs as either `TEXT` or `JSON` and specify the minimum accepted log level for your application. Regardless of the output format setting in Lambda, we will always output JSON formatted logging messages. When you have this feature enabled, log messages that don’t meet the configured log level are discarded by Lambda. For example, if you set the minimum log level to `WARN`, you will only receive `WARN` and `ERROR` messages in your AWS CloudWatch Logs, all other log levels will be discarded by Lambda. @@ -453,7 +453,7 @@ sequenceDiagram **Priority of log level settings in Powertools for AWS Lambda** -When the Advanced Logging Controls feature is enabled, we are unable to increase the minimum log level below the `AWS_LAMBDA_LOG_LEVEL` environment variable value, see [AWS Lambda service documentation](...docs link) for more details. +When the Advanced Logging Controls feature is enabled, we are unable to increase the minimum log level below the `AWS_LAMBDA_LOG_LEVEL` environment variable value, see [AWS Lambda service documentation](https://docs.aws.amazon.com/lambda/latest/dg/monitoring-cloudwatchlogs.html#monitoring-cloudwatchlogs-log-level) for more details. We prioritise log level settings in this order: From 166cd7733438e63efdcc33830d11954924cddec2 Mon Sep 17 00:00:00 2001 From: Andrea Amorosi Date: Thu, 16 Nov 2023 11:01:38 +0100 Subject: [PATCH 5/6] tests(logger): add unit tests for the feature --- .../src/config/ConfigServiceInterface.ts | 8 +++- .../src/config/EnvironmentVariablesService.ts | 10 +++-- .../EnvironmentVariablesService.test.ts | 40 ++++++++++--------- .../tests/unit/middleware/middy.test.ts | 3 ++ 4 files changed, 37 insertions(+), 24 deletions(-) diff --git a/packages/logger/src/config/ConfigServiceInterface.ts b/packages/logger/src/config/ConfigServiceInterface.ts index 9debaa22a7..27c76b19e8 100644 --- a/packages/logger/src/config/ConfigServiceInterface.ts +++ b/packages/logger/src/config/ConfigServiceInterface.ts @@ -21,6 +21,8 @@ interface ConfigServiceInterface { * the function's log level using the Advanced Logging Controls feature. This value always * takes precedence over other means of configuring the log level. * + * @note we need to map the `FATAL` log level to `CRITICAL`, see {@link https://docs.aws.amazon.com/lambda/latest/dg/configuration-logging.html#configuration-logging-log-levels AWS Lambda Log Levels}. + * * @returns {string} */ getAwsLogLevel(): string; @@ -40,7 +42,11 @@ interface ConfigServiceInterface { getLogEvent(): boolean; /** - * It returns the value of the LOG_LEVEL environment variable. + * It returns the value of the `POWERTOOLS_LOG_LEVEL, or `LOG_LEVEL` (legacy) environment variables + * when the first one is not set. + * + * @note The `LOG_LEVEL` environment variable is considered legacy and will be removed in a future release. + * @note The `AWS_LAMBDA_LOG_LEVEL` environment variable always takes precedence over the ones above. * * @returns {string} */ diff --git a/packages/logger/src/config/EnvironmentVariablesService.ts b/packages/logger/src/config/EnvironmentVariablesService.ts index 77fd297092..47955efcb7 100644 --- a/packages/logger/src/config/EnvironmentVariablesService.ts +++ b/packages/logger/src/config/EnvironmentVariablesService.ts @@ -27,7 +27,7 @@ class EnvironmentVariablesService private functionVersionVariable = 'AWS_LAMBDA_FUNCTION_VERSION'; private logEventVariable = 'POWERTOOLS_LOGGER_LOG_EVENT'; private logLevelVariable = 'POWERTOOLS_LOG_LEVEL'; - private logLevelVariableAlias = 'LOG_LEVEL'; + private logLevelVariableLegacy = 'LOG_LEVEL'; private memoryLimitInMBVariable = 'AWS_LAMBDA_FUNCTION_MEMORY_SIZE'; private sampleRateValueVariable = 'POWERTOOLS_LOGGER_SAMPLE_RATE'; @@ -38,6 +38,8 @@ class EnvironmentVariablesService * the function's log level using the Advanced Logging Controls feature. This value always * takes precedence over other means of configuring the log level. * + * @note we need to map the `FATAL` log level to `CRITICAL`, see {@link https://docs.aws.amazon.com/lambda/latest/dg/configuration-logging.html#configuration-logging-log-levels AWS Lambda Log Levels}. + * * @returns {string} */ public getAwsLogLevel(): string { @@ -105,17 +107,17 @@ class EnvironmentVariablesService } /** - * It returns the value of the `POWERTOOLS_LOG_LEVEL, or `LOG_LEVEL` environment variables + * It returns the value of the `POWERTOOLS_LOG_LEVEL, or `LOG_LEVEL` (legacy) environment variables * when the first one is not set. * - * @note The `LOG_LEVEL` environment variable is deprecated and will be removed in a future release. + * @note The `LOG_LEVEL` environment variable is considered legacy and will be removed in a future release. * @note The `AWS_LAMBDA_LOG_LEVEL` environment variable always takes precedence over the ones above. * * @returns {string} */ public getLogLevel(): string { const logLevelVariable = this.get(this.logLevelVariable); - const logLevelVariableAlias = this.get(this.logLevelVariableAlias); + const logLevelVariableAlias = this.get(this.logLevelVariableLegacy); return logLevelVariable !== '' ? logLevelVariable : logLevelVariableAlias; } diff --git a/packages/logger/tests/unit/config/EnvironmentVariablesService.test.ts b/packages/logger/tests/unit/config/EnvironmentVariablesService.test.ts index e796e90c4a..7c1c4de428 100644 --- a/packages/logger/tests/unit/config/EnvironmentVariablesService.test.ts +++ b/packages/logger/tests/unit/config/EnvironmentVariablesService.test.ts @@ -17,6 +17,20 @@ describe('Class: EnvironmentVariablesService', () => { process.env = ENVIRONMENT_VARIABLES; }); + describe('Method: getAwsLogLevel', () => { + it('returns the value of the environment variable AWS_LAMBDA_LOG_LEVEL and aliases it as needed', () => { + // Prepare + process.env.AWS_LAMBDA_LOG_LEVEL = 'FATAL'; + const service = new EnvironmentVariablesService(); + + // Act + const value = service.getAwsLogLevel(); + + // Assess + expect(value).toEqual('CRITICAL'); + }); + }); + describe('Method: getAwsRegion', () => { test('it returns the value of the environment variable AWS_REGION', () => { // Prepare @@ -126,8 +140,9 @@ describe('Class: EnvironmentVariablesService', () => { }); describe('Method: getLogLevel', () => { - test('it returns the value of the environment variable LOG_LEVEL', () => { + test('it returns the value of the environment variable LOG_LEVEL when POWERTOOLS_LOG_LEVEL is not set', () => { // Prepare + process.env.POWERTOOLS_LOG_LEVEL = undefined; process.env.LOG_LEVEL = 'ERROR'; const service = new EnvironmentVariablesService(); @@ -138,36 +153,23 @@ describe('Class: EnvironmentVariablesService', () => { expect(value).toEqual('ERROR'); }); - test('it returns the value of the environment variable AWS_LAMBDA_LOG_LEVEL if the LOG_LEVEL one is not set and aliases it as needed', () => { - // Prepare - process.env.LOG_LEVEL = undefined; - process.env.AWS_LAMBDA_LOG_LEVEL = 'FATAL'; - const service = new EnvironmentVariablesService(); - - // Act - const value = service.getLogLevel(); - - // Assess - expect(value).toEqual('CRITICAL'); - }); - - test('it returns the value of the environment variable LOG_LEVEL even if the AWS_LAMBDA_LOG_LEVEL one is not set', () => { + test('it returns the value of the environment variable POWERTOOLS_LOG_LEVEL when LOG_LEVEL one is also set', () => { // Prepare process.env.LOG_LEVEL = 'WARN'; - process.env.AWS_LAMBDA_LOG_LEVEL = 'FATAL'; + process.env.POWERTOOLS_LOG_LEVEL = 'INFO'; const service = new EnvironmentVariablesService(); // Act const value = service.getLogLevel(); // Assess - expect(value).toEqual('WARN'); + expect(value).toEqual('INFO'); }); - test('it returns an empty value if neither AWS_LAMBDA_LOG_LEVEL nor LOG_LEVEL are set', () => { + test('it returns an empty value if neither POWERTOOLS_LOG_LEVEL nor LOG_LEVEL are set', () => { // Prepare process.env.LOG_LEVEL = undefined; - process.env.AWS_LAMBDA_LOG_LEVEL = undefined; + process.env.POWERTOOLS_LOG_LEVEL = undefined; const service = new EnvironmentVariablesService(); // Act diff --git a/packages/logger/tests/unit/middleware/middy.test.ts b/packages/logger/tests/unit/middleware/middy.test.ts index f2815b01cd..8a9e09e261 100644 --- a/packages/logger/tests/unit/middleware/middy.test.ts +++ b/packages/logger/tests/unit/middleware/middy.test.ts @@ -303,6 +303,9 @@ describe('Middy middleware', () => { get(name: string): string { return `a-string-from-${name}`; }, + getAwsLogLevel(): string { + return 'INFO'; + }, getCurrentEnvironment(): string { return 'dev'; }, From 7037cc5be253b7cc82e0115d3ff61f47bfb4cc56 Mon Sep 17 00:00:00 2001 From: Andrea Amorosi Date: Thu, 16 Nov 2023 11:01:57 +0100 Subject: [PATCH 6/6] docs(logger): make POWERTOOLS_LOG_LEVEL default --- docs/core/logger.md | 16 ++++++------- docs/index.md | 2 +- .../batch/templates/sam/dynamodb.yaml | 2 +- docs/snippets/batch/templates/sam/sqs.yaml | 2 +- examples/cdk/src/example-stack.ts | 2 +- examples/sam/template.yaml | 8 +++---- .../tests/e2e/basicFeatures.middy.test.ts | 2 +- packages/logger/tests/e2e/constants.ts | 2 +- .../tests/e2e/sampleRate.decorator.test.ts | 2 +- .../helpers/populateEnvironmentVariables.ts | 2 +- packages/logger/tests/unit/Logger.test.ts | 24 +++++++++++++++++-- packages/logger/tests/unit/helpers.test.ts | 7 ++++-- 12 files changed, 47 insertions(+), 24 deletions(-) diff --git a/docs/core/logger.md b/docs/core/logger.md index 1f07c31d88..bd0be2de36 100644 --- a/docs/core/logger.md +++ b/docs/core/logger.md @@ -46,12 +46,12 @@ The library requires two settings. You can set them as environment variables, or These settings will be used across all logs emitted: -| Setting | Description | Environment variable | Default Value | Allowed Values | Example Value | Constructor parameter | -| ---------------------- | ---------------------------------------------------------------------------------------------------------------- | ------------------------------------- | ------------------- | ------------------------------------------------------ | ------------------- | --------------------- | -| **Service name** | Sets the name of service of which the Lambda function is part of, that will be present across all log statements | `POWERTOOLS_SERVICE_NAME` | `service_undefined` | Any string | `serverlessAirline` | `serviceName` | -| **Logging level** | Sets how verbose Logger should be, from the most verbose to the least verbose (no logs) | `POWERTOOLS_LOG_LEVEL` or `LOG_LEVEL` | `INFO` | `DEBUG`, `INFO`, `WARN`, `ERROR`, `CRITICAL`, `SILENT` | `ERROR` | `logLevel` | -| **Log incoming event** | Whether to log or not the incoming event when using the decorator or middleware | `POWERTOOLS_LOGGER_LOG_EVENT` | `false` | `true`, `false` | `false` | `logEvent` | -| **Debug log sampling** | Probability that a Lambda invocation will print all the log items regardless of the log level setting | `POWERTOOLS_LOGGER_SAMPLE_RATE` | `0` | `0.0` to `1` | `0.5` | `sampleRateValue` | +| Setting | Description | Environment variable | Default Value | Allowed Values | Example Value | Constructor parameter | +| ---------------------- | ---------------------------------------------------------------------------------------------------------------- | ------------------------------- | ------------------- | ------------------------------------------------------ | ------------------- | --------------------- | +| **Service name** | Sets the name of service of which the Lambda function is part of, that will be present across all log statements | `POWERTOOLS_SERVICE_NAME` | `service_undefined` | Any string | `serverlessAirline` | `serviceName` | +| **Logging level** | Sets how verbose Logger should be, from the most verbose to the least verbose (no logs) | `POWERTOOLS_LOG_LEVEL` | `INFO` | `DEBUG`, `INFO`, `WARN`, `ERROR`, `CRITICAL`, `SILENT` | `ERROR` | `logLevel` | +| **Log incoming event** | Whether to log or not the incoming event when using the decorator or middleware | `POWERTOOLS_LOGGER_LOG_EVENT` | `false` | `true`, `false` | `false` | `logEvent` | +| **Debug log sampling** | Probability that a Lambda invocation will print all the log items regardless of the log level setting | `POWERTOOLS_LOGGER_SAMPLE_RATE` | `0` | `0.0` to `1` | `0.5` | `sampleRateValue` | #### Example using AWS Serverless Application Model (SAM) @@ -71,7 +71,7 @@ These settings will be used across all logs emitted: Runtime: nodejs20.x Environment: Variables: - LOG_LEVEL: WARN + POWERTOOLS_LOG_LEVEL: WARN POWERTOOLS_SERVICE_NAME: serverlessAirline ``` @@ -421,7 +421,7 @@ The `SILENT` log level provides a simple and efficient way to suppress all log m This feature is useful when you want to have your code instrumented to produce logs, but due to some requirement or business decision, you prefer to not emit them. -By setting the log level to `SILENT`, which can be done either through the `logLevel` constructor option or by using the `LOG_LEVEL` environment variable, you can easily suppress all logs as needed. +By setting the log level to `SILENT`, which can be done either through the `logLevel` constructor option or by using the `POWERTOOLS_LOG_LEVEL` environment variable, you can easily suppress all logs as needed. !!! note Use the `SILENT` log level with care, as it can make it more challenging to monitor and debug your application. Therefore, we advise using this log level judiciously. diff --git a/docs/index.md b/docs/index.md index b8f6f67199..0a1a7ff9c4 100644 --- a/docs/index.md +++ b/docs/index.md @@ -307,7 +307,7 @@ Core utilities such as Tracing, Logging, and Metrics will be available across al | **POWERTOOLS_LOGGER_LOG_EVENT** | Log incoming event | [Logger](core/logger.md) | `false` | | **POWERTOOLS_LOGGER_SAMPLE_RATE** | Debug log sampling | [Logger](core/logger.md) | `0` | | **POWERTOOLS_DEV** | Increase JSON indentation to ease debugging when running functions locally or in a non-production environment | [Logger](core/logger.md) | `false` | -| **POWERTOOLS_LOG_LEVEL** | Set the log level, alias for `LOG_LEVEL` and always overridden by `AWS_LAMBDA_LOG_LEVEL` | [Logger](core/logger.md) | `INFO` | +| **POWERTOOLS_LOG_LEVEL** | Sets how verbose Logger should be, from the most verbose to the least verbose (no logs) | [Logger](core/logger.md) | `INFO` | | **POWERTOOLS_PARAMETERS_MAX_AGE** | Adjust how long values are kept in cache (in seconds) | [Parameters](utilities/parameters.md) | `5` | | **POWERTOOLS_PARAMETERS_SSM_DECRYPT** | Set whether to decrypt or not values retrieved from AWS Systems Manager Parameters Store | [Parameters](utilities/parameters.md) | `false` | | **POWERTOOLS_IDEMPOTENCY_DISABLED** | Disable the Idempotency logic without changing your code, useful for testing | [Idempotency](utilities/idempotency.md) | `false` | diff --git a/docs/snippets/batch/templates/sam/dynamodb.yaml b/docs/snippets/batch/templates/sam/dynamodb.yaml index dfa9e3fd1e..83dc648054 100644 --- a/docs/snippets/batch/templates/sam/dynamodb.yaml +++ b/docs/snippets/batch/templates/sam/dynamodb.yaml @@ -10,7 +10,7 @@ Globals: Tracing: Active Environment: Variables: - LOG_LEVEL: INFO + POWERTOOLS_LOG_LEVEL: INFO POWERTOOLS_SERVICE_NAME: hello Resources: diff --git a/docs/snippets/batch/templates/sam/sqs.yaml b/docs/snippets/batch/templates/sam/sqs.yaml index 08dcf89d38..77ce058c94 100644 --- a/docs/snippets/batch/templates/sam/sqs.yaml +++ b/docs/snippets/batch/templates/sam/sqs.yaml @@ -10,7 +10,7 @@ Globals: Tracing: Active Environment: Variables: - LOG_LEVEL: INFO + POWERTOOLS_LOG_LEVEL: INFO POWERTOOLS_SERVICE_NAME: hello Resources: diff --git a/examples/cdk/src/example-stack.ts b/examples/cdk/src/example-stack.ts index a7aeb12b4d..986f7fb79c 100644 --- a/examples/cdk/src/example-stack.ts +++ b/examples/cdk/src/example-stack.ts @@ -19,7 +19,7 @@ const commonProps: Partial = { NODE_OPTIONS: '--enable-source-maps', // see https://docs.aws.amazon.com/lambda/latest/dg/typescript-exceptions.html POWERTOOLS_SERVICE_NAME: 'items-store', POWERTOOLS_METRICS_NAMESPACE: 'PowertoolsCDKExample', - LOG_LEVEL: 'DEBUG', + POWERTOOLS_LOG_LEVEL: 'DEBUG', }, bundling: { externalModules: [ diff --git a/examples/sam/template.yaml b/examples/sam/template.yaml index 39d440f21f..9596113f30 100644 --- a/examples/sam/template.yaml +++ b/examples/sam/template.yaml @@ -64,7 +64,7 @@ Resources: SAMPLE_TABLE: !Ref SampleTable POWERTOOLS_SERVICE_NAME: items-store POWERTOOLS_METRICS_NAMESPACE: PowertoolsSAMExample - LOG_LEVEL: Debug + POWERTOOLS_LOG_LEVEL: debug Events: Api: Type: Api @@ -104,7 +104,7 @@ Resources: SAMPLE_TABLE: !Ref SampleTable POWERTOOLS_SERVICE_NAME: items-store POWERTOOLS_METRICS_NAMESPACE: PowertoolsSAMExample - LOG_LEVEL: Debug + POWERTOOLS_LOG_LEVEL: debug Events: Api: Type: Api @@ -134,7 +134,7 @@ Resources: Variables: POWERTOOLS_SERVICE_NAME: items-store POWERTOOLS_METRICS_NAMESPACE: PowertoolsSAMExample - LOG_LEVEL: Debug + POWERTOOLS_LOG_LEVEL: debug # add ssm:getParameter permission to the function Policies: - SSMParameterWithSlashPrefixReadPolicy: @@ -186,7 +186,7 @@ Resources: SAMPLE_TABLE: !Ref SampleTable POWERTOOLS_SERVICE_NAME: items-store POWERTOOLS_METRICS_NAMESPACE: PowertoolsSAMExample - LOG_LEVEL: Debug + POWERTOOLS_LOG_LEVEL: debug Events: Api: Type: Api diff --git a/packages/logger/tests/e2e/basicFeatures.middy.test.ts b/packages/logger/tests/e2e/basicFeatures.middy.test.ts index 8a66abaac9..5901064aff 100644 --- a/packages/logger/tests/e2e/basicFeatures.middy.test.ts +++ b/packages/logger/tests/e2e/basicFeatures.middy.test.ts @@ -72,7 +72,7 @@ describe(`Logger E2E tests, basic functionalities middy usage`, () => { describe('Log level filtering', () => { it( - 'should filter log based on LOG_LEVEL (INFO) environment variable in Lambda', + 'should filter log based on POWERTOOLS_LOG_LEVEL (INFO) environment variable in Lambda', async () => { for (let i = 0; i < invocationCount; i++) { // Get log messages of the invocation and filter by level diff --git a/packages/logger/tests/e2e/constants.ts b/packages/logger/tests/e2e/constants.ts index d4e2b18e8e..11c2677680 100644 --- a/packages/logger/tests/e2e/constants.ts +++ b/packages/logger/tests/e2e/constants.ts @@ -23,7 +23,7 @@ const commonEnvironmentVars = { CHILD_LOG_MSG: 'child-only-log-msg', CHILD_LOG_LEVEL: 'ERROR', POWERTOOLS_SERVICE_NAME: 'logger-e2e-testing', - LOG_LEVEL: 'INFO', + POWERTOOLS_LOG_LEVEL: 'INFO', }; export { diff --git a/packages/logger/tests/e2e/sampleRate.decorator.test.ts b/packages/logger/tests/e2e/sampleRate.decorator.test.ts index 67c803dd58..7694a1bf18 100644 --- a/packages/logger/tests/e2e/sampleRate.decorator.test.ts +++ b/packages/logger/tests/e2e/sampleRate.decorator.test.ts @@ -44,7 +44,7 @@ describe(`Logger E2E tests, sample rate and injectLambdaContext()`, () => { { entry: lambdaFunctionCodeFilePath, environment: { - LOG_LEVEL: 'ERROR', + POWERTOOLS_LOG_LEVEL: 'ERROR', SAMPLE_RATE: '0.5', LOG_MSG: `Log message ${randomUUID()}`, }, diff --git a/packages/logger/tests/helpers/populateEnvironmentVariables.ts b/packages/logger/tests/helpers/populateEnvironmentVariables.ts index b993a774ba..9c7e47f8cf 100644 --- a/packages/logger/tests/helpers/populateEnvironmentVariables.ts +++ b/packages/logger/tests/helpers/populateEnvironmentVariables.ts @@ -11,5 +11,5 @@ if ( } // Powertools for AWS Lambda (TypeScript) variables -process.env.LOG_LEVEL = 'DEBUG'; +process.env.POWERTOOLS_LOG_LEVEL = 'DEBUG'; process.env.POWERTOOLS_SERVICE_NAME = 'hello-world'; diff --git a/packages/logger/tests/unit/Logger.test.ts b/packages/logger/tests/unit/Logger.test.ts index 5e56ae83c6..1c0d1e8582 100644 --- a/packages/logger/tests/unit/Logger.test.ts +++ b/packages/logger/tests/unit/Logger.test.ts @@ -208,9 +208,9 @@ describe('Class: Logger', () => { expect(consoleSpy).toBeCalledTimes(0); }); - test('when the log level is set through LOG_LEVEL env variable, it DOES print to stdout', () => { + test('when the log level is set through POWERTOOLS_LOG_LEVEL env variable, it DOES print to stdout', () => { // Prepare - process.env.LOG_LEVEL = methodOfLogger.toUpperCase(); + process.env.POWERTOOLS_LOG_LEVEL = methodOfLogger.toUpperCase(); const logger = new Logger(); const consoleSpy = jest .spyOn(logger['console'], getConsoleMethod(methodOfLogger)) @@ -2178,5 +2178,25 @@ describe('Class: Logger', () => { 'Invalid log level: INVALID' ); }); + + it('uses log level set by ALC & emits a warning when setting a higher log level than ALC', () => { + // Prepare + process.env.AWS_LAMBDA_LOG_LEVEL = 'ERROR'; + process.env.LOG_LEVEL = undefined; + process.env.POWERTOOLS_LOG_LEVEL = undefined; + const logger = new Logger(); + const warningSpy = jest.spyOn(logger, 'warn'); + + // Act + logger.setLogLevel('WARN'); + + // Assess + expect(logger.level).toBe(20); + expect(logger.getLevelName()).toBe('ERROR'); + expect(warningSpy).toHaveBeenCalledTimes(1); + expect(warningSpy).toHaveBeenCalledWith( + 'Current log level (WARN) does not match AWS Lambda Advanced Logging Controls minimum log level (ERROR). This can lead to data loss, consider adjusting them.' + ); + }); }); }); diff --git a/packages/logger/tests/unit/helpers.test.ts b/packages/logger/tests/unit/helpers.test.ts index ba16e38c31..39597f3be1 100644 --- a/packages/logger/tests/unit/helpers.test.ts +++ b/packages/logger/tests/unit/helpers.test.ts @@ -110,7 +110,7 @@ describe('Helper: createLogger function', () => { // Prepare const loggerOptions = undefined; delete process.env.POWERTOOLS_SERVICE_NAME; - delete process.env.LOG_LEVEL; + delete process.env.POWERTOOLS_LOG_LEVEL; // Act const logger = createLogger(loggerOptions); @@ -260,7 +260,7 @@ describe('Helper: createLogger function', () => { test('when no log level is set, returns a Logger instance with INFO level', () => { // Prepare const loggerOptions: ConstructorOptions = {}; - delete process.env.LOG_LEVEL; + delete process.env.POWERTOOLS_LOG_LEVEL; // Act const logger = createLogger(loggerOptions); @@ -325,6 +325,9 @@ describe('Helper: createLogger function', () => { get(name: string): string { return `a-string-from-${name}`; }, + getAwsLogLevel(): string { + return 'INFO'; + }, getCurrentEnvironment(): string { return 'dev'; },