Logging in AWS Lambda Python Handlers

A Python Lambda function's logging is configured twice before most developers notice: once by the runtime, which attaches a handler to the root logger before the function's module is imported, and again by whatever the function's code does. The execution environment is then reused across invocations, so anything the handler function adds is added again on every warm start. The results are duplicated lines, plain-text output that defeats a JSON formatter, and — with queue handlers — records that are written an invocation late or not at all. This page covers configuring once, correctly. It is a task article under logging in Python runtimes and frameworks, part of the modern Python logging libraries deep dive section, and it complements tracing AWS Lambda Python functions.

Prerequisites

pip install "python-json-logger>=2.0.7,<4.0.0"

The runtime's own logging configuration is present in every Python Lambda runtime; nothing needs installing to observe it.

Implementation

Step 1 — Configure at module scope. Code outside the handler function runs once per execution environment, when the module is imported during a cold start. Code inside runs on every invocation. Logging configuration belongs outside, and it should be guarded so that re-importing — which can happen in tests — does not apply it twice.

# handler.py
import logging
import os
import sys

from pythonjsonlogger import jsonlogger

_CONFIGURED = False

def _configure_logging() -> None:
    global _CONFIGURED
    if _CONFIGURED:
        return
    root = logging.getLogger()
    for h in list(root.handlers):          # 1. remove the runtime's handler
        root.removeHandler(h)
    handler = logging.StreamHandler(sys.stdout)
    handler.setFormatter(jsonlogger.JsonFormatter(
        "%(asctime)s %(levelname)s %(name)s %(message)s"))
    handler.addFilter(_InvocationFilter())
    root.addHandler(handler)
    root.setLevel(os.environ.get("LOG_LEVEL", "INFO"))
    _CONFIGURED = True

Step 2 — Replace, rather than add to, the runtime's handler. The runtime attaches a handler with its own format to the root logger before your module loads. Adding a JSON handler alongside it produces two lines per record, one of them in the runtime's text format. Removing it first, as above, leaves exactly one path. It is worth confirming what the runtime installed, since its behaviour has varied between runtime versions and it may respect a platform-level log format setting.

Step 3 — Stamp every record with the request identifier. The context object passed to the handler carries the invocation's request identifier, which the platform's own log entries and metrics also carry. Setting it in a context variable at the start of each invocation, and copying it onto records with a filter, makes every line joinable with the platform's report for the same invocation.

import contextvars

_request_id: contextvars.ContextVar[str] = contextvars.ContextVar("request_id", default="-")
_cold_start = True

class _InvocationFilter(logging.Filter):
    def filter(self, record: logging.LogRecord) -> bool:
        record.request_id = _request_id.get()
        record.function = os.environ.get("AWS_LAMBDA_FUNCTION_NAME", "local")
        return True

_configure_logging()
log = logging.getLogger("order-webhook")


def handler(event, context):
    global _cold_start
    token = _request_id.set(context.aws_request_id)
    try:
        log.info("invocation started", extra={"cold_start": _cold_start})
        _cold_start = False
        result = process(event)
        log.info("invocation finished", extra={"outcome": "ok"})
        return result
    except Exception:
        log.exception("invocation failed", extra={"outcome": "error"})
        raise
    finally:
        _request_id.reset(token)

Expected Output: one line per record, JSON, each carrying the invocation identifier.

{"asctime": "2026-09-18 14:02:11,408", "levelname": "INFO", "name": "order-webhook", "message": "invocation started", "request_id": "5c1f8a2e-7b4d-11f0-9b1a-0242ac120002", "function": "order-webhook", "cold_start": true}
{"asctime": "2026-09-18 14:02:11,820", "levelname": "INFO", "name": "order-webhook", "message": "invocation finished", "request_id": "5c1f8a2e-7b4d-11f0-9b1a-0242ac120002", "function": "order-webhook", "outcome": "ok"}

Step 4 — Write synchronously. A QueueHandler moves writing to a background thread, which is valuable in a server and harmful here. The execution environment is frozen the moment the handler returns, so the listener thread stops wherever it was; records still in the queue are written when the next invocation thaws the environment — attributed by timestamp to the wrong moment — or never, if no further invocation arrives. A StreamHandler writing to standard output completes before the handler returns, and the volume per invocation is small enough that the synchronous cost is negligible.

Step 5 — Keep per-invocation volume small. Every line is ingested and billed, and a function invoked millions of times a day multiplies every log statement by that count. A start record, an end record carrying the outcome and the key counts, and exception records cover almost every investigation. Debug detail belongs behind a level that is off in production and can be enabled per function through an environment variable when needed.

What the platform already records

Part of logging well in a function is not duplicating what the platform provides, because every duplicate is billed ingestion with no additional information.

The platform records the start and end of every invocation, its duration, billed duration, memory configured and used, and whether it was a cold start. It records timeouts and out-of-memory terminations, which the function's own code cannot log because it is stopped before it can. It captures anything written to standard output and standard error and attaches the request identifier to its own lines.

The function's logging should therefore add what the platform cannot see: what the invocation was asked to do, what it decided, which downstream calls it made and how they went, and why it failed when it did. Logging the duration, or a line saying the handler started, largely repeats the platform's report. The start record in step 3 earns its place only because it carries application context — the cold start flag, the event's key identifiers — that the platform's record does not.

For timeouts specifically, the platform's record is the only evidence, and the function's last log line before it is the only clue to what was happening. Logging at the start of long operations — "calling payment provider" rather than only "payment provider responded" — is what makes that last line informative.

Joining logs to traces inside a function

A function that is also traced benefits from the same correlation a long-running service gets, and the mechanics are almost identical with one difference in timing.

The trace identifier is available from the active span during the invocation, and a filter that reads it and stamps it on each record — as described in adding trace IDs to log records — works unchanged. The filter should run on the calling thread, which with a synchronous handler it always does, so there is none of the context-loss risk that a queue handler introduces in a server.

The difference is that a function's span usually begins inside the handler, after the incoming trace context has been extracted from the event. Records logged before that point — at the very start of the handler, or during module-level initialisation on a cold start — have no active span and therefore no trace identifier. That is correct, and it is worth knowing so that a missing trace identifier on the first record of a cold start is not mistaken for a correlation bug. Starting the span as early as possible in the handler, before the first log call, gives every invocation record a trace identifier.

With both the request identifier and the trace identifier on each record, a single line can be joined in both directions: to the platform's invocation report through the request identifier, and to the distributed trace that spans the function and its callers through the trace identifier. That pair is what makes a function's logs as navigable as a service's, despite the function having no long-lived process to attach context to.

Configuration options

Verification

Invoke the function several times in a row against one warm environment and count lines per record.

for i in 1 2 3 4; do
  aws lambda invoke --function-name order-webhook --payload '{}' /dev/null >/dev/null
done
aws logs tail /aws/lambda/order-webhook --since 2m --format short \
  | grep -c '"invocation started"'

Expected Output: four — one start record per invocation, not a growing number.

4

A count of 14 for four invocations is the growing-duplication failure: 2, 3, 4 and 5 copies respectively, from a handler added per invocation.

Common mistakes

Configuring inside the handler function. Error signature: duplication that grows with each warm invocation. Root cause: a handler added per invocation to a persistent root logger. Remediation: configure at module scope, guarded.

Adding without removing. Error signature: every line twice, one of them plain text. Root cause: the runtime's pre-attached root handler left in place. Remediation: remove existing root handlers first.

A queue handler. Error signature: an invocation's final records appearing minutes later or missing. Root cause: the listener thread frozen with the environment. Remediation: write synchronously to standard output.

No request identifier. Error signature: log lines that cannot be matched to the platform's invocation report. Root cause: records carry no invocation context. Remediation: set it per invocation and stamp it with a filter.

Duplicating the platform's report. Error signature: log volume dominated by lines restating duration and memory. Root cause: logging what the platform already records. Remediation: log application context only.

Frequently Asked Questions