feat: support for extra keys in log messages

Author: heitorlessa

aws_lambda_powertools/logging/formatter.py

@@ -3,6 +3,30 @@
 import os
 from typing import Dict, Iterable, Optional, Union
 
+STD_LOGGING_KEYS = (
+    "name",
+    "msg",
+    "args",
+    "levelname",
+    "levelno",
+    "pathname",
+    "filename",
+    "module",
+    "exc_info",
+    "exc_text",
+    "stack_info",
+    "lineno",
+    "funcName",
+    "created",
+    "msecs",
+    "relativeCreated",
+    "thread",
+    "threadName",
+    "processName",
+    "process",
+    "asctime",
+)
+
 
 class JsonFormatter(logging.Formatter):
     """AWS Lambda Logging formatter.
@@ -120,15 +144,21 @@ def _extract_log_keys(self, log_record: logging.LogRecord) -> Dict:
 
         formatted_log = {}
 
-        # Iterate over new or existing log structure
-        # replace reserved logging expression e.g. '%(level)s' to 'INFO'
-        # lastly, add or replace non-reserved keys
+        # We have to iterate over a default or existing log structure
+        # then replace any logging expression for reserved keys e.g. '%(level)s' to 'INFO'
+        # and lastly add or replace incoming keys (those added within the constructor or .structure_logs method)
         for key, value in self.log_format.items():
             if value and key in self.reserved_keys:
                 formatted_log[key] = value % record_dict
             else:
                 formatted_log[key] = value
 
+        # pick up extra keys when logging a new message e.g. log.info("my message", extra={"additional_key": "value"}
+        # these messages will be added to the root of the final structure not within `message` key
+        for key, value in record_dict.items():
+            if key not in STD_LOGGING_KEYS:
+                formatted_log[key] = value
+
         return formatted_log
 
     def format(self, record):  # noqa: A003

tests/functional/test_logger.py

@@ -381,3 +381,22 @@ def test_logger_do_not_log_twice_when_root_logger_is_setup(stdout, service_name)
     # since child's log records propagated to root logger should be rejected
     logs = list(stdout.getvalue().strip().split("\n"))
     assert len(logs) == 2
+
+
+def test_logger_extra_kwargs(stdout, service_name):
+    # GIVEN Logger is initialized
+    logger = Logger(service=service_name, stream=stdout)
+
+    # WHEN `request_id` is an extra field in a log message to the existing structured log
+    fields = {"request_id": "blah"}
+
+    logger.info("with extra fields", extra=fields)
+    logger.info("without extra fields")
+
+    extra_fields_log, no_extra_fields_log = capture_multiple_logging_statements_output(stdout)
+
+    # THEN first log should have request_id field in the root structure
+    assert "request_id" in extra_fields_log
+
+    # THEN second log should not have request_id in the root structure
+    assert "request_id" not in no_extra_fields_log