Skip to content

Commit

Permalink
docs(logger): improve ALC messaging in the PT context (#3359)
Browse files Browse the repository at this point in the history 
* fix(parameters): make cache aware of single vs multiple calls

Signed-off-by: heitorlessa <lessa@amazon.co.uk>

* chore: cleanup, add test for single and nested

Signed-off-by: heitorlessa <lessa@amazon.co.uk>

* docs(logger): improve messaging on ALC usefulness in PT ctx

---------

Signed-off-by: heitorlessa <lessa@amazon.co.uk>
Co-authored-by: Leandro Damascena <lcdama@amazon.pt>
  • Loading branch information
@heitorlessa @leandrodamascena
heitorlessa and leandrodamascena authored Nov 17, 2023
1 parent 879e5c8 commit 85d4df8
Showing 1 changed file with 38 additions and 28 deletions.
66 changes: 38 additions & 28 deletions docs/core/logger.md
View file
Original file line number Diff line number Diff line change
Expand Up @@ -19,10 +19,10 @@ Logger provides an opinionated logger with output structured as JSON.

Logger requires two settings:

| Setting | Description | Environment variable | Constructor parameter |
| ----------------- | ------------------------------------------------------------------- | --------------------------------------------------- | --------------------- |
| **Logging level** | Sets how verbose Logger should be (INFO, by default) | `POWERTOOLS_LOG_LEVEL` | `level` |
| **Service** | Sets **service** key that will be present across all log statements | `POWERTOOLS_SERVICE_NAME` | `service` |
| Setting | Description | Environment variable | Constructor parameter |
| ----------------- | ------------------------------------------------------------------- | ------------------------- | --------------------- |
| **Logging level** | Sets how verbose Logger should be (INFO, by default) | `POWERTOOLS_LOG_LEVEL` | `level` |
| **Service** | Sets **service** key that will be present across all log statements | `POWERTOOLS_SERVICE_NAME` | `service` |

There are some [other environment variables](#environment-variables) which can be set to modify Logger's settings at a global scope.

Expand All @@ -39,7 +39,7 @@ Your Logger will include the following keys to your structured logging:
| **level**: `str` | `INFO` | Logging level |
| **location**: `str` | `collect.handler:1` | Source code location where statement was executed |
| **message**: `Any` | `Collecting payment` | Unserializable JSON values are casted as `str` |
| **timestamp**: `str` | `2021-05-03 10:20:19,650+0000` | Timestamp with milliseconds, by default uses default AWS Lambda timezone (UTC) |
| **timestamp**: `str` | `2021-05-03 10:20:19,650+0000` | Timestamp with milliseconds, by default uses default AWS Lambda timezone (UTC) |
| **service**: `str` | `payment` | Service name defined, by default `service_undefined` |
| **xray_trace_id**: `str` | `1-5759e988-bd862e3fe1be46a994272793` | When [tracing is enabled](https://docs.aws.amazon.com/lambda/latest/dg/services-xray.html){target="_blank"}, it shows X-Ray Trace ID |
| **sampling_rate**: `float` | `0.1` | When enabled, it shows sampling rate in percentage e.g. 10% |
Expand Down Expand Up @@ -280,13 +280,13 @@ The default log level is `INFO`. It can be set using the `level` constructor opt

We support the following log levels:

| Level | Numeric value | Standard logging
| ---------- | ------------- | -----------------
| `DEBUG` | 10 | `logging.DEBUG`
| `INFO` | 20 | `logging.INFO`
| `WARNING` | 30 | `logging.WARNING`
| `ERROR` | 40 | `logging.ERROR`
| `CRITICAL` | 50 | `logging.CRITICAL`
| Level | Numeric value | Standard logging |
| ---------- | ------------- | ------------------ |
| `DEBUG` | 10 | `logging.DEBUG` |
| `INFO` | 20 | `logging.INFO` |
| `WARNING` | 30 | `logging.WARNING` |
| `ERROR` | 40 | `logging.ERROR` |
| `CRITICAL` | 50 | `logging.CRITICAL` |

If you want to access the numeric value of the current log level, you can use the `log_level` property. For example, if the current log level is `INFO`, `logger.log_level` property will return `10`.

Expand All @@ -304,39 +304,49 @@ If you want to access the numeric value of the current log level, you can use th

#### AWS Lambda Advanced Logging Controls (ALC)

!!! question "When is it useful?"
When you want to set a logging policy to drop informational or verbose logs for one or all AWS Lambda functions, regardless of runtime and logger used.

<!-- markdownlint-disable MD013 -->
With [AWS Lambda Advanced Logging Controls (ALC)](https://docs.aws.amazon.com/lambda/latest/dg/monitoring-cloudwatchlogs.html#monitoring-cloudwatchlogs-advanced){target="_blank"}, 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.
<!-- markdownlint-enable MD013 -->
With [AWS Lambda Advanced Logging Controls (ALC)](https://docs.aws.amazon.com/lambda/latest/dg/monitoring-cloudwatchlogs.html#monitoring-cloudwatchlogs-advanced){target="_blank"}, you can enforce a minimum log level that Lambda will accept from your application code.

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.
When enabled, you should keep `Logger` and ALC log level in sync to avoid data loss.

Here's a sequence diagram to demonstrate how ALC will drop both `INFO` and `DEBUG` logs emitted from `Logger`, when ALC log level is stricter than `Logger`.
<!-- markdownlint-enable MD013 -->

```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"
Note over Application Logger: POWERTOOLS_LOG_LEVEL="DEBUG"
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.error("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--xLambda 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](https://docs.aws.amazon.com/lambda/latest/dg/monitoring-cloudwatchlogs.html#monitoring-cloudwatchlogs-log-level){target="_blank"} 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 `level` constructor option, or by calling the `logger.setLevel()` method
2. Explicit log level in `Logger` constructor, or by calling the `logger.setLevel()` 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.
If you set `Logger` level lower than ALC, we will emit a warning informing you that your messages will be discarded by Lambda.

> **NOTE**
>
> With ALC 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){target="_blank"} for more details.
### Logging exceptions

Expand Down Expand Up @@ -427,12 +437,12 @@ You can easily change the date format using one of the following parameters:

The following environment variables are available to configure Logger at a global scope:

| Setting | Description | Environment variable | Default |
|---------------------------|------------------------------------------------------------------------------|-----------------------------------------|---------|
| **Event Logging** | Whether to log the incoming event. | `POWERTOOLS_LOGGER_LOG_EVENT` | `false` |
| **Debug Sample Rate** | Sets the debug log sampling. | `POWERTOOLS_LOGGER_SAMPLE_RATE` | `0` |
| **Disable Deduplication** | Disables log deduplication filter protection to use Pytest Live Log feature. | `POWERTOOLS_LOG_DEDUPLICATION_DISABLED` | `false` |
| **TZ** | Sets timezone when using Logger, e.g., `US/Eastern`. Timezone is defaulted to UTC when `TZ` is not set | `TZ` | `None` (UTC) |
| Setting | Description | Environment variable | Default |
| ------------------------- | ------------------------------------------------------------------------------------------------------ | --------------------------------------- | ------------ |
| **Event Logging** | Whether to log the incoming event. | `POWERTOOLS_LOGGER_LOG_EVENT` | `false` |
| **Debug Sample Rate** | Sets the debug log sampling. | `POWERTOOLS_LOGGER_SAMPLE_RATE` | `0` |
| **Disable Deduplication** | Disables log deduplication filter protection to use Pytest Live Log feature. | `POWERTOOLS_LOG_DEDUPLICATION_DISABLED` | `false` |
| **TZ** | Sets timezone when using Logger, e.g., `US/Eastern`. Timezone is defaulted to UTC when `TZ` is not set | `TZ` | `None` (UTC) |

[`POWERTOOLS_LOGGER_LOG_EVENT`](#logging-incoming-event) can also be set on a per-method basis, and [`POWERTOOLS_LOGGER_SAMPLE_RATE`](#sampling-debug-logs) on a per-instance basis. These parameter values will override the environment variable value.

Expand Down Expand Up @@ -529,7 +539,7 @@ If you prefer configuring it separately, or you'd want to bring this JSON Format
| **`json_default`** | function to coerce unserializable values, when no custom serializer/deserializer is set | `str` |
| **`datefmt`** | string directives (strftime) to format log timestamp | `%Y-%m-%d %H:%M:%S,%F%z`, where `%F` is a custom ms directive |
| **`use_datetime_directive`** | format the `datefmt` timestamps using `datetime`, not `time` (also supports the custom `%F` directive for milliseconds) | `False` |
| **`utc`** | enforce logging timestamp to UTC (ignore `TZ` environment variable) | `False` |
| **`utc`** | enforce logging timestamp to UTC (ignore `TZ` environment variable) | `False` |
| **`log_record_order`** | set order of log keys when logging | `["level", "location", "message", "timestamp"]` |
| **`kwargs`** | key-value to be included in log messages | `None` |

Expand Down

0 comments on commit 85d4df8

Please sign in to comment.