feat(logger): introduce POWERTOOLS_DEBUG for internal debugging (aws-powertools#1572)

Author: heitorlessa

aws_lambda_powertools/package_logger.py

@@ -1,7 +1,25 @@
 import logging
 
+from aws_lambda_powertools.logging.logger import set_package_logger
+from aws_lambda_powertools.shared.functions import powertools_debug_is_set
+
+
+def set_package_logger_handler(stream=None):
+    """Sets up Lambda Powertools package logging.
+
+    By default, we discard any output to not interfere with customers logging.
+
+    When POWERTOOLS_DEBUG env var is set, we setup `aws_lambda_powertools` logger in DEBUG level.
+
+    Parameters
+    ----------
+    stream: sys.stdout
+        log stream, stdout by default
+    """
+
+    if powertools_debug_is_set():
+        return set_package_logger(stream=stream)
 
-def set_package_logger_handler():
     logger = logging.getLogger("aws_lambda_powertools")
     logger.addHandler(logging.NullHandler())
     logger.propagate = False

aws_lambda_powertools/shared/constants.py

@@ -36,4 +36,6 @@
 # JSON indentation level
 PRETTY_INDENT: int = 4
 COMPACT_INDENT = None
+
 POWERTOOLS_DEV_ENV: str = "POWERTOOLS_DEV"
+POWERTOOLS_DEBUG_ENV: str = "POWERTOOLS_DEBUG"

aws_lambda_powertools/shared/functions.py

@@ -20,9 +20,9 @@ def strtobool(value: str) -> bool:
     > note:: Copied from distutils.util.
     """
     value = value.lower()
-    if value in ("y", "yes", "t", "true", "on", "1"):
+    if value in ("1", "y", "yes", "t", "true", "on"):
         return True
-    if value in ("n", "no", "f", "false", "off", "0"):
+    if value in ("0", "n", "no", "f", "false", "off"):
         return False
     raise ValueError(f"invalid truth value {value!r}")
 
@@ -91,3 +91,12 @@ def powertools_dev_is_set() -> bool:
         return True
 
     return False
+
+
+def powertools_debug_is_set() -> bool:
+    is_on = strtobool(os.getenv(constants.POWERTOOLS_DEBUG_ENV, "0"))
+    if is_on:
+        warnings.warn("POWERTOOLS_DEBUG environment variable is enabled. Setting logging level to DEBUG.")
+        return True
+
+    return False

docs/index.md

@@ -454,15 +454,9 @@ Core utilities such as Tracing, Logging, Metrics, and Event Handler will be avai
 
 ## Debug mode
 
-As a best practice, AWS Lambda Powertools module logging statements are suppressed. If necessary, you can enable debugging using `set_package_logger` for additional information on every internal operation:
+As a best practice for libraries, AWS Lambda Powertools module logging statements are suppressed.
 
-```python title="Powertools debug mode example"
-from aws_lambda_powertools.logging.logger import set_package_logger
-
-set_package_logger() # (1)
-```
-
-1. :information_source: this will configure our `aws_lambda_powertools` logger with debug.
+When necessary, you can use `POWERTOOLS_DEBUG` environment variable to enable debugging. This will provide additional information on every internal operation.
 
 ## Tenets
 

tests/functional/test_logger.py

@@ -5,14 +5,15 @@
 import random
 import re
 import string
+import warnings
 from ast import Dict
 from collections import namedtuple
 from datetime import datetime, timezone
 from typing import Any, Callable, Iterable, List, Optional, Union
 
 import pytest
 
-from aws_lambda_powertools import Logger, Tracer
+from aws_lambda_powertools import Logger, Tracer, set_package_logger_handler
 from aws_lambda_powertools.logging import correlation_paths
 from aws_lambda_powertools.logging.exceptions import InvalidLoggerSamplingRateError
 from aws_lambda_powertools.logging.formatter import (
@@ -827,3 +828,33 @@ def handler(event, context, planet, str_end="."):
     log = capture_logging_output(stdout)
 
     assert log["message"] == "Hello World!"
+
+
+def test_set_package_logger_handler_with_powertools_debug_env_var(stdout, monkeypatch: pytest.MonkeyPatch):
+    # GIVEN POWERTOOLS_DEBUG is set
+    monkeypatch.setenv(constants.POWERTOOLS_DEBUG_ENV, "1")
+    logger = logging.getLogger("aws_lambda_powertools")
+
+    # WHEN set_package_logger is used at initialization
+    # and any Powertools operation is used (e.g., Tracer)
+    set_package_logger_handler(stream=stdout)
+    Tracer(disabled=True)
+
+    # THEN Tracer debug log statement should be logged
+    output = stdout.getvalue()
+    assert "Tracing has been disabled" in output
+    assert logger.level == logging.DEBUG
+
+
+def test_powertools_debug_env_var_warning(monkeypatch: pytest.MonkeyPatch):
+    # GIVEN POWERTOOLS_DEBUG is set
+    monkeypatch.setenv(constants.POWERTOOLS_DEBUG_ENV, "1")
+    warning_message = "POWERTOOLS_DEBUG environment variable is enabled. Setting logging level to DEBUG."
+
+    # WHEN set_package_logger is used at initialization
+    # THEN a warning should be emitted
+    with warnings.catch_warnings(record=True) as w:
+        warnings.simplefilter("default")
+        set_package_logger_handler()
+        assert len(w) == 1
+        assert str(w[0].message) == warning_message

tests/functional/test_shared_functions.py

@@ -1,6 +1,11 @@
+import warnings
+
 import pytest
 
+from aws_lambda_powertools.shared import constants
 from aws_lambda_powertools.shared.functions import (
+    powertools_debug_is_set,
+    powertools_dev_is_set,
     resolve_env_var_choice,
     resolve_truthy_env_var_choice,
     strtobool,
@@ -31,3 +36,31 @@ def test_strtobool_value_error():
     with pytest.raises(ValueError) as exp:
         strtobool("fail")
     assert str(exp.value) == "invalid truth value 'fail'"
+
+
+def test_powertools_dev_warning(monkeypatch: pytest.MonkeyPatch):
+    # GIVEN POWERTOOLS_DEBUG is set
+    monkeypatch.setenv(constants.POWERTOOLS_DEV_ENV, "1")
+    warning_message = "POWERTOOLS_DEV environment variable is enabled. Increasing verbosity across utilities."
+
+    # WHEN set_package_logger is used at initialization
+    # THEN a warning should be emitted
+    with warnings.catch_warnings(record=True) as w:
+        warnings.simplefilter("default")
+        powertools_dev_is_set()
+        assert len(w) == 1
+        assert str(w[0].message) == warning_message
+
+
+def test_powertools_debug_warning(monkeypatch: pytest.MonkeyPatch):
+    # GIVEN POWERTOOLS_DEBUG is set
+    monkeypatch.setenv(constants.POWERTOOLS_DEBUG_ENV, "1")
+    warning_message = "POWERTOOLS_DEBUG environment variable is enabled. Setting logging level to DEBUG."
+
+    # WHEN set_package_logger is used at initialization
+    # THEN a warning should be emitted
+    with warnings.catch_warnings(record=True) as w:
+        warnings.simplefilter("default")
+        powertools_debug_is_set()
+        assert len(w) == 1
+        assert str(w[0].message) == warning_message