docs(logger): snippets split, improved, and lint (#1262)

Author: heitorlessa

docs/core/logger.md

@@ -21,7 +21,7 @@ Tracer is an opinionated thin wrapper for [AWS X-Ray Python SDK](https://github.
 Before your use this utility, your AWS Lambda function [must have permissions](https://docs.aws.amazon.com/lambda/latest/dg/services-xray.html#services-xray-permissions) to send traces to AWS X-Ray.
 
 ```yaml hl_lines="9 12" title="AWS Serverless Application Model (SAM) example"
---8<-- "examples/tracer/template.yaml"
+--8<-- "examples/tracer/sam/template.yaml"
 ```
 
 ### Lambda handler

docs/core/tracer.md

@@ -9,15 +9,16 @@ Globals:
     Tracing: Active
     Environment:
       Variables:
-        POWERTOOLS_SERVICE_NAME: example
+        POWERTOOLS_SERVICE_NAME: payment
+        LOG_LEVEL: INFO
     Layers:
       # Find the latest Layer version in the official documentation
       # https://awslabs.github.io/aws-lambda-powertools-python/latest/#lambda-layer
       - !Sub arn:aws:lambda:${AWS::Region}:017000801446:layer:AWSLambdaPowertoolsPython:21
 
 Resources:
-  CaptureLambdaHandlerExample:
+  LoggerLambdaHandlerExample:
     Type: AWS::Serverless::Function
     Properties:
-      CodeUri: src
-      Handler: capture_lambda_handler.handler
+      CodeUri: ../src
+      Handler: inject_lambda_context.handler

examples/tracer/template.yaml renamed to examples/logger/sam/template.yaml

@@ -0,0 +1,15 @@
+from aws_lambda_powertools import Logger
+from aws_lambda_powertools.utilities.typing import LambdaContext
+
+logger = Logger()
+
+
+def handler(event: dict, context: LambdaContext) -> str:
+    order_id = event.get("order_id")
+
+    # this will ensure order_id key always has the latest value before logging
+    # alternative, you can use `clear_state=True` parameter in @inject_lambda_context
+    logger.append_keys(order_id=order_id)
+    logger.info("Collecting payment")
+
+    return "hello world"

examples/logger/src/append_keys.py

@@ -0,0 +1,11 @@
+from aws_lambda_powertools import Logger
+from aws_lambda_powertools.utilities.typing import LambdaContext
+
+logger = Logger()
+
+
+def handler(event: dict, context: LambdaContext) -> str:
+    fields = {"request_id": "1123"}
+    logger.info("Collecting payment", extra=fields)
+
+    return "hello world"

examples/logger/src/append_keys_extra.py

@@ -0,0 +1,8 @@
+{
+    "level": "INFO",
+    "location": "collect.handler:9",
+    "message": "Collecting payment",
+    "timestamp": "2021-05-03 11:47:12,494+0200",
+    "service": "payment",
+    "request_id": "1123"
+}

examples/logger/src/append_keys_extra_output.json

@@ -0,0 +1,8 @@
+{
+    "level": "INFO",
+    "location": "collect.handler:11",
+    "message": "Collecting payment",
+    "timestamp": "2021-05-03 11:47:12,494+0200",
+    "service": "payment",
+    "order_id": "order_id_value"
+}

examples/logger/src/append_keys_output.json

@@ -0,0 +1,28 @@
+import os
+
+import requests
+
+from aws_lambda_powertools import Logger
+
+ENDPOINT = os.getenv("PAYMENT_API", "")
+logger = Logger(service="payment")
+
+
+class PaymentError(Exception):
+    ...
+
+
+def handler(event, context):
+    logger.append_keys(payment_id="123456789")
+    charge_id = event.get("charge_id", "")
+
+    try:
+        ret = requests.post(url=f"{ENDPOINT}/collect", data={"charge_id": charge_id})
+        ret.raise_for_status()
+
+        logger.info("Charge collected successfully", extra={"charge_id": charge_id})
+        return ret.json()
+    except requests.HTTPError as e:
+        raise PaymentError(f"Unable to collect payment for charge {charge_id}") from e
+
+    logger.info("goodbye")

examples/logger/src/append_keys_vs_extra.py

@@ -0,0 +1,21 @@
+[
+    {
+        "level": "INFO",
+        "location": "<module>:22",
+        "message": "Charge collected successfully",
+        "timestamp": "2021-01-12 14:09:10,859",
+        "service": "payment",
+        "sampling_rate": 0.0,
+        "payment_id": "123456789",
+        "charge_id": "75edbad0-0857-4fc9-b547-6180e2f7959b"
+    },
+    {
+        "level": "INFO",
+        "location": "<module>:27",
+        "message": "goodbye",
+        "timestamp": "2021-01-12 14:09:10,860",
+        "service": "payment",
+        "sampling_rate": 0.0,
+        "payment_id": "123456789"
+    }
+]

examples/logger/src/append_keys_vs_extra_output.json

@@ -0,0 +1,13 @@
+from aws_lambda_powertools import Logger
+from aws_lambda_powertools.logging.formatter import LambdaPowertoolsFormatter
+
+
+class CustomFormatter(LambdaPowertoolsFormatter):
+    def serialize(self, log: dict) -> str:
+        """Serialize final structured log dict to JSON str"""
+        log["event"] = log.pop("message")  # rename message key to event
+        return self.json_serializer(log)  # use configured json serializer
+
+
+logger = Logger(service="payment", logger_formatter=CustomFormatter())
+logger.info("hello")

examples/logger/src/bring_your_own_formatter.py

@@ -0,0 +1,43 @@
+import json
+import logging
+from typing import Iterable, List, Optional
+
+from aws_lambda_powertools import Logger
+from aws_lambda_powertools.logging.formatter import BasePowertoolsFormatter
+
+
+class CustomFormatter(BasePowertoolsFormatter):
+    def __init__(self, log_record_order: Optional[List[str]], *args, **kwargs):
+        self.log_record_order = log_record_order or ["level", "location", "message", "timestamp"]
+        self.log_format = dict.fromkeys(self.log_record_order)
+        super().__init__(*args, **kwargs)
+
+    def append_keys(self, **additional_keys):
+        # also used by `inject_lambda_context` decorator
+        self.log_format.update(additional_keys)
+
+    def remove_keys(self, keys: Iterable[str]):
+        for key in keys:
+            self.log_format.pop(key, None)
+
+    def clear_state(self):
+        self.log_format = dict.fromkeys(self.log_record_order)
+
+    def format(self, record: logging.LogRecord) -> str:  # noqa: A003
+        """Format logging record as structured JSON str"""
+        return json.dumps(
+            {
+                "event": super().format(record),
+                "timestamp": self.formatTime(record),
+                "my_default_key": "test",
+                **self.log_format,
+            }
+        )
+
+
+logger = Logger(service="payment", logger_formatter=CustomFormatter())
+
+
+@logger.inject_lambda_context
+def handler(event, context):
+    logger.info("Collecting payment")

examples/logger/src/bring_your_own_formatter_from_scratch.py

@@ -0,0 +1,10 @@
+{
+    "event": "Collecting payment",
+    "timestamp": "2021-05-03 11:47:12,494",
+    "my_default_key": "test",
+    "cold_start": true,
+    "lambda_function_name": "test",
+    "lambda_function_memory_size": 128,
+    "lambda_function_arn": "arn:aws:lambda:eu-west-1:12345678910:function:test",
+    "lambda_request_id": "52fdfc07-2182-154f-163f-5f0f9a621d72"
+}

examples/logger/src/bring_your_own_formatter_from_scratch_output.json

@@ -0,0 +1,7 @@
+{
+    "level": "INFO",
+    "location": "<module>:16",
+    "timestamp": "2021-12-30 13:41:53,413+0100",
+    "service": "payment",
+    "event": "hello"
+}

examples/logger/src/bring_your_own_formatter_output.json

@@ -0,0 +1,11 @@
+import logging
+from pathlib import Path
+
+from aws_lambda_powertools import Logger
+
+log_file = Path("/tmp/log.json")
+log_file_handler = logging.FileHandler(filename=log_file)
+
+logger = Logger(service="payment", logger_handler=log_file_handler)
+
+logger.info("hello world")

examples/logger/src/bring_your_own_handler.py

@@ -0,0 +1,17 @@
+import functools
+
+import orjson
+
+from aws_lambda_powertools import Logger
+
+custom_serializer = orjson.dumps
+custom_deserializer = orjson.loads
+
+logger = Logger(service="payment", json_serializer=custom_serializer, json_deserializer=custom_deserializer)
+
+# NOTE: when using parameters, you can pass a partial
+custom_serializer_with_parameters = functools.partial(orjson.dumps, option=orjson.OPT_SERIALIZE_NUMPY)
+
+logger_two = Logger(
+    service="payment", json_serializer=custom_serializer_with_parameters, json_deserializer=custom_deserializer
+)

examples/logger/src/bring_your_own_json_serializer.py

@@ -0,0 +1,16 @@
+from aws_lambda_powertools import Logger
+from aws_lambda_powertools.utilities.typing import LambdaContext
+
+logger = Logger()
+
+
+@logger.inject_lambda_context(clear_state=True)
+def handler(event: dict, context: LambdaContext) -> str:
+    if event.get("special_key"):
+        # Should only be available in the first request log
+        # as the second request doesn't contain `special_key`
+        logger.append_keys(debugging_key="value")
+
+    logger.info("Collecting payment")
+
+    return "hello world"

examples/logger/src/clear_state.py

@@ -0,0 +1,13 @@
+{
+    "level": "INFO",
+    "location": "collect.handler:10",
+    "message": "Collecting payment",
+    "timestamp": "2021-05-03 11:47:12,494+0200",
+    "service": "payment",
+    "special_key": "debug_key",
+    "cold_start": true,
+    "lambda_function_name": "test",
+    "lambda_function_memory_size": 128,
+    "lambda_function_arn": "arn:aws:lambda:eu-west-1:12345678910:function:test",
+    "lambda_request_id": "52fdfc07-2182-154f-163f-5f0f9a621d72"
+}

examples/logger/src/clear_state_event_one.json

@@ -0,0 +1,12 @@
+{
+    "level": "INFO",
+    "location": "collect.handler:10",
+    "message": "Collecting payment",
+    "timestamp": "2021-05-03 11:47:12,494+0200",
+    "service": "payment",
+    "cold_start": false,
+    "lambda_function_name": "test",
+    "lambda_function_memory_size": 128,
+    "lambda_function_arn": "arn:aws:lambda:eu-west-1:12345678910:function:test",
+    "lambda_request_id": "52fdfc07-2182-154f-163f-5f0f9a621d72"
+}

examples/logger/src/clear_state_event_two.json

@@ -0,0 +1,11 @@
+import logging
+
+from aws_lambda_powertools import Logger
+from aws_lambda_powertools.logging import utils
+
+logger = Logger()
+
+external_logger = logging.logger()
+
+utils.copy_config_to_registered_loggers(source_logger=logger)
+external_logger.info("test message")

examples/logger/src/cloning_logger_config.py

@@ -0,0 +1,18 @@
+from typing import Dict, List
+
+import boto3
+
+from aws_lambda_powertools import Logger
+from aws_lambda_powertools.utilities.typing import LambdaContext
+
+boto3.set_stream_logger()
+boto3.set_stream_logger("botocore")
+
+logger = Logger()
+client = boto3.client("s3")
+
+
+def handler(event: Dict, context: LambdaContext) -> List:
+    response = client.list_buckets()
+
+    return response.get("Buckets", [])

examples/logger/src/enabling_boto_logging.py

@@ -0,0 +1,21 @@
+from dataclasses import dataclass
+
+import fake_lambda_context_for_logger_module  # sample module for completeness
+import pytest
+
+
+@pytest.fixture
+def lambda_context():
+    @dataclass
+    class LambdaContext:
+        function_name: str = "test"
+        memory_limit_in_mb: int = 128
+        invoked_function_arn: str = "arn:aws:lambda:eu-west-1:809313241:function:test"
+        aws_request_id: str = "52fdfc07-2182-154f-163f-5f0f9a621d72"
+
+    return LambdaContext()
+
+
+def test_lambda_handler(lambda_context):
+    test_event = {"test": "event"}
+    fake_lambda_context_for_logger_module.handler(test_event, lambda_context)

examples/logger/src/fake_lambda_context_for_logger.py

@@ -0,0 +1,11 @@
+from aws_lambda_powertools import Logger
+from aws_lambda_powertools.utilities.typing import LambdaContext
+
+logger = Logger()
+
+
+@logger.inject_lambda_context
+def handler(event: dict, context: LambdaContext) -> str:
+    logger.info("Collecting payment")
+
+    return "hello world"

examples/logger/src/fake_lambda_context_for_logger_module.py

@@ -0,0 +1,13 @@
+from aws_lambda_powertools import Logger
+from aws_lambda_powertools.utilities.typing import LambdaContext
+
+logger = Logger()
+
+
+@logger.inject_lambda_context
+def handler(event: dict, context: LambdaContext) -> str:
+    logger.info("Collecting payment")
+
+    # You can log entire objects too
+    logger.info({"operation": "collect_payment", "charge_id": event["charge_id"]})
+    return "hello world"

examples/logger/src/inject_lambda_context.py

@@ -0,0 +1,29 @@
+[
+    {
+        "level": "INFO",
+        "location": "collect.handler:9",
+        "message": "Collecting payment",
+        "timestamp": "2021-05-03 11:47:12,494+0200",
+        "service": "payment",
+        "cold_start": true,
+        "lambda_function_name": "test",
+        "lambda_function_memory_size": 128,
+        "lambda_function_arn": "arn:aws:lambda:eu-west-1:12345678910:function:test",
+        "lambda_request_id": "52fdfc07-2182-154f-163f-5f0f9a621d72"
+    },
+    {
+        "level": "INFO",
+        "location": "collect.handler:12",
+        "message": {
+            "operation": "collect_payment",
+            "charge_id": "ch_AZFlk2345C0"
+        },
+        "timestamp": "2021-05-03 11:47:12,494+0200",
+        "service": "payment",
+        "cold_start": true,
+        "lambda_function_name": "test",
+        "lambda_function_memory_size": 128,
+        "lambda_function_arn": "arn:aws:lambda:eu-west-1:12345678910:function:test",
+        "lambda_request_id": "52fdfc07-2182-154f-163f-5f0f9a621d72"
+    }
+]

examples/logger/src/inject_lambda_context_output.json

@@ -0,0 +1,9 @@
+from aws_lambda_powertools import Logger
+from aws_lambda_powertools.utilities.typing import LambdaContext
+
+logger = Logger()
+
+
+@logger.inject_lambda_context(log_event=True)
+def handler(event: dict, context: LambdaContext) -> str:
+    return "hello world"