feat(logging): structured logs with request correlation via Powertools - #204
feat(logging): structured logs with request correlation via Powertools#204oto-macenauer-absa wants to merge 4 commits into
Conversation
The service ran with 52 DEBUG and zero INFO log statements, so at the
production LOG_LEVEL=INFO it emitted nothing per request: no request line,
no outcome, and no reason for a rejection. Raising the level to DEBUG was
unusable because the level was applied to the root logger and botocore,
urllib3 and s3transfer flooded the log group.
Adopt AWS Lambda Powertools as the logging backend. Its handler is attached
to the root logger, so modules keep using logging.getLogger(__name__) and
inherit JSON formatting, the Lambda execution context and the request
correlation id without touching every call site. inject_lambda_context is
not used as a decorator because it raises AttributeError when the Lambda
context is None, which is how the tests invoke lambda_handler.
Resolve a correlation id per request from X-Correlation-ID, X-Request-ID or
the API Gateway request id, and return it in the X-Correlation-ID response
header of every response. Header values are accepted only when they match
^[A-Za-z0-9._:-]{1,128}$, since they are written into the log stream.
Add the missing log lines: every non-2xx response now has exactly one line
explaining its cause, partial fan-out failures report which writers accepted
and which failed, and requests, cold start init, writers and queries report
durations.
Fixes found on the way:
- writer_kafka called logger.exception() outside an except block, so the
traceback was taken from an empty sys.exc_info() and the Kafka error was
lost; the captured exception is now passed via exc_info.
- dispatch_request caught only six exception types, so psycopg2 and Kafka
errors escaped to the runtime as an opaque API Gateway 502; the boundary
now catches Exception while SystemExit still propagates for /terminate.
- Degraded health was logged at DEBUG, invisible at the production level.
- Malformed request bodies and a missing topic_name path parameter returned
500 internal; they are client errors and now return 400 validation.
Third-party loggers are capped at WARNING so DEBUG and TRACE stay readable.
The custom TRACE level is retained and pinned by a test, because an
unrecognised level would silently fall back to INFO and disable payload
logging without an error.
Two conf_path tests asserted POSIX path separators and failed on Windows;
they now compare Path objects.
Closes #193
|
Warning Review limit reached
Next review available in: 45 minutes Enable usage-based reviews in Billing to review now. Otherwise, wait until the next included review is available. How can I continue?After more reviews become available, a review can be triggered using the To avoid repeated limits, reduce automatic review volume by pausing incremental auto-reviews earlier, using label-based review opt-in, excluding WIP or generated PR titles, or requesting reviews manually when the PR is ready. If your team needs uninterrupted high-volume reviews, an organization admin can enable usage-based reviews. How do review limits work?CodeRabbit enforces per-developer PR review limits for each organization. Most developers receive the normal plan review availability. For paid Pro and Pro+ PR reviews, CodeRabbit uses adaptive limits for sustained high-volume activity. When a developer's recent PR review activity reaches the 95th percentile or higher among CodeRabbit users, additional reviews become available more gradually as earlier reviews age out of the rolling window. Please refer docs for additional details. Review details⚙️ Run configurationConfiguration used: Organization UI Review profile: CHILL Plan: Pro Plus Run ID: 📒 Files selected for processing (2)
WalkthroughThis change introduces AWS Lambda Powertools structured logging, request correlation, centralized response correlation headers, expanded handler and writer telemetry, revised validation behavior, and tests and documentation covering the new observability contracts. ChangesEventGate observability
Estimated code review effort: 4 (Complex) | ~45 minutes Possibly related PRs
Suggested labels: Suggested reviewers: Poem
🚥 Pre-merge checks | ✅ 4 | ❌ 1❌ Failed checks (1 warning)
✅ Passed checks (4 passed)
✨ Finishing Touches🧪 Generate unit tests (beta)
Thanks for using CodeRabbit! It's free for OSS, and your support helps us grow. If you like it, consider giving us a shout-out. Comment |
Two conflicts, both resolved in favour of master's semantics with the new structured logging applied on top: - handler_topic: master made topic authorization case insensitive (_resolve_authorized_user, #195). Kept it, and kept its error messages, while adding the rejection log lines. The user log key is re-bound to the configured spelling once resolved, since the token casing may differ. - writer_postgres: master turned an unsupported topic into a silent skip rather than a WriteError, so that Kafka-only topics do not fail the whole POST. Kept the skip and dropped the ERROR introduced on this branch, which would have broken those topics. Also drop the module level `global` for the cold start flag in favour of a mutable container, so the name no longer trips pylint's constant naming rule.
![coderabbitai[bot]](https://avatars.githubusercontent.com/in/347564?s=60&v=4){kind=small}
There was a problem hiding this comment.
Actionable comments posted: 6
Caution
Some comments are outside the diff and can’t be posted inline due to platform limitations.
⚠️ Outside diff range comments (1)
src/writers/writer_eventbridge.py (1)
72-118: 📐 Maintainability & Code Quality | 🟡 Minor | ⚡ Quick winRemove duplicate request-bound
topicfields.
topicis already bound by the request observability layer; repeating it inextracreates conflicting, redundant log context.
src/writers/writer_eventbridge.py#L72-L118: removetopicfrom eachextrapayload.src/writers/writer_kafka.py#L126-L190: removetopicfrom eachextrapayload.src/writers/writer_postgres.py#L173-L174: removetopicfrom the configuration-failure log.src/writers/writer_postgres.py#L193-L205: removetopicfrom unsupported-topic and insertion-failure logs.src/writers/writer_postgres.py#L207-L224: removetopicfrom insertion start/success logs.As per coding guidelines, “Do not re-log
topic… because they are bound insrc/utils/observability.py.”🤖 Prompt for AI Agents
Verify each finding against current code. Fix only still-valid issues, skip the rest with a brief reason, keep changes minimal, and validate. In `@src/writers/writer_eventbridge.py` around lines 72 - 118, Remove the redundant topic field from every log extra payload in src/writers/writer_eventbridge.py lines 72-118, src/writers/writer_kafka.py lines 126-190, and src/writers/writer_postgres.py lines 173-174, 193-205, and 207-224. Preserve all other logging context and rely on the request observability layer to bind topic.Source: Coding guidelines
🧹 Nitpick comments (2)
src/handlers/handler_topic.py (1)
114-134: 📐 Maintainability & Code Quality | 🔵 Trivial | ⚡ Quick winCentralize duplicated request-parsing/validation logic.
handler_topic.pyandhandler_stats.pyboth independently implement the sametopic_namepath-param extraction (missing → 400), lowercasing +append_request_keys(topic=...), and JSON body parse/type validation (invalid JSON / non-dict → 400), with a subtle divergence in how an empty body is defaulted ("{}" vs ""). As per coding guidelines: "Avoid duplicate validation and centralize parsing in one layer where practical."
src/handlers/handler_topic.py#L114-L134: extract thetopic_nameresolution and JSON body parsing/typing checks into a shared helper (e.g. insrc/utils/utils.py) reused by both handlers.src/handlers/handler_stats.py#L58-L90: adopt the same shared helper instead of re-implementing the identical checks, and align the empty-body default behavior withhandler_topic.py(or make the difference explicit/intentional).🤖 Prompt for AI Agents
Verify each finding against current code. Fix only still-valid issues, skip the rest with a brief reason, keep changes minimal, and validate. In `@src/handlers/handler_topic.py` around lines 114 - 134, The request parsing and validation logic is duplicated across both handlers. In src/handlers/handler_topic.py:114-134, extract topic_name resolution, lowercasing, append_request_keys, and JSON object validation into a shared helper, then use it from the handler; in src/handlers/handler_stats.py:58-90, replace the duplicated checks with that helper and align its empty-body behavior with handler_topic.py, or make any intentional difference explicit.Source: Coding guidelines
src/handlers/handler_stats.py (1)
58-64: 📐 Maintainability & Code Quality | 🔵 Trivial | ⚡ Quick winDuplicate request-parsing/validation logic vs.
handler_topic.py.This
topic_nameextraction/validation block and JSON body parsing block closely duplicate the equivalent logic insrc/handlers/handler_topic.py(handle_request, lines 114-134), with a subtle divergence: here an empty body defaults to"{}"whilehandler_topic.pydefaults to""(which fails JSON parsing). As per coding guidelines: "Avoid duplicate validation and centralize parsing in one layer where practical."Also applies to: 82-90
🤖 Prompt for AI Agents
Verify each finding against current code. Fix only still-valid issues, skip the rest with a brief reason, keep changes minimal, and validate. In `@src/handlers/handler_stats.py` around lines 58 - 64, Remove the duplicated topic_name extraction/validation and JSON body parsing from the affected handler, and reuse the centralized parsing/validation flow provided by handler_topic.py’s handle_request. Ensure empty-body handling follows that shared implementation rather than defaulting to "{}"; preserve the existing normalized topic_name and request-key behavior after the shared parsing succeeds.Source: Coding guidelines
🤖 Prompt for all review comments with AI agents
Verify each finding against current code. Fix only still-valid issues, skip the
rest with a brief reason, keep changes minimal, and validate.
Inline comments:
In `@DEVELOPER.md`:
- Around line 223-227: The structured logging example in DEVELOPER.md
incorrectly passes the request-bound topic through extra. Update the warning
example to remove topic from extra while preserving the constant message and the
documented bind_request_context()/append_request_keys() guidance.
In `@README.md`:
- Around line 164-174: Specify a language for both fenced query blocks in the
README, using text since no dedicated Logs Insights lexer is configured. Leave
the query contents unchanged.
In `@src/handlers/handler_topic.py`:
- Around line 142-143: Remove the extra http_method field from the
logger.warning call in the unsupported-method handling path, while preserving
the warning message and error response behavior.
In `@src/utils/utils.py`:
- Around line 65-67: Update the response-header handling in the relevant utility
function to always overwrite CORRELATION_ID_RESPONSE_HEADER with the request’s
resolved correlation_id instead of preserving a route-supplied value. Add a
regression test covering a handler response that already includes this header
and assert that the returned value matches correlation_id.
In `@src/writers/writer_kafka.py`:
- Around line 148-161: The flush loop should stop retrying whenever flush
reports completion, even if delivery callbacks populated errors. Update the
completion condition in the flush retry logic to break when remaining is None or
0, and leave error propagation to the existing WriteError handling rather than
gating completion on not errors.
In `@tests/unit/utils/test_conf_path.py`:
- Line 82: Update the assertions in the configuration path tests to use the
expected-first pattern, placing expected_current_conf on the left and the
resolved conf_dir path on the right in both affected assertions.
---
Outside diff comments:
In `@src/writers/writer_eventbridge.py`:
- Around line 72-118: Remove the redundant topic field from every log extra
payload in src/writers/writer_eventbridge.py lines 72-118,
src/writers/writer_kafka.py lines 126-190, and src/writers/writer_postgres.py
lines 173-174, 193-205, and 207-224. Preserve all other logging context and rely
on the request observability layer to bind topic.
---
Nitpick comments:
In `@src/handlers/handler_stats.py`:
- Around line 58-64: Remove the duplicated topic_name extraction/validation and
JSON body parsing from the affected handler, and reuse the centralized
parsing/validation flow provided by handler_topic.py’s handle_request. Ensure
empty-body handling follows that shared implementation rather than defaulting to
"{}"; preserve the existing normalized topic_name and request-key behavior after
the shared parsing succeeds.
In `@src/handlers/handler_topic.py`:
- Around line 114-134: The request parsing and validation logic is duplicated
across both handlers. In src/handlers/handler_topic.py:114-134, extract
topic_name resolution, lowercasing, append_request_keys, and JSON object
validation into a shared helper, then use it from the handler; in
src/handlers/handler_stats.py:58-90, replace the duplicated checks with that
helper and align its empty-body behavior with handler_topic.py, or make any
intentional difference explicit.
🪄 Autofix (Beta)
Fix all unresolved CodeRabbit comments on this PR:
- Push a commit to this branch (recommended)
- Create a new PR with the fixes
ℹ️ Review info
⚙️ Run configuration
Configuration used: Organization UI
Review profile: CHILL
Plan: Pro Plus
Run ID: 4eaa7b08-09a1-41d3-8429-b14ee05caead
📒 Files selected for processing (30)
.github/copilot-instructions.mdDEVELOPER.mdREADME.mdadr/001-observability/001-observability.mdrequirements.txtsrc/event_gate_lambda.pysrc/event_stats_lambda.pysrc/handlers/handler_api.pysrc/handlers/handler_health.pysrc/handlers/handler_stats.pysrc/handlers/handler_token.pysrc/handlers/handler_topic.pysrc/readers/reader_postgres.pysrc/utils/conf_path.pysrc/utils/config_loader.pysrc/utils/logging_levels.pysrc/utils/observability.pysrc/utils/postgres_base.pysrc/utils/utils.pysrc/writers/writer_eventbridge.pysrc/writers/writer_kafka.pysrc/writers/writer_postgres.pytests/integration/test_health_endpoint.pytests/unit/handlers/test_handler_topic.pytests/unit/test_event_gate_lambda.pytests/unit/utils/test_conf_path.pytests/unit/utils/test_logging_levels.pytests/unit/utils/test_observability.pytests/unit/utils/test_utils.pytests/unit/writers/test_writer_kafka.py
- utils: always overwrite X-Correlation-ID on the response so callers receive the id bound to their request, never a handler-supplied one - writer_kafka: stop the flush retry loop once flush reports completion; delivery-callback errors cannot be fixed by retrying and only delayed the WriteError by the full backoff - handler_topic: drop http_method from extra, it is already bound per request by bind_request_context() - docs: fix the logging example that re-logged the request-bound topic; tag the Logs Insights fences as text (MD040) - tests: expected == actual assertion order in test_conf_path; add a regression test for the correlation header overwrite Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01CwqcWSicURugFDSL3eBJeP
There was a problem hiding this comment.
Actionable comments posted: 1
Caution
Some comments are outside the diff and can’t be posted inline due to platform limitations.
⚠️ Outside diff range comments (1)
DEVELOPER.md (1)
243-247: 🎯 Functional Correctness | 🟡 Minor | ⚡ Quick winUse the Powertools logger for
registered_formatterin DEVELOPER.md.
logger = logging.getLogger(__name__)creates a stdlibLogger, whoseregistered_formatteronly exists on the PowertoolsLogger; copying this example can raiseAttributeError. Refer readers tosrc.utils.observability.logger.registered_formatteror remove this reference to formatter access and focus test docs oncaplogassertions.🤖 Prompt for AI Agents
Verify each finding against current code. Fix only still-valid issues, skip the rest with a brief reason, keep changes minimal, and validate. In `@DEVELOPER.md` around lines 243 - 247, Update the DEVELOPER.md example to use the Powertools logger from src.utils.observability.logger when accessing registered_formatter, or remove direct formatter access and document assertions through caplog instead. Do not use logging.getLogger(__name__) for this formatter-based example, since registered_formatter is only available on the Powertools Logger.
🤖 Prompt for all review comments with AI agents
Verify each finding against current code. Fix only still-valid issues, skip the
rest with a brief reason, keep changes minimal, and validate.
Inline comments:
In `@src/writers/writer_postgres.py`:
- Around line 191-197: Move the POSTGRES_WRITE_TOPICS membership check to the
beginning of write(), before connection-field and psycopg2 validation. Return
immediately with the existing debug logging for unsupported topics, while
preserving validation and write behavior for supported topics.
---
Outside diff comments:
In `@DEVELOPER.md`:
- Around line 243-247: Update the DEVELOPER.md example to use the Powertools
logger from src.utils.observability.logger when accessing registered_formatter,
or remove direct formatter access and document assertions through caplog
instead. Do not use logging.getLogger(__name__) for this formatter-based
example, since registered_formatter is only available on the Powertools Logger.
🪄 Autofix (Beta)
Fix all unresolved CodeRabbit comments on this PR:
- Push a commit to this branch (recommended)
- Create a new PR with the fixes
ℹ️ Review info
⚙️ Run configuration
Configuration used: Organization UI
Review profile: CHILL
Plan: Pro Plus
Run ID: 0dc0adc3-b514-4bc8-a209-0e5ff201a7cd
📒 Files selected for processing (15)
DEVELOPER.mdREADME.mdrequirements.txtsrc/event_gate_lambda.pysrc/handlers/handler_api.pysrc/handlers/handler_topic.pysrc/utils/observability.pysrc/utils/utils.pysrc/writers/writer_kafka.pysrc/writers/writer_postgres.pytests/unit/handlers/test_handler_topic.pytests/unit/test_event_gate_lambda.pytests/unit/utils/test_conf_path.pytests/unit/utils/test_observability.pytests/unit/utils/test_utils.py
🚧 Files skipped from review as they are similar to previous changes (11)
- src/handlers/handler_api.py
- tests/unit/test_event_gate_lambda.py
- tests/unit/utils/test_utils.py
- tests/unit/utils/test_observability.py
- src/writers/writer_kafka.py
- tests/unit/handlers/test_handler_topic.py
- src/event_gate_lambda.py
- README.md
- src/utils/utils.py
- src/utils/observability.py
- src/handlers/handler_topic.py
The POSTGRES_WRITE_TOPICS membership check ran after the secret load, the connection-field check and the psycopg2 check. Since HandlerTopic._write_to_all() calls every configured writer and turns any WriteError into a 500 for the whole request, a partially configured or unreachable Postgres made requests fail for topics the Postgres writer never persists. The check now runs first, so those topics return early regardless of the writer's configuration state. TRACE payload logging now also skips ignored topics, which is the intended behaviour - the payload is never written by this writer. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01CwqcWSicURugFDSL3eBJeP
1 participant
Overview
EventGate ran with 52
DEBUGand zeroINFOlog statements. Production runs atLOG_LEVEL=INFO, so the service emitted effectively nothing per request — no request line, no outcome, no reason for a rejection.DEBUGwas the only alternative and was unusable, because the level was set on the root logger andbotocore/urllib3/s3transferflooded the log group.Concretely, before this PR: a client receiving
401,403or400produced no log line at all; a partial fan-out failure (Kafka accepted, Postgres failed) returned500without recording which sink had already taken the message; nothing tied one invocation's lines together or tied them to the caller's job.This PR adopts AWS Lambda Powertools for JSON logging, adds a request correlation id, and fills the logging gaps. Rationale and rejected alternatives are recorded in
adr/001-observability/001-observability.md.Approach
The Powertools handler is attached to the root logger, so modules keep using
logging.getLogger(__name__)and inherit JSON formatting, the Lambda execution context and the correlation id without touching every call site.copy_config_to_registered_loggers()was rejected because it setspropagate = Falseand breakscaplog.inject_lambda_contextis not used as a decorator because it raisesAttributeErrorwhen the Lambda context isNone— which is how both unit and integration tests invokelambda_handler.Correlation id resolves from
X-Correlation-ID→X-Request-ID→ API Gateway request id, and is returned in theX-Correlation-IDresponse header of every response. Header values are accepted only when they match^[A-Za-z0-9._:-]{1,128}$, since they land in the log stream (newlines would be a log-injection vector).X-Ray tracing is deliberately not included — no
aws-xray-sdkdependency is added. The ADR documents the plug-in point if it is enabled later.Bugs fixed on the way
writer_kafkacalledlogger.exception()outside anexceptblock, so the traceback came from an emptysys.exc_info()(NoneType: None) and the real Kafka error was lost.dispatch_requestcaught only six exception types;psycopg2.ErrorandKafkaExceptionescaped to the runtime as an opaque API Gateway502. It now catchesException;SystemExitstill propagates so/terminateis unaffected.DEBUG— invisible at the production level.conf_pathtests asserted POSIX path separators and failed on Windows.Behaviour changes to review
POSTbody →400 validation(was500 internal).topic_namepath parameter →400 validation(was500 internal).X-Correlation-IDheader. Additive; response bodies unchanged.Verification
Three integration tests prove the correlation contract end-to-end: the caller's id is echoed back, a malformed id is rejected rather than written back, and error responses carry the id.
Release Notes
X-Correlation-ID(orX-Request-ID) to correlate their logs with EventGate; the id is returned on every response, including errors.topic_namepath parameter now return 400 instead of 500.POWERTOOLS_LOG_LEVEL,POWERTOOLS_SERVICE_NAME;LOG_LEVELalso acceptsTRACE.Related
Closes #193
Summary by CodeRabbit
X-Correlation-IDresponse header.