fix(preprod): Stop chunk crash from reserved LogRecord key#117550
Merged
NicoHinderling merged 1 commit intoJun 12, 2026
Conversation
The unchanged_with_diff_hash branch in _process_chunk logged with
extra={"name": ...}. "name" is a reserved LogRecord attribute, so
logging raised KeyError: "Attempt to overwrite 'name' in LogRecord"
whenever that branch ran at INFO level. The bare except in
process_snapshot_comparison_chunk swallowed it, marked the chunk done
without writing its result blob, and finalize then 404'd reading the
missing blob and degraded every affected image to errored.
The comparison still finalized as SUCCESS, so the failure was invisible
to users. Rename the extra key to "image_name" to avoid the collision.
Refs SENTRY-5QH9
Refs SENTRY-5QF7
github-actions
Bot
added
the
Scope: Backend
jamieQ
approved these changes
Jun 12, 2026
| logger.info( | ||
| "preprod.snapshots.odiff.unchanged_with_diff_hash", | ||
| extra={ | ||
| "name": name, |
Member
There was a problem hiding this comment.
can this class of problem be prevented before runtime in some manner?
3 tasks
NicoHinderling
added a commit
that referenced
this pull request
Jun 12, 2026
## Summary
When a snapshot comparison chunk fails,
`process_snapshot_comparison_chunk` logs `compare_snapshots: chunk
failed` — but the log `extra` only carried `comparison_id` and
`chunk_index`. So in the logs explore view you can see *that* a chunk
failed but not *why*; the real exception type and message live two hops
away in a separately-captured issue (a different transaction/trace),
which is exactly what made a recent incident hard to diagnose.
## Change
Add `error_type` (e.g. `"KeyError"`) and `error` (the exception message)
to the log `extra`, so the cause is visible directly on the `chunk
failed` log line.
```python
except Exception as e:
logger.exception(
"compare_snapshots: chunk failed",
extra={
"comparison_id": comparison_id,
"chunk_index": chunk_index,
"error_type": type(e).__name__,
"error": str(e),
},
)
```
No behavior change — purely diagnostic enrichment.
## Test
`ProcessChunkTest::test_chunk_failure_logs_exception_details` forces a
chunk failure under `assertLogs` and asserts the emitted record carries
`error_type`/`error` (plus the existing `comparison_id`/`chunk_index`).
## Context
Follow-up to the diagnosability gap surfaced while debugging the
reserved-`LogRecord`-key chunk crash (#117550). Independent of that fix.
NicoHinderling
added a commit
that referenced
this pull request
Jun 12, 2026
…ng extra= (#117562) ## Summary Passing a reserved `LogRecord` attribute (`name`, `message`, `args`, `module`, …) as a key in a logging `extra=` dict raises `KeyError: "Attempt to overwrite 'X' in LogRecord"` **at runtime**, when the log line actually fires. Nothing static catches it — it passes ruff, mypy, and a human skim — and it recently caused a silent production incident in preprod snapshots (the log call meant to aid debugging was the thing that crashed; see #117550). This adds a custom **S019** flake8 rule (Sentry's `S###` family in `tools/flake8_plugin.py`) that flags this class before runtime, and fixes the only two existing violations it surfaces repo-wide. This follows up a review question on #117550 ("can this class of problem be prevented before runtime?"). ## Changes - **S019 rule** (`tools/flake8_plugin.py`): flags `logger.<level>(..., extra={...})` calls whose `extra` dict has a literal string key colliding with a reserved `LogRecord` attribute. Auto-registered via the existing `S=` prefix plugin (no config change). - **`test_S019`** (`tests/tools/test_flake8_plugin.py`): covers `name`/`message` hits, a non-reserved key (ok), and a dynamic `extra=var` (not flagged). - **Fixes for the two surfaced violations:** - `hybridcloud/apigateway/proxy.py`: `"message"` → `"error"` in a breaker-config warning (would have crashed when invalid config was hit). - `preprod/snapshots/tasks.py`: `"name"` → `"image_name"` (same fix as #117550; identical change, no conflict whichever merges first). ## Known limitation Only **literal** `extra={...}` dicts with constant string keys are checked. Dynamic dicts (`extra=some_var`, `extra={**spread}`, computed keys) can't be detected statically — but the literal case is the one that actually bites. ## Test Plan - [x] `test_S019` passes; full `tests/tools/test_flake8_plugin.py` suite green (18 tests) - [x] `flake8 --select=S019 src tests tools` reports clean after the two fixes (was 2 hits before) - [x] ruff + mypy clean on changed files
3 tasks
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
2 participants
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
Summary
A snapshot comparison chunk could crash on a logging statement — not on any diff logic — silently corrupting the comparison.
In
_process_chunk, theunchanged_with_diff_hashbranch (image is visually unchanged but has a different content hash) logged withextra={"name": ...}.nameis a reservedLogRecordattribute, so Python's logging internals raised:whenever that branch executed at INFO level. The bare
except Exceptioninprocess_snapshot_comparison_chunkswallowed the error, marked the chunk done with no result blob written, andfinalize_snapshot_comparisonthen hit a 404 reading the missingchunks/{idx}.jsonand degraded every affected image toerrored.Because errored images don't change comparison state, the comparison still finalized as SUCCESS — so the failure was invisible to users in the status check, PR comment, and web UI.
Fix
Rename the colliding
extrakey from"name"to"image_name". Audited the entiresrc/sentry/preprod/tree — this was the only reserved-LogRecord-key collision.Test
Added
ProcessChunkTest::test_chunk_with_unchanged_diff_hash_writes_result, which drives theunchanged_with_diff_hashbranch underassertLogs(level="INFO")(so the offending log line actually executes) and asserts the chunk result blob gets written. It fails before the fix (blob never written) and passes after.Observed in production
KeyErrorchunk crash: SENTRY-5QH9Both began together ~2026-06-09 19:00 UTC.
Follow-ups (not in this PR)
compare_snapshots: chunk failedlog so the root cause isn't two hops away.