Record every background task execution in task_runs - #285
Merged
Conversation
Seventeen periodic tasks run here. Five record anything, and those five write singleton sync-state rows holding only the latest tick, so the questions an operator asks after an incident have had no answer: how many times has this failed, how long has it been failing, what did it delete last night, why did it skip. The columns come from those questions rather than from what Celery exposes, and the names are inherited rather than invented: celery_task_id matches the column Scan already carries for the same value, skipped_reason matches the sync-state tables, and result follows the detail_code / detail_params pairing admin_health_service uses in six places. Writing happens in the signal handlers O1 added, so no task needs changing. A task that wants to say more returns skipped_reason or detail_code and the recorder picks those up; everything else in the return value is dropped, because some tasks return snapshots measured in megabytes. Three boundaries keep this from duplicating what exists. Scans stay in scans, which already has status, timings and the Celery id. The sync-state tables stay as the "right now" answer and this table is the "over time" answer. Scheduled-but-not-started work is not written: task_prerun fires when a task begins, so an open row means it started and did not report an end, and pre-writing beat's schedule would make "beat never fired" and "the task died" look identical. Retries write a row each rather than incrementing a counter. A counter would say "2 attempts, ended fine" and lose that the first one timed out. The vocabulary grows by nesting rather than duplication: the wider set is built from SYNC_SKIPPED_REASON_VALUES plus the task-only reasons, so the sync-state contract stays closed over what such a row can hold and no value is written twice. is_valid_skipped_reason gained a sync_only flag so a check against a sync-state table cannot accept trivy_timeout. Retention rides the existing operational sweep at 90 days, matching the audit log's window.
The integration test rewrote the async URL to postgresql+psycopg, which resolves to a package that is not installed: the requirements pin psycopg2-binary. Every test in the file errored on import of the dialect. test_audit_export.py gets this right and I copied the shape of its helper without the exact string. The docstring now says which driver and why, so the next copy carries the reason with it.
A new table gives trustedoss_app nothing, and this one needs all four: INSERT to open a row, UPDATE to close it, SELECT for the admin list, DELETE for the retention sweep. Without the grant every write was refused. The failure mode is worth recording. The recorder swallows its own errors on purpose, so that recording history can never fail the work being recorded. That is still the right call, but it means a missing grant produces no symptom at all beyond a warning line: tasks run, nothing is written, and the table stays empty while looking healthy. The integration test caught it because it asserts on rows rather than on the absence of an exception, which is the only way this class of fault is visible. The grant matrix test caught the same thing from the other side, and its message is what named the fix.
sync_session_scope does not commit on exit. Its docstring says so and gives the reason: the scan pipeline mixes intermediate and terminal commits, so the helper leaves the decision to the caller. I did not read it, and the recorder wrote nothing. The failure produced no error, no log line and no row. Rolling back at the end of the block is not an exception, so the swallow-everything design had nothing to swallow, and the table simply stayed empty while every task reported success. Two CI runs went into looking at the wrong cause: the grants that went in with the previous commit were genuinely missing and are still needed for UPDATE and DELETE, but they were not why nothing was written. The unit test stub had no commit() at all, which is why it passed against code that never called one. It counts commits now, and two tests assert on that count, so this exact mistake fails at the unit level rather than surviving to an integration run.
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
1 participant
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.
Second half of the observability groundwork (O4). Builds on the signal handlers #283 added, which is why the two were sequenced: the handlers get written once.
The gap
Seventeen periodic tasks run in this deployment. Five record anything at all, and those five write to singleton sync-state rows that hold only the most recent tick. The questions an operator actually asks after an incident have had no answer:
The table
Columns come from those questions rather than from what Celery happens to expose, and names are inherited rather than invented:
celery_task_idmatches the columnScanalready carries for the same value,skipped_reasonmatches the sync-state tables,resultfollows thedetail_code/detail_paramspairingadmin_health_serviceuses in six places.Writing happens in the signal handlers, so no task needs changing. A task that wants to say more returns
skipped_reasonordetail_code; anything else in the return value is dropped, because some tasks return snapshots measured in megabytes.Three boundaries
scansalready has status, timings and the Celery id. Two homes for one fact means neither is authoritative.task_prerunfires when a task begins. Pre-writing beat's schedule would make "beat never fired" and "the task started and died" look identical, and those need different responses.An open row (no
finished_at) therefore means the run started and never reported an end. That is the only trace a killed worker leaves, sooutcomeis nullable on purpose and the check constraint allows NULL.Retries write a row each
A counter would say "2 attempts, ended fine" and lose that the first one timed out. Attempts share the Celery id, which is what groups them, hence the index on that column.
Vocabulary
Grows by nesting, not duplication:
SKIPPED_REASON_VALUES = SYNC_SKIPPED_REASON_VALUES + task-only reasons, so the subset relation holds by construction and no value is written twice.is_valid_skipped_reasongained async_onlyflag so a check against a sync-state table cannot accepttrivy_timeout, which such a row can never hold.Costs
Two extra database round trips per task execution, one at each end. Acceptable against tasks measured in seconds to minutes; the recorder swallows its own errors so a database hiccup degrades the history rather than failing the work.
Retention rides the existing operational sweep at 90 days, matching the audit log's window. Unlike
audit_logsthis is diagnostic rather than evidential, so it is swept rather than kept.Verification
17 unit tests and 5 integration tests. The load-bearing integration test is the failure-then-success sequence: a single-execution test passes just as happily against a design that overwrites one row per task, and overwriting is precisely what the sync-state tables do today.
ruff checkclean,mypyclean across 822 files, full unit suite green (5814 passed; the 28 errors are the DB-backed tests that need a local instance).The config-key contract test caught the new environment variable before it could ship undeclared;
.env.exampleand the reference page carry it in both locales.