feat(logger): new stack_trace field with rich exception details

aws_lambda_powertools/logging/formatter.py

@@ -5,10 +5,14 @@
 import logging
 import os
 import time
+import traceback
 from abc import ABCMeta, abstractmethod
 from datetime import datetime, timezone
 from functools import partial
 from typing import Any, Callable, Dict, Iterable, List, Optional, Tuple, Union
+from ..shared.functions import (
+    resolve_truthy_env_var_choice
+)
 
 from aws_lambda_powertools.logging.types import LogRecord
 from aws_lambda_powertools.shared import constants
@@ -77,6 +81,7 @@ def __init__(
         log_record_order: List[str] | None = None,
         utc: bool = False,
         use_rfc3339: bool = False,
+        include_stacktrace: bool = None,
         **kwargs,
     ) -> None:
         """Return a LambdaPowertoolsFormatter instance.
@@ -148,16 +153,34 @@ def __init__(
         self.keys_combined = {**self._build_default_keys(), **kwargs}
         self.log_format.update(**self.keys_combined)
 
+        self.include_stacktrace = resolve_truthy_env_var_choice(env=os.getenv(constants.POWERTOOLS_STACKTRACE_ENV, "false"),
+                                                               choice=include_stacktrace,
+                                                               )
+
         super().__init__(datefmt=self.datefmt)
 
     def serialize(self, log: LogRecord) -> str:
         """Serialize structured log dict to JSON str"""
         return self.json_serializer(log)
+
+    def serialize_traceback(self, e: Exception) -> list:
+        return [{"file": fs.filename, 
+                    "line": fs.lineno,
+                    "column": fs.colno,
+                    "function": fs.name,
+                    "statement": fs.line
+                    } for fs in traceback.extract_tb(e.__traceback__)]
+
 
     def format(self, record: logging.LogRecord) -> str:  # noqa: A003
         """Format logging record as structured JSON str"""
         formatted_log = self._extract_log_keys(log_record=record)
         formatted_log["message"] = self._extract_log_message(log_record=record)
+
+        if self.include_stacktrace:
+            # Generate the traceback from the traceback library
+            formatted_log["stack_trace"] = self.serialize_traceback(record.msg) #JSR
+
         # exception and exception_name fields can be added as extra key
         # in any log level, we try to extract and use them first
         extracted_exception, extracted_exception_name = self._extract_log_exception(log_record=record)

aws_lambda_powertools/shared/constants.py

@@ -42,3 +42,5 @@
 
 POWERTOOLS_DEV_ENV: str = "POWERTOOLS_DEV"
 POWERTOOLS_DEBUG_ENV: str = "POWERTOOLS_DEBUG"
+
+POWERTOOLS_STACKTRACE_ENV: str = "POWERTOOLS_LOGGER_ENHANCED_STACKTRACE"

docs/core/logger.md

@@ -319,6 +319,22 @@ Logger can optionally log uncaught exceptions by setting `log_uncaught_exception
     --8<-- "examples/logger/src/logging_uncaught_exceptions_output.json"
     ```
 
+#### Stack trace logging
+
+Logger can optionally log the full stack trace as JSON by setting `logger_formatter=LambdaPowertoolsFormatter(include_stacktrace=True)` at initialization. Optionally, setting the `POWERTOOLS_LOGGER_ENHANCED_STACKTRACE` environment variable to `true` will include stacktrace information in the logs.
+
+=== "logging_stacktrace.py"
+
+    ```python hl_lines="8"
+    --8<-- "examples/logger/src/logging_stacktrace.py"
+    ```
+
+=== "logging_stacktrace_output.json"
+
+    ```json hl_lines="7-22"
+    --8<-- "examples/logger/src/logging_stacktrace_output.json"
+    ```
+
 ### Date formatting
 
 Logger uses Python's standard logging date format with the addition of timezone: `2021-05-03 11:47:12,494+0200`.
@@ -352,6 +368,7 @@ The following environment variables are available to configure Logger at a globa
 | **Event Logging**         | Whether to log the incoming event.                                           | `POWERTOOLS_LOGGER_LOG_EVENT`           | `false` |
 | **Debug Sample Rate**     | Sets the debug log sampling.                                                 | `POWERTOOLS_LOGGER_SAMPLE_RATE`         | `0`     |
 | **Disable Deduplication** | Disables log deduplication filter protection to use Pytest Live Log feature. | `POWERTOOLS_LOG_DEDUPLICATION_DISABLED` | `false` |
+| **Include Stack Trace**   | Includes JSON formatted stack trace in the log output.                       | `POWERTOOLS_LOGGER_ENHANCED_STACKTRACE` | `false` |
 
 [`POWERTOOLS_LOGGER_LOG_EVENT`](#logging-incoming-event) can also be set on a per-method basis, and [`POWERTOOLS_LOGGER_SAMPLE_RATE`](#sampling-debug-logs) on a per-instance basis. These parameter values will override the environment variable value.
 

docs/index.md

@@ -723,6 +723,7 @@ Core utilities such as Tracing, Logging, Metrics, and Event Handler will be avai
 | **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_LOGGER_ENHANCED_STACKTRACE** | Include JSON formatted stack trace in log message                                      | [Logging](./core/logger.md){target="_blank"}                                             | `false`               |
 
 ### Optimizing for non-production environments
 

examples/logger/src/logging_stacktrace.py

@@ -0,0 +1,19 @@
+import requests
+
+from aws_lambda_powertools import Logger
+from aws_lambda_powertools.utilities.typing import LambdaContext
+from aws_lambda_powertools.logging.formatter import LambdaPowertoolsFormatter
+
+ENDPOINT = "http://httpbin.org/status/500"
+logger = Logger(logger_formatter=LambdaPowertoolsFormatter(include_stacktrace=True))
+
+
+def lambda_handler(event: dict, context: LambdaContext) -> str:
+    try:
+        ret = requests.get(ENDPOINT)
+        ret.raise_for_status()
+    except requests.HTTPError as e:
+        logger.exception(e)
+        raise RuntimeError("Unable to fullfil request") from e
+
+    return "hello world"

examples/logger/src/logging_stacktrace_output.json

@@ -0,0 +1,26 @@
+{
+    "level": "ERROR",
+    "location": "lambda_handler:16",
+    "message": "500 Server Error: INTERNAL SERVER ERROR for url: http://httpbin.org/status/500",
+    "timestamp": "2023-09-28 19:25:09,781+0000",
+    "service": "service_undefined",
+    "stack_trace": [
+        {
+            "File": "/var/task/app.py",
+            "Line": 14,
+            "Column": 8,
+            "Function": "lambda_handler",
+            "Statement": "ret.raise_for_status()"
+        },
+        {
+            "File": "/var/task/requests/models.py",
+            "Line": 1021,
+            "Column": 12,
+            "Function": "raise_for_status",
+            "Statement": "raise HTTPError(http_error_msg, response=self)"
+        }
+    ],
+    "exception": "Traceback (most recent call last):\n  File \"/var/task/app.py\", line 14, in lambda_handler\n    ret.raise_for_status()\n  File \"/var/task/requests/models.py\", line 1021, in raise_for_status\n    raise HTTPError(http_error_msg, response=self)\nrequests.exceptions.HTTPError: 500 Server Error: INTERNAL SERVER ERROR for url: http://httpbin.org/status/500",
+    "exception_name": "HTTPError",
+    "xray_trace_id": "1-6515d315-07fbcb5e693988c6480a98e2"
+}

tests/functional/test_logger.py

@@ -959,3 +959,62 @@ def test_stream_defaults_to_stdout(service_name, capsys):
     # NOTE: we can't assert on capsys.readouterr().err due to a known bug: https://github.com/pytest-dev/pytest/issues/5997
     log = json.loads(capsys.readouterr().out.strip())
     assert log["message"] == msg
+
+def test_logger_logs_no_stack_trace_without_parameter(stdout):
+    logger = Logger(stream=stdout)
+
+    try:
+        val = 1 + "someString"
+    except Exception as e:
+        logger.exception(e)
+
+    log = capture_logging_output(stdout)
+    assert "stack_trace" not in log
+
+def test_logger_logs_stack_trace_with_parameter(stdout):
+    logger = Logger(stream=stdout, logger_formatter=LambdaPowertoolsFormatter(include_stacktrace=True))
+
+    try:
+        val = 1 + "someString"
+    except Exception as e:
+        logger.exception(e)
+
+    log = capture_logging_output(stdout)
+    assert "stack_trace" in log
+
+def test_logger_logs_stack_trace_with_env_var(stdout, monkeypatch: pytest.MonkeyPatch):
+    monkeypatch.setenv(constants.POWERTOOLS_STACKTRACE_ENV, "true")
+    logger = Logger(stream=stdout)
+
+    try:
+        val = 1 + "someString"
+    except Exception as e:
+        logger.exception(e)
+
+    log = capture_logging_output(stdout)
+    assert "stack_trace" in log
+
+
+def test_logger_logs_no_stack_trace_with_env_var(stdout, monkeypatch: pytest.MonkeyPatch):
+    monkeypatch.setenv(constants.POWERTOOLS_STACKTRACE_ENV, "false")
+    logger = Logger(stream=stdout)
+
+    try:
+        val = 1 + "someString"
+    except Exception as e:
+        logger.exception(e)
+
+    log = capture_logging_output(stdout)
+    assert "stack_trace" not in log
+
+def test_logger_logs_no_stack_trace_with_parameter_override(stdout, monkeypatch: pytest.MonkeyPatch):
+    monkeypatch.setenv(constants.POWERTOOLS_STACKTRACE_ENV, "true")
+    logger = Logger(stream=stdout, logger_formatter=LambdaPowertoolsFormatter(include_stacktrace=False))
+
+    try:
+        val = 1 + "someString"
+    except Exception as e:
+        logger.exception(e)
+
+    log = capture_logging_output(stdout)
+    assert "stack_trace" not in log