Scheduler: a queued webhook whose secret cannot be decrypted ends the pass, and keeps ending it #573

New issue

Closed

opened 2026-10-01 10:47:45 +00:00 by tiagoagueda · 0 comments

tiagoagueda commented

2026-10-01 10:47:45 +00:00

Owner

Found on 2026-09-29 in a read-only review of postulo at 95348908d, comparing the webhook delivery pass with the document-copy and sync passes, and confirmed by running send_due_reminders after changing SECRET_KEY.

Checked again on 2026-10-01 against main at 0a5cad587: still present. The code is now at notifications/management/commands/send_due_reminders.py:197 (the call to webhooks.send_pending()) and :242 (scheduler.beat()); notifications/webhooks.py and the two sibling passes have not moved.

deliver reads the connection's secret before its first try, so a secret written under another key raises SecretsUnreadable out of deliver, out of send_pending and out of the scheduler pass. The row has already been claimed, so it comes back after the 15-minute lease with no attempt recorded, is never given up on, and ends a pass every time it does.

Where: notifications/webhooks.py:122-123, deliver: secret = connection.secrets.get("secret") or "" sits outside the try blocks at lines 124 and 130; notifications/webhooks.py:155-165, send_pending, has no per-row guard; notifications/management/commands/send_due_reminders.py:195 calls it in the middle of one_pass, before run_syncs, reap_archives, errands.forget_old, pages.expire_unconfirmed and scheduler.beat() at line 240. The two sibling passes already handle this: documents/archiving.py:138 and plugins/syncing.py:81 catch SecretsUnreadable and record it.
What happens: secrets become unreadable when SECRET_KEY is rotated without POSTULO_FIELD_KEY, or when a backup is restored onto an instance with a different key, both cases plugins/secrets.py and the restore check describe. Any webhook row still pending or failed at that moment is picked up by the next pass: claim moves next_attempt_at 15 minutes ahead, deliver raises, and the pass ends. In a probe on the snapshot the pass raised SecretsUnreadable, run_syncs was never called, and the row stayed pending with 0 attempts and next_attempt_at 15 minutes on. A looping scheduler logs "A scheduler pass ended badly" and tries again; the row returns every 15 minutes and ends that pass too. Each bad row can end a pass, so several rows with staggered times end most passes.
Why it matters: every pass that meets the row skips sync connections, archive and errand reaping, the expiry of kept pages and the heartbeat, which the Compose healthcheck reads. The row never reaches given up, and neither the row nor the connection says why.
Fix: in deliver, read the secret inside a try; on SecretsUnreadable, record the message on the connection with record_test(False, ...) and end the row with fail(str(error), final=True), as the copy pass does. Also wrap each row in send_pending so an unexpected exception is logged against that row and the batch continues, as announce_due_reminders does per reminder since #221.

Done when

A test in tests/test_webhooks.py queues a row, changes SECRET_KEY with POSTULO_FIELD_KEY empty, runs webhooks.send_pending() and expects no exception, the row given up with the unreadable-secrets message, and the message on the connection.
A test in tests/test_scheduler.py expects run_syncs to be called and the heartbeat written on the same pass.

Found on 2026-09-29 in a read-only review of postulo at 95348908d, comparing the webhook delivery pass with the document-copy and sync passes, and confirmed by running `send_due_reminders` after changing `SECRET_KEY`. Checked again on 2026-10-01 against `main` at `0a5cad587`: still present. The code is now at `notifications/management/commands/send_due_reminders.py:197` (the call to `webhooks.send_pending()`) and `:242` (`scheduler.beat()`); `notifications/webhooks.py` and the two sibling passes have not moved. `deliver` reads the connection's secret before its first `try`, so a secret written under another key raises `SecretsUnreadable` out of `deliver`, out of `send_pending` and out of the scheduler pass. The row has already been claimed, so it comes back after the 15-minute lease with no attempt recorded, is never given up on, and ends a pass every time it does. - **Where:** `notifications/webhooks.py:122-123`, `deliver`: `secret = connection.secrets.get("secret") or ""` sits outside the `try` blocks at lines 124 and 130; `notifications/webhooks.py:155-165`, `send_pending`, has no per-row guard; `notifications/management/commands/send_due_reminders.py:195` calls it in the middle of `one_pass`, before `run_syncs`, `reap_archives`, `errands.forget_old`, `pages.expire_unconfirmed` and `scheduler.beat()` at line 240. The two sibling passes already handle this: `documents/archiving.py:138` and `plugins/syncing.py:81` catch `SecretsUnreadable` and record it. - **What happens:** secrets become unreadable when `SECRET_KEY` is rotated without `POSTULO_FIELD_KEY`, or when a backup is restored onto an instance with a different key, both cases `plugins/secrets.py` and the restore check describe. Any webhook row still pending or failed at that moment is picked up by the next pass: `claim` moves `next_attempt_at` 15 minutes ahead, `deliver` raises, and the pass ends. In a probe on the snapshot the pass raised `SecretsUnreadable`, `run_syncs` was never called, and the row stayed `pending` with 0 attempts and `next_attempt_at` 15 minutes on. A looping scheduler logs "A scheduler pass ended badly" and tries again; the row returns every 15 minutes and ends that pass too. Each bad row can end a pass, so several rows with staggered times end most passes. - **Why it matters:** every pass that meets the row skips sync connections, archive and errand reaping, the expiry of kept pages and the heartbeat, which the Compose healthcheck reads. The row never reaches *given up*, and neither the row nor the connection says why. - **Fix:** in `deliver`, read the secret inside a `try`; on `SecretsUnreadable`, record the message on the connection with `record_test(False, ...)` and end the row with `fail(str(error), final=True)`, as the copy pass does. Also wrap each row in `send_pending` so an unexpected exception is logged against that row and the batch continues, as `announce_due_reminders` does per reminder since #221. ## Done when - A test in `tests/test_webhooks.py` queues a row, changes `SECRET_KEY` with `POSTULO_FIELD_KEY` empty, runs `webhooks.send_pending()` and expects no exception, the row *given up* with the unreadable-secrets message, and the message on the connection. - A test in `tests/test_scheduler.py` expects `run_syncs` to be called and the heartbeat written on the same pass.

tiagoagueda added this to the 0.5.0 milestone

2026-10-01 10:47:45 +00:00

tiagoagueda added the

tier

bug

labels

2026-10-01 10:47:45 +00:00

tiagoagueda referenced this issue from a commit

2026-10-04 10:04:59 +00:00

Give up on a webhook whose secret cannot be read

tiagoagueda closed this issue

2026-10-04 10:04:59 +00:00