chore(tests): refactor E2E logger to ease maintenance, writing tests and parallelization (#1460)

Author: heitorlessa

aws_lambda_powertools/shared/constants.py

@@ -23,3 +23,12 @@
 XRAY_SDK_CORE_MODULE: str = "aws_xray_sdk.core"
 
 IDEMPOTENCY_DISABLED_ENV: str = "POWERTOOLS_IDEMPOTENCY_DISABLED"
+
+LOGGER_LAMBDA_CONTEXT_KEYS = [
+    "function_arn",
+    "function_memory_size",
+    "function_name",
+    "function_request_id",
+    "cold_start",
+    "xray_trace_id",
+]

poetry.lock

@@ -65,6 +65,7 @@ mypy-boto3-lambda = "^1.24.0"
 mypy-boto3-xray = "^1.24.0"
 mypy-boto3-s3 = { version = "^1.24.0", python = ">=3.7" }
 mypy-boto3-cloudformation = { version = "^1.24.0", python = ">=3.7" }
+mypy-boto3-logs = { version = "^1.24.0", python = ">=3.7" }
 types-requests = "^2.28.8"
 typing-extensions = { version = "^4.3.0", python = ">=3.7" }
 python-snappy = "^0.6.1"

pyproject.toml

@@ -0,0 +1,25 @@
+import pytest
+
+from tests.e2e.logger.infrastructure import LoggerStack
+from tests.e2e.utils.infrastructure import deploy_once
+
+
+@pytest.fixture(autouse=True, scope="module")
+def infrastructure(request: pytest.FixtureRequest, tmp_path_factory: pytest.TempPathFactory, worker_id: str):
+    """Setup and teardown logic for E2E test infrastructure
+
+    Parameters
+    ----------
+    request : pytest.FixtureRequest
+        pytest request fixture to introspect absolute path to test being executed
+    tmp_path_factory : pytest.TempPathFactory
+        pytest temporary path factory to discover shared tmp when multiple CPU processes are spun up
+    worker_id : str
+        pytest-xdist worker identification to detect whether parallelization is enabled
+
+    Yields
+    ------
+    Dict[str, str]
+        CloudFormation Outputs from deployed infrastructure
+    """
+    yield from deploy_once(stack=LoggerStack, request=request, tmp_path_factory=tmp_path_factory, worker_id=worker_id)

tests/e2e/logger/conftest.py

@@ -1,17 +1,11 @@
-import os
-
 from aws_lambda_powertools import Logger
 
 logger = Logger()
 
-MESSAGE = os.environ["MESSAGE"]
-ADDITIONAL_KEY = os.environ["ADDITIONAL_KEY"]
-
 
-@logger.inject_lambda_context(log_event=True)
+@logger.inject_lambda_context
 def lambda_handler(event, context):
-    logger.debug(MESSAGE)
-    logger.info(MESSAGE)
-    logger.append_keys(**{ADDITIONAL_KEY: "test"})
-    logger.info(MESSAGE)
+    message, append_keys = event.get("message", ""), event.get("append_keys", {})
+    logger.append_keys(**append_keys)
+    logger.info(message)
     return "success"

tests/e2e/logger/handlers/basic_handler.py

@@ -0,0 +1,11 @@
+from pathlib import Path
+
+from tests.e2e.utils.infrastructure import BaseInfrastructureV2
+
+
+class LoggerStack(BaseInfrastructureV2):
+    def __init__(self, handlers_dir: Path, feature_name: str = "logger") -> None:
+        super().__init__(feature_name, handlers_dir)
+
+    def create_resources(self):
+        self.create_lambda_functions()

tests/e2e/logger/handlers/no_context_handler.py

@@ -1,143 +1,37 @@
-import boto3
+import json
+from uuid import uuid4
+
 import pytest
-from e2e import conftest
 
+from aws_lambda_powertools.shared.constants import LOGGER_LAMBDA_CONTEXT_KEYS
 from tests.e2e.utils import data_fetcher
 
 
-@pytest.fixture(scope="module")
-def config() -> conftest.LambdaConfig:
-    return {
-        "parameters": {},
-        "environment_variables": {
-            "MESSAGE": "logger message test",
-            "LOG_LEVEL": "INFO",
-            "ADDITIONAL_KEY": "extra_info",
-        },
-    }
-
-
-def test_basic_lambda_logs_visible(execute_lambda: conftest.InfrastructureOutput, config: conftest.LambdaConfig):
-    # GIVEN
-    lambda_name = execute_lambda.get_lambda_function_name(cf_output_name="basichandlerarn")
-    timestamp = execute_lambda.get_lambda_execution_time_timestamp()
-    cw_client = boto3.client("logs")
+@pytest.fixture
+def basic_handler_fn(infrastructure: dict) -> str:
+    return infrastructure.get("BasicHandler", "")
 
-    # WHEN
-    filtered_logs = data_fetcher.get_logs(lambda_function_name=lambda_name, start_time=timestamp, log_client=cw_client)
 
-    # THEN
-    assert any(
-        log.message == config["environment_variables"]["MESSAGE"]
-        and log.level == config["environment_variables"]["LOG_LEVEL"]
-        for log in filtered_logs
-    )
+@pytest.fixture
+def basic_handler_fn_arn(infrastructure: dict) -> str:
+    return infrastructure.get("BasicHandlerArn", "")
 
 
-def test_basic_lambda_no_debug_logs_visible(
-    execute_lambda: conftest.InfrastructureOutput, config: conftest.LambdaConfig
-):
+def test_basic_lambda_logs_visible(basic_handler_fn, basic_handler_fn_arn):
     # GIVEN
-    lambda_name = execute_lambda.get_lambda_function_name(cf_output_name="basichandlerarn")
-    timestamp = execute_lambda.get_lambda_execution_time_timestamp()
-    cw_client = boto3.client("logs")
+    message = "logs should be visible with default settings"
+    custom_key = "order_id"
+    additional_keys = {custom_key: f"{uuid4()}"}
+    payload = json.dumps({"message": message, "append_keys": additional_keys})
 
     # WHEN
-    filtered_logs = data_fetcher.get_logs(lambda_function_name=lambda_name, start_time=timestamp, log_client=cw_client)
+    _, execution_time = data_fetcher.get_lambda_response(lambda_arn=basic_handler_fn_arn, payload=payload)
+    data_fetcher.get_lambda_response(lambda_arn=basic_handler_fn_arn, payload=payload)
 
     # THEN
-    assert not any(
-        log.message == config["environment_variables"]["MESSAGE"] and log.level == "DEBUG" for log in filtered_logs
-    )
-
-
-def test_basic_lambda_contextual_data_logged(execute_lambda: conftest.InfrastructureOutput):
-    # GIVEN
-    required_keys = (
-        "xray_trace_id",
-        "function_request_id",
-        "function_arn",
-        "function_memory_size",
-        "function_name",
-        "cold_start",
-    )
-
-    lambda_name = execute_lambda.get_lambda_function_name(cf_output_name="basichandlerarn")
-    timestamp = execute_lambda.get_lambda_execution_time_timestamp()
-    cw_client = boto3.client("logs")
-
-    # WHEN
-    filtered_logs = data_fetcher.get_logs(lambda_function_name=lambda_name, start_time=timestamp, log_client=cw_client)
-
-    # THEN
-    assert all(keys in logs.dict(exclude_unset=True) for logs in filtered_logs for keys in required_keys)
-
-
-def test_basic_lambda_additional_key_persistence_basic_lambda(
-    execute_lambda: conftest.InfrastructureOutput, config: conftest.LambdaConfig
-):
-    # GIVEN
-    lambda_name = execute_lambda.get_lambda_function_name(cf_output_name="basichandlerarn")
-    timestamp = execute_lambda.get_lambda_execution_time_timestamp()
-    cw_client = boto3.client("logs")
-
-    # WHEN
-    filtered_logs = data_fetcher.get_logs(lambda_function_name=lambda_name, start_time=timestamp, log_client=cw_client)
-
-    # THEN
-    assert any(
-        log.extra_info
-        and log.message == config["environment_variables"]["MESSAGE"]
-        and log.level == config["environment_variables"]["LOG_LEVEL"]
-        for log in filtered_logs
-    )
-
-
-def test_basic_lambda_empty_event_logged(execute_lambda: conftest.InfrastructureOutput):
+    logs = data_fetcher.get_logs(function_name=basic_handler_fn, start_time=execution_time)
 
-    # GIVEN
-    lambda_name = execute_lambda.get_lambda_function_name(cf_output_name="basichandlerarn")
-    timestamp = execute_lambda.get_lambda_execution_time_timestamp()
-    cw_client = boto3.client("logs")
-
-    # WHEN
-    filtered_logs = data_fetcher.get_logs(lambda_function_name=lambda_name, start_time=timestamp, log_client=cw_client)
-
-    # THEN
-    assert any(log.message == {} for log in filtered_logs)
-
-
-def test_no_context_lambda_contextual_data_not_logged(execute_lambda: conftest.InfrastructureOutput):
-
-    # GIVEN
-    required_missing_keys = (
-        "function_request_id",
-        "function_arn",
-        "function_memory_size",
-        "function_name",
-        "cold_start",
-    )
-
-    lambda_name = execute_lambda.get_lambda_function_name(cf_output_name="nocontexthandlerarn")
-    timestamp = execute_lambda.get_lambda_execution_time_timestamp()
-    cw_client = boto3.client("logs")
-
-    # WHEN
-    filtered_logs = data_fetcher.get_logs(lambda_function_name=lambda_name, start_time=timestamp, log_client=cw_client)
-
-    # THEN
-    assert not any(keys in logs.dict(exclude_unset=True) for logs in filtered_logs for keys in required_missing_keys)
-
-
-def test_no_context_lambda_event_not_logged(execute_lambda: conftest.InfrastructureOutput):
-
-    # GIVEN
-    lambda_name = execute_lambda.get_lambda_function_name(cf_output_name="nocontexthandlerarn")
-    timestamp = execute_lambda.get_lambda_execution_time_timestamp()
-    cw_client = boto3.client("logs")
-
-    # WHEN
-    filtered_logs = data_fetcher.get_logs(lambda_function_name=lambda_name, start_time=timestamp, log_client=cw_client)
-
-    # THEN
-    assert not any(log.message == {} for log in filtered_logs)
+    assert len(logs) == 2
+    assert len(logs.get_cold_start_log()) == 1
+    assert len(logs.get_log(key=custom_key)) == 2
+    assert logs.have_keys(*LOGGER_LAMBDA_CONTEXT_KEYS) is True