Log ownership: a raising frame must not log the traceback

Open
#219 0 comments 0 reactions 0 assignees View on GitHub

Nobody has claimed this yet.

Assessment

Difficulty
3/5
Estimated time
1-2 days
Newbie friendliness
71/100
Issue type
Refactor
Clarity
Clearly specified
Activity status
Active
Tech stack
kafka, postgresql, python
Domain
observability

Research direction

Read adr/002-observability/002-observability.md first, then inspect the exception/logging paths in src/writers/writer_kafka.py, src/writers/writer_postgres.py, src/writers/writer_eventbridge.py, src/handlers/handler_topic.py, and src/handlers/handler_token.py. Trace each logged exception to its caller (_write_to_all(), dispatch_request(), _refresh_keys_if_needed()) to confirm where traceback ownership should live. Add or update unit tests for these flows to assert log level counts, with acceptance defined as one aggregate ERROR plus per-writer WARNING on failed writes, exactly one ERROR for missing access config, and no ERROR on token refresh when the request succeeds.

Written by the indexing model from the issue text.

Description

refactoring type:tech-debt
Description of Technical Debt

ADR-002 states the invariant an ERROR alarm depends on: among records emitted during a single invocation, the count of ERROR records equals the count of 5xx responses the service built to report a failed request.

Three sites break it today, each the same way — a frame logs at ERROR and then lets the exception escape to a frame that logs it again:

Site Today Effect
src/writers/writer_kafka.py, writer_postgres.py, writer_eventbridge.py ERROR before raise WriteError Writer ERROR + _write_to_all() WARNING + aggregate ERROR = two ERROR records for one failed write, and on exception paths the same traceback twice
src/handlers/handler_topic.py, missing access config ERROR before raise RuntimeError Handler ERROR + boundary logger.exception = two ERROR for one 500
src/handlers/handler_token.py, with_public_keys_queried() logger.exception before raise RuntimeError _refresh_keys_if_needed() catches it at WARNING and the request still succeeds: one ERROR, zero 5xx
Impact of Technical Debt
  • An alarm on level = "ERROR" counts log lines, not failed requests. One failed Postgres write reads as two failures, so any future alerting or EMF metric built on the ERROR count is inflated from day one.
  • The handler_token case is the inverse and worse: a token refresh that fails but recovers emits an ERROR on a request that returns 2xx, so the ERROR count also has false entries unrelated to any failure.
  • The same traceback is written two or three times per failed write, inflating CloudWatch cost on exactly the requests that are already the most expensive to log.
  • ADR-002 documents the invariant as the contract. Until these are fixed, the code and the ADR disagree, which is a trap for the next person wiring up monitoring.
Category

Code Quality / Refactoring

Priority

Medium - Should be addressed soon

Proposed Solution

The fix is ownership, not level. Downgrading the writers to WARNING is not enough: _write_to_all() already emits a WARNING carrying the same traceback, so the duplicate simply moves one level down.

Apply the rule ADR-002 §Attaching tracebacks states:

A traceback is logged exactly once, by the frame that converts the exception into a response or swallows it. A frame that wraps and re-raises does not log it above DEBUG.

Concretely:

  1. Writers — drop the ERROR before raise WriteError. Use raise WriteError(...) from exc so exc_info=True on the caller's WARNING formats the full __cause__ chain; nothing is lost. A DEBUG breadcrumb is acceptable where the writer knows something the caller does not.
  2. handler_topic, missing access config — drop the logger.error; the boundary logger.exception in dispatch_request() already owns that record.
  3. handler_token.with_public_keys_queried() — drop the logger.exception entirely. The function cannot know whether its caller treats the failure as fatal (initialization) or recoverable (refresh), so the decision belongs to the callers: the init path logs ERROR, _refresh_keys_if_needed() keeps its existing WARNING.
Effort Estimate

1 day, including test updates

Dependencies / Related
  • ADR-002 §Logging strategy and §Attaching tracebacks (adr/002-observability/002-observability.md)
  • #193
  • PR #204
  • #220 — the other invariant gap found in the same review
Additional Context

Acceptance:

  • A failed write emits exactly one ERROR (the aggregate) and one WARNING per failing writer.
  • A 500 from missing access configuration emits exactly one ERROR.
  • A failed token refresh that still returns 2xx emits no ERROR.
  • Unit tests assert the record counts per level, not just the messages, so a regression fails the build rather than quietly re-inflating the count.
Dominant language
Python
Stars
4
Forks
0
Avg merge
20h 22m
Merged PRs (30d)
8

Contributor guide

No contributing guide indexed for this repository

First steps

  1. Read the whole issue, then the project's contributing guide.
  2. Comment on the issue to say you are picking it up — it saves two people doing the same work.
  3. Fork the repository and make your change on a branch.
  4. Open a pull request that references the issue number.

More from AbsaOSS/EventGate

All issues in AbsaOSS/EventGate

Similar issues

More Python issues

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.