Skip to content

Prefer the original telemetry exception over its recorded-cause copy - #4089

Draft
anth-volk wants to merge 3 commits into
masterfrom
telemetry-rank-cause-copies
Draft

anth-volk wants to merge 3 commits into
masterfrom
telemetry-rank-cause-copies

Conversation

@anth-volk

@anth-volk anth-volk commented Oct 27, 2026 •

Copy link
Copy Markdown
Collaborator

Fixes #4088

Stacked on #4086 (fingerprint algorithm 2), so the base is telemetry-fingerprint-function-names.

What was wrong

When a simulation worker or coordinator fails on the simulation service's newer report path, the service logs the original exception, then failure_causes.record_failure_cause records a redacted copy that carries the original's traceback. _primary_preference ranked both as exceptions, so when they had the same timestamp, the record whose fingerprint inputs sorted first represented the failure: the copy, for a ValueError. One cause then split across two groups and two issues, as a8e6ee4984a289c0 and 88e59fcf916bc9ff did on 2026-10-26.

What tells the copy apart

Only its exception class, Stage12FailureCause.

  • Code (policyengine-simulation-executor, stage12_runtime/failure_causes.py on main): record_failure_cause wraps the redacted summary in Stage12FailureCause, attaches the original's traceback, and calls runtime.record_exception(cause, handled=True). In policyengine-observability, record_exception writes event.name exception.recorded and error.handled true for every handled exception, and error.type is type(error).__name__. The copy passes no attributes; its only attribute is the observability_id the runtime adds to every record. The original comes from failure_recording.report_original_failure, which logs a record with the error, no event name and a stage12_failure_scope attribute.
  • Logs (_AllLogs, 2026-10-20 to 2026-10-28): every Stage12FailureCause record (28 from policyengine-stage12-uk-worker, 23 from policyengine-stage12-coordinator, 4 from policyengine-stage12-us-worker) is an exception.recorded event with error.handled true and no stage12_failure_scope, and each service logged the same number of originals with stage12_failure_scope and no event name. Each of the 28 UK worker copies has the same frames as an original of the same request logged no later, and 10 have its timestamp to the microsecond; those ties are what split the groups. A coordinator's or US worker's copy is recorded seconds after its original, from another point in the call stack, so its frames differ and the original was already chosen as the earlier record. After a worker's copy, its operation logs an operation.completed record with a RuntimeError about a second later.
  • exception.recorded with error.handled true doesn't identify a copy: the simulation gateway logs its handled ValueError the same way. The copy's writer sets no event name or attribute of its own, so the class name is the only field it sets on purpose.

What changed

  • records.py: RECORDED_CAUSE_COPY_TYPES holds Stage12FailureCause, and _primary_preference ranks a record of that class after other exceptions and before messages and failed requests. A failure with only the copy still uses it. The tie-breaker and the fingerprint are unchanged.
  • gcp/observability/README.md describes the ranking, and changelog.d/telemetry-rank-cause-copies.fixed.md the fix.

Fingerprints

How a record is fingerprinted doesn't change, only which record represents these failures. Failures that were counted in a Stage12FailureCause group move to their original exception's group, so a Stage12FailureCause group's issue would stop being updated. This belongs with fingerprint algorithm 2 and needs no further algorithm change, as long as #4086 merges first and this follows before the report opens issues for Stage12FailureCause groups under algorithm 2. No issue exists for one today.

Grouping the 1,394 ERROR records that the report's query returns for 2026-10-26, with a throwaway fingerprint key: master gives policyengine-stage12-uk-worker a ValueError group of 10 production failures and a Stage12FailureCause group of 4; this branch gives one ValueError group of 14. Every other group is the same.

Testing

The first commit adds the tests and they fail; the second commit is the fix. The third commit corrects the comment, README and changelog, which had said the copy has the same stack as the original; it changes no code.

  • test_records.py: a worker failure logged as the original ValueError, its copy with the same timestamp, and the worker's later RuntimeError is represented by the original in all six input orders. Before the fix the copy was chosen in all six. A failure with only the copy, a message and a failed request is represented by the copy in all six orders; this passes before and after.
  • test_groups.py: four worker failures, two with copies at the same timestamp and two with copies 100 ms later, form one ValueError group of four. Before the fix they formed a ValueError group of two and a Stage12FailureCause group of two.
  • report_support.py gains original_worker_failure and recorded_cause_copy, which build the two records.
  • pytest tests/unit/telemetry_error_issues: 262 passed on Fingerprint telemetry exceptions by function names, not module paths #4086; 7 failed and 268 passed after the first commit; 275 passed after the second.
  • ruff format and lint, the quality guards, the rules guard against Fingerprint telemetry exceptions by function names, not module paths #4086's branch, the rules tool tests, the generated-files check and uv lock --check pass. No inline suppressions were added (94 noqa, 9 type or pyright ignores, as on master).

🤖 Generated with Claude Code

@codecov

codecov Bot commented Oct 27, 2026 •

Copy link
Copy Markdown

Codecov Report

✅ All modified and coverable lines are covered by tests.
✅ Project coverage is 87.83%. Comparing base (fe8ad13) to head (a24113d).
⚠️ Report is 2 commits behind head on master.

Additional details and impacted files
@@           Coverage Diff           @@
##           master    #4089   +/-   ##
=======================================
  Coverage   87.83%   87.83%           
=======================================
  Files         270      270           
  Lines       16058    16058           
  Branches     2626     2626           
=======================================
  Hits        14105    14105           
  Misses       1284     1284           
  Partials      669      669           

☔ View full report in Codecov by Harness.
📢 Have feedback on the report? Share it here.

🚀 New features to boost your workflow:
  • ❄️ Test Analytics: Detect flaky tests, report on failures, and find test suite problems.

Base automatically changed from telemetry-fingerprint-function-names to master October 27, 2026 21:25
anth-volk and others added 3 commits October 28, 2026 01:25
…ded copy

When a simulation worker fails, the simulation service logs the original
exception, then `record_failure_cause` records a redacted copy: a handled
`exception.recorded` event of class `Stage12FailureCause` with the same
stack, often with the same timestamp to the microsecond.
`primary_records` ranks both as exceptions, so on a tied timestamp it picks
whichever error type sorts first, and one cause splits across two error
groups. These tests describe ranking the copy after the original exception
and before messages and failed requests:

- a failure with the original, the copy and the worker's later
  RuntimeError is represented by the original, in all six input orders;
- a failure with only the copy, a message and a failed request is
  represented by the copy, in all six orders (this passes already);
- four worker failures, two with copies at the same timestamp and two
  with copies logged later, form one ValueError group of four.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
When a simulation worker fails, the simulation service logs the original
exception, then `failure_causes.record_failure_cause` records a redacted
copy through `record_exception(handled=True)`: an `exception.recorded`
event of class `Stage12FailureCause` with the original's stack, often
with the same timestamp to the microsecond. `_primary_preference` ranked
both as exceptions, so when the timestamps tied, the record whose
fingerprint inputs sorted first represented the failure, and one cause
split across two groups and two issues.

The copy sets no event name or attribute of its own: the event name and
handled flag are what the runtime writes for any handled exception, and
the only attribute is the `observability_id` it adds to every record. So
`RECORDED_CAUSE_COPY_TYPES` lists the copy's class, and
`_primary_preference` ranks such a record after other exceptions and
before messages and failed requests. A failure with only the copy still
uses it.

This changes which record represents those failures but not how a record
is fingerprinted, so it belongs with fingerprint algorithm 2 and needs no
further bump as long as the algorithm 2 change merges first.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
The comment, README and changelog said the copy has the same stack as the
original exception. The logs from 2026-10-20 to 2026-10-28 show that for
the UK worker (all 28 copies had the original's frames, 10 with the same
timestamp to the microsecond), but a coordinator's or US worker's copy is
recorded seconds later from another point in the call stack, so its frames
differ. They now say the copy carries the original's traceback, and that a
worker's copy often has the original's frames and timestamp. No code
changes.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>

This branch was previously deployed

1 inactive deployment
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

Telemetry error report splits a simulation worker failure between its exception and the recorded copy

1 participant