feat(logger): Adding support to new env variables (aws-powertools#3348)

leandrodamascena · web-flow · commit 9fc5169fba89 · 2023-11-16T16:30:27.000+01:00
diff --git a/aws_lambda_powertools/logging/logger.py b/aws_lambda_powertools/logging/logger.py
@@ -6,6 +6,7 @@
 import os
 import random
 import sys
+import warnings
 from typing import (
     IO,
     TYPE_CHECKING,
@@ -24,13 +25,13 @@
 import jmespath
 
 from aws_lambda_powertools.logging import compat
-
-from ..shared import constants
-from ..shared.functions import (
+from aws_lambda_powertools.shared import constants
+from aws_lambda_powertools.shared.functions import (
     extract_event_from_common_models,
     resolve_env_var_choice,
     resolve_truthy_env_var_choice,
 )
+
 from ..shared.types import AnyCallableT
 from .exceptions import InvalidLoggerSamplingRateError
 from .filters import SuppressFilter
@@ -76,7 +77,7 @@ class Logger:
     ---------------------
     POWERTOOLS_SERVICE_NAME : str
         service name
-    LOG_LEVEL: str
+    POWERTOOLS_LOG_LEVEL: str
         logging level (e.g. INFO, DEBUG)
     POWERTOOLS_LOGGER_SAMPLE_RATE: float
         sampling rate ranging from 0 to 1, 1 being 100% sampling
@@ -297,7 +298,7 @@ def _init_logger(
         if self.child or is_logger_preconfigured:
             return
 
-        self.setLevel(self._determine_log_level(log_level))
+        self.setLevel(log_level)
         self._configure_sampling()
         self.addHandler(self.logger_handler)
         self.structure_logs(formatter_options=formatter_options, **kwargs)
@@ -676,8 +677,8 @@ def get_correlation_id(self) -> Optional[str]:
             return self.registered_formatter.log_format.get("correlation_id")
         return None
 
-    def setLevel(self, level: Union[str, int]) -> None:
-        return self._logger.setLevel(level)
+    def setLevel(self, level: Union[str, int, None]) -> None:
+        return self._logger.setLevel(self._determine_log_level(level))
 
     def addHandler(self, handler: logging.Handler) -> None:
         return self._logger.addHandler(handler)
@@ -714,17 +715,88 @@ def handlers(self) -> List[logging.Handler]:
         """
         return self._logger.handlers
 
-    @staticmethod
-    def _determine_log_level(level: Union[str, int, None]) -> Union[str, int]:
-        """Returns preferred log level set by the customer in upper case"""
+    def _get_aws_lambda_log_level(self) -> Optional[str]:
+        """
+        Retrieve the log level for AWS Lambda from the Advanced Logging Controls feature.
+        Returns:
+            Optional[str]: The corresponding logging level.
+        """
+
+        return constants.LAMBDA_ADVANCED_LOGGING_LEVELS.get(os.getenv(constants.LAMBDA_LOG_LEVEL_ENV))
+
+    def _get_powertools_log_level(self, level: Union[str, int, None]) -> Optional[str]:
+        """Retrieve the log level for Powertools from the environment variable or level parameter.
+        If log level is an integer, we convert to its respective string level `logging.getLevelName()`.
+        If no log level is provided, we check env vars for the log level: POWERTOOLS_LOG_LEVEL_ENV and POWERTOOLS_LOG_LEVEL_LEGACY_ENV.
+        Parameters:
+        -----------
+        level : Union[str, int, None]
+            The specified log level as a string, integer, or None.
+        Environment variables
+        ---------------------
+        POWERTOOLS_LOG_LEVEL : str
+            log level (e.g: INFO, DEBUG, WARNING, ERROR, CRITICAL)
+        LOG_LEVEL (Legacy) : str
+            log level (e.g: INFO, DEBUG, WARNING, ERROR, CRITICAL)
+        Returns:
+        --------
+        Optional[str]:
+            The corresponding logging level. Returns None if the log level is not explicitly specified.
+        """  # noqa E501
+
+        # Extract log level from Powertools Logger env vars
+        log_level_env = os.getenv(constants.POWERTOOLS_LOG_LEVEL_ENV) or os.getenv(
+            constants.POWERTOOLS_LOG_LEVEL_LEGACY_ENV,
+        )
+        # If level is an int (logging.INFO), return its respective string ("INFO")
         if isinstance(level, int):
-            return level
+            return logging.getLevelName(level)
+
+        return level or log_level_env
+
+    def _determine_log_level(self, level: Union[str, int, None]) -> Union[str, int]:
+        """Determine the effective log level considering Lambda and Powertools preferences.
+        It emits an UserWarning if Lambda ALC log level is lower than Logger log level.
+        Parameters:
+        -----------
+        level: Union[str, int, None]
+            The specified log level as a string, integer, or None.
+        Returns:
+        ----------
+            Union[str, int]: The effective logging level.
+        """
 
-        log_level: Optional[str] = level or os.getenv("LOG_LEVEL")
-        if log_level is None:
+        # This function consider the following order of precedence:
+        # 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 setLevel, it sets it.
+        # 4 - If a log level is set via Powertools env variables, it sets it.
+        # 5 - If none of the above is true, the default log level applies INFO.
+
+        lambda_log_level = self._get_aws_lambda_log_level()
+        powertools_log_level = self._get_powertools_log_level(level)
+
+        if powertools_log_level and lambda_log_level:
+            # If Powertools log level is set and higher than AWS Lambda Advanced Logging Controls, emit a warning
+            if logging.getLevelName(lambda_log_level) > logging.getLevelName(powertools_log_level):
+                warnings.warn(
+                    f"Current log level ({powertools_log_level}) does not match AWS Lambda Advanced Logging Controls "
+                    f"minimum log level ({lambda_log_level}). This can lead to data loss, consider adjusting them.",
+                    UserWarning,
+                    stacklevel=2,
+                )
+
+        # AWS Lambda Advanced Logging Controls takes precedence over Powertools log level and we use this
+        if lambda_log_level:
+            return lambda_log_level
+
+        # Check if Powertools log level is None, which means it's not set
+        # We assume INFO as the default log level
+        if powertools_log_level is None:
             return logging.INFO
 
-        return log_level.upper()
+        # Powertools log level is set, we use this
+        return powertools_log_level.upper()
 
 
 def set_package_logger(
diff --git a/aws_lambda_powertools/shared/constants.py b/aws_lambda_powertools/shared/constants.py
@@ -42,3 +42,18 @@
 
 POWERTOOLS_DEV_ENV: str = "POWERTOOLS_DEV"
 POWERTOOLS_DEBUG_ENV: str = "POWERTOOLS_DEBUG"
+POWERTOOLS_LOG_LEVEL_ENV: str = "POWERTOOLS_LOG_LEVEL"
+POWERTOOLS_LOG_LEVEL_LEGACY_ENV: str = "LOG_LEVEL"
+LAMBDA_LOG_LEVEL_ENV: str = "AWS_LAMBDA_LOG_LEVEL"
+
+# Mapping of Lambda log levels to Python logging levels
+# https://docs.aws.amazon.com/lambda/latest/dg/configuration-logging.html#configuration-logging-log-levels
+LAMBDA_ADVANCED_LOGGING_LEVELS = {
+    None: None,
+    "TRACE": "NOTSET",
+    "DEBUG": "DEBUG",
+    "INFO": "INFO",
+    "WARN": "WARNING",
+    "ERROR": "ERROR",
+    "FATAL": "CRITICAL",
+}
diff --git a/benchmark/template.yaml b/benchmark/template.yaml
@@ -12,7 +12,7 @@ Globals:
         POWERTOOLS_SERVICE_NAME: benchmark
         POWERTOOLS_METRICS_NAMESPACE: LambdaPowertools
         POWERTOOLS_LOGGER_LOG_EVENT: "true"
-        LOG_LEVEL: INFO
+        POWERTOOLS_LOG_LEVEL: INFO
 
 Resources:
   InstrumentedFunction:
@@ -45,4 +45,4 @@ Outputs:
   InstrumentedLogGroup:
     Value: !Ref InstrumentedLogGroup
   ReferenceLogGroup:
-    Value: !Ref ReferenceLogGroup
+    Value: !Ref ReferenceLogGroup
diff --git a/docs/core/logger.md b/docs/core/logger.md
@@ -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)                | `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.
 
@@ -274,6 +274,70 @@ Logger is commonly initialized in the global scope. Due to [Lambda Execution Con
     --8<-- "examples/logger/src/clear_state_event_two.json"
     ```
 
+### Log levels
+
+The default log level is `INFO`. It can be set using the `level` constructor option, `setLevel()` method or by using the `POWERTOOLS_LOG_LEVEL` environment variable.
+
+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`
+
+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`.
+
+=== "setting_log_level_constructor.py"
+
+    ```python hl_lines="3"
+    --8<-- "examples/logger/src/setting_log_level_via_constructor.py"
+    ```
+
+=== "setting_log_level_programmatically.py"
+
+    ```python hl_lines="6 9 12"
+    --8<-- "examples/logger/src/setting_log_level_programmatically.py"
+    ```
+
+#### AWS Lambda Advanced Logging Controls (ALC)
+
+<!-- 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 -->
+
+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 `level` constructor option, 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.
+
 ### Logging exceptions
 
 Use `logger.exception` method to log contextual information about exceptions. Logger will include `exception_name` and `exception` keys to aid troubleshooting and error enumeration.
diff --git a/docs/index.md b/docs/index.md
@@ -722,7 +722,7 @@ Core utilities such as Tracing, Logging, Metrics, and Event Handler will be avai
 | **POWERTOOLS_PARAMETERS_MAX_AGE**         | Adjust how long values are kept in cache (in seconds)                                  | [Parameters](./utilities/parameters.md#adjusting-cache-ttl){target="_blank"}             | `5`                   |
 | **POWERTOOLS_PARAMETERS_SSM_DECRYPT**     | Sets whether to decrypt or not values retrieved from AWS SSM Parameters Store          | [Parameters](./utilities/parameters.md#ssmprovider){target="_blank"}                     | `false`               |
 | **POWERTOOLS_DEV**                        | Increases verbosity across utilities                                                   | Multiple; see [POWERTOOLS_DEV effect below](#optimizing-for-non-production-environments) | `false`               |
-| **LOG_LEVEL**                             | Sets logging level                                                                     | [Logging](./core/logger.md){target="_blank"}                                             | `INFO`                |
+| **POWERTOOLS_LOG_LEVEL**                  | Sets logging level                                                                     | [Logging](./core/logger.md){target="_blank"}                                             | `INFO`                |
 
 ### Optimizing for non-production environments
 
diff --git a/docs/tutorial/index.md b/docs/tutorial/index.md
@@ -392,7 +392,7 @@ The first option could be to use the standard Python Logger, and use a specializ
     formatter = jsonlogger.JsonFormatter(fmt="%(asctime)s %(levelname)s %(name)s %(message)s")
     logHandler.setFormatter(formatter)
     logger.addHandler(logHandler)
-    logger.setLevel(os.getenv("LOG_LEVEL", "INFO"))
+    logger.setLevel(os.getenv("POWERTOOLS_LOG_LEVEL", "INFO"))
 
     app = APIGatewayRestResolver()
 
@@ -424,7 +424,7 @@ With just a few lines our logs will now output to `JSON` format. We've taken the
 
 * **L7**: Creates an application logger named `APP`.
 * **L8-11**: Configures handler and formatter.
-* **L12**: Sets the logging level set in the `LOG_LEVEL` environment variable, or `INFO` as a sentinel value.
+* **L12**: Sets the logging level set in the `POWERTOOLS_LOG_LEVEL` environment variable, or `INFO` as a sentinel value.
 
 After that, we use this logger in our application code to record the required information. We see logs structured as follows:
 
@@ -485,7 +485,7 @@ def lambda_handler(event, context):
 
 Let's break this down:
 
-* **L5**: We add Powertools for AWS Lambda (Python) Logger; the boilerplate is now done for you. By default, we set `INFO` as the logging level if `LOG_LEVEL` env var isn't set.
+* **L5**: We add Powertools for AWS Lambda (Python) Logger; the boilerplate is now done for you. By default, we set `INFO` as the logging level if `POWERTOOLS_LOG_LEVEL` env var isn't set.
 * **L22**: We use `logger.inject_lambda_context` decorator to inject key information from Lambda context into every log.
 * **L22**: We also instruct Logger to use the incoming API Gateway Request ID as a [correlation id](../core/logger.md##set_correlation_id-method){target="_blank"} automatically.
 * **L22**: Since we're in dev, we also use `log_event=True` to automatically log each incoming request for debugging. This can be also set via [environment variables](./index.md#environment-variables){target="_blank"}.
diff --git a/examples/batch_processing/sam/dynamodb_batch_processing.yaml b/examples/batch_processing/sam/dynamodb_batch_processing.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/batch_processing/sam/kinesis_batch_processing.yaml b/examples/batch_processing/sam/kinesis_batch_processing.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/batch_processing/sam/sqs_batch_processing.yaml b/examples/batch_processing/sam/sqs_batch_processing.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/event_handler_graphql/sam/template.yaml b/examples/event_handler_graphql/sam/template.yaml
@@ -10,7 +10,7 @@ Globals:
     Environment:
       Variables:
         # Powertools for AWS Lambda (Python) env vars: https://docs.powertools.aws.dev/lambda/python/latest/#environment-variables
-        LOG_LEVEL: INFO
+        POWERTOOLS_LOG_LEVEL: INFO
         POWERTOOLS_LOGGER_SAMPLE_RATE: 0.1
         POWERTOOLS_LOGGER_LOG_EVENT: true
         POWERTOOLS_SERVICE_NAME: example
diff --git a/examples/event_handler_lambda_function_url/sam/template.yaml b/examples/event_handler_lambda_function_url/sam/template.yaml
@@ -9,7 +9,7 @@ Globals:
     Tracing: Active
     Environment:
       Variables:
-        LOG_LEVEL: INFO
+        POWERTOOLS_LOG_LEVEL: INFO
         POWERTOOLS_LOGGER_SAMPLE_RATE: 0.1
         POWERTOOLS_LOGGER_LOG_EVENT: true
         POWERTOOLS_SERVICE_NAME: example
diff --git a/examples/event_handler_rest/sam/micro_function_template.yaml b/examples/event_handler_rest/sam/micro_function_template.yaml
@@ -37,7 +37,7 @@ Resources:
             MemorySize: 128 # Each Lambda Function can have it's own memory configuration
             Environment:
                 Variables:
-                    LOG_LEVEL: INFO
+                    POWERTOOLS_LOG_LEVEL: INFO
             Tags:
                 LambdaPowertools: python
 
@@ -60,4 +60,4 @@ Resources:
             MemorySize: 128 # Each Lambda Function can have it's own memory configuration
             Environment:
                 Variables:
-                    LOG_LEVEL: INFO
+                    POWERTOOLS_LOG_LEVEL: INFO
diff --git a/examples/event_handler_rest/sam/template.yaml b/examples/event_handler_rest/sam/template.yaml
@@ -17,7 +17,7 @@ Globals:
     Tracing: Active
     Environment:
       Variables:
-        LOG_LEVEL: INFO
+        POWERTOOLS_LOG_LEVEL: INFO
         POWERTOOLS_LOGGER_SAMPLE_RATE: 0.1
         POWERTOOLS_LOGGER_LOG_EVENT: true
         POWERTOOLS_SERVICE_NAME: example
diff --git a/examples/logger/sam/template.yaml b/examples/logger/sam/template.yaml
@@ -10,7 +10,7 @@ Globals:
     Environment:
       Variables:
         POWERTOOLS_SERVICE_NAME: payment
-        LOG_LEVEL: INFO
+        POWERTOOLS_LOG_LEVEL: INFO
     Layers:
       # Find the latest Layer version in the official documentation
       # https://docs.powertools.aws.dev/lambda/python/latest/#lambda-layer
diff --git a/examples/logger/src/setting_log_level_programmatically.py b/examples/logger/src/setting_log_level_programmatically.py
@@ -0,0 +1,12 @@
+from aws_lambda_powertools import Logger
+
+logger = Logger()
+
+# print default log level
+print(logger.log_level)  # returns 20 (INFO)
+
+# Setting programmatic log level
+logger.setLevel("DEBUG")
+
+# print new log level
+print(logger.log_level)  # returns 10 (DEBUG)
diff --git a/examples/logger/src/setting_log_level_via_constructor.py b/examples/logger/src/setting_log_level_via_constructor.py
diff --git a/examples/middleware_factory/sam/combining_powertools_utilities_template.yaml b/examples/middleware_factory/sam/combining_powertools_utilities_template.yaml
diff --git a/tests/functional/test_logger.py b/tests/functional/test_logger.py
diff --git a/tests/performance/data_masking/load_test_data_masking/pt-load-test-stack/template.yaml b/tests/performance/data_masking/load_test_data_masking/pt-load-test-stack/template.yaml
