feat(plugins): record webhook deliveries turned away at the readiness guard (BLO-28803) - #1418
feat(plugins): record webhook deliveries turned away at the readiness guard (BLO-28803)#1418allyblockcast[bot] wants to merge 2 commits into
Conversation
1 similar comment
|
@ally head Requested a review from @allyblockcast directly (native GitHub review request, not just this comment) against current head |
![allyblockcast[bot]](https://avatars.githubusercontent.com/u/57363972?s=60&v=4){kind=small}
There was a problem hiding this comment.
Ally — Consolidated PR Review
Lenses: pr-review-toolkit (code, tests, comments, errors, types) + gstack/review + native-codex.
Reviewed head: 01e4f22
Critical Issues (0)
Important Issues (1)
- [native-codex]
server/src/services/metrics.ts:2136— the public rejection path emits onelogger.warnrecord for every rejected request, with no rate limit or coalescing.pluginIdis caller-controlled and an attacker can ignoreRetry-After, so the metric cardinality cap does not bound log volume; a sustained flood against a not-ready plugin can amplify logs and create an operational DoS.- Keep the bounded counter, but rate-limit or aggregate the warning (for example, emit a sampled/periodic summary keyed by the bounded plugin key and response class), while preserving per-request detail only where a bounded logging policy allows it.
Suggestions (0)
Strengths
- The counter labels use the resolved plugin row rather than the URL parameter, and the explicit admission cap provides a second cardinality defense.
- Retryable and terminal outcomes are represented as separate metric series, with route-level tests exercising rendered Prometheus exposition.
- Metrics failures are isolated from the HTTP response path so instrumentation cannot turn a deliberate 503 into a 500.
Recommended Action
- Address the Important logging-volume issue before merge.
|
Addressed the Important review finding in commit 4a9c840a740c555fd46eb08ae2e22d898c2ad0d2. The rejection counter remains per-request, but warning logs are now coalesced per bounded This keeps the 503/410 mapping unchanged and bounds the in-process log state to 64 admitted keys x 2 response classes. |
There was a problem hiding this comment.
Ally — Consolidated PR Review
Lenses: pr-review-toolkit (code, tests, comments, errors, types) + gstack/review + native-codex.
Reviewed head: 4a9c840
Prior Findings Dispositioned (1)
- prior:01e4f22 important 1 — fixed —
server/src/services/metrics.ts:2202— rejection logging is routed throughlogPluginWebhookDeliveryRejection, which coalesces repeated events per bounded plugin key and response class for 60 seconds and emits a suppressed-count summary instead of one warning per request.
Critical Issues (0)
Important Issues (0)
Suggestions (0)
Strengths
- The rejection counter is recorded on both the retryable 503 and terminal 410 paths, with separate response classes.
- Labels use the resolved plugin row and apply a bounded plugin-key admission policy, while caller-supplied request detail remains in logs.
- Tests exercise rendered Prometheus exposition, cardinality behavior, response separation, and log coalescing.
Recommended Action
- No Critical or Important issues remain from the current review.
- Consider Suggestions opportunistically.
|
Track A landing 2026-09-06: not merged — Tracking issue: BLO-32249 — rebase onto current This PR is deliberately left open rather than replaced, so the existing Ally review ledger stays attached to #1418. |
4a9c840 to
d7456f6
Compare
Rebased onto
|
| branch commit | status |
|---|---|
9c9ad4dc webhook ingestion answers 503, not 400 (BLO-28659) |
dropped — on master as 4dee26de0 |
5b4d117e partition not-ready statuses; uninstalled is 410 |
dropped — on master as 3d8ffe39a |
01e4f228 record deliveries turned away at the readiness guard (BLO-28803) |
kept → 338c68667 |
4a9c840a coalesce webhook rejection logs |
kept → d7456f62a |
So what remains is only the unlanded BLO-28803 contribution.
One conflict needed a judgement call, and it is worth flagging. Master has moved
past this branch: 1cd4148a0 (BLO-28659) inverted the readiness partition from a
retryable allowlist to a terminal denylist, so an off-enum plugin.status
now delays alerts instead of destroying them. This branch still carried the older
!WEBHOOK_RETRYABLE_PLUGIN_STATUSES.has(...) form. I kept master's
WEBHOOK_TERMINAL_PLUGIN_STATUSES denylist and layered the counter on top —
taking the branch side would have silently reverted that fix and reintroduced
payload destruction on unknown statuses. The metric instrumentation itself is
unchanged in behaviour; it now records on master's two arms.
The remaining conflicts (8 in metrics.ts, 1 test docblock) were both-sides-added
text — master's backstop metrics beside this branch's webhook counter — resolved
as keep-both.
Net diff against master is purely additive: 432 insertions, 0 deletions.
Local verification before pushing:
vitest run server/src/__tests__/plugin-webhook-not-ready-retryable.test.ts→ 23 passed (23)tsc --noEmit -p server/tsconfig.json→ clean- both commits parse independently (the intermediate commit is buildable, not just the tip)
mergeStateStatus is now MERGEABLE (was DIRTY).
The rebase invalidates the previous Ally attestations at 01e4f228 and 4a9c840a.
A fresh consolidated review of d7456f62a25164c0969242a5e81ea1c9762a79ab follows
once CI reports.
Disclosure: I performed this rebase, so the follow-up review is a self-review of my
own conflict resolution rather than an independent pass.
… guard (BLO-28803)
The ingestion route returns from the Step 2 readiness guard long before the
Step 6 plugin_webhook_deliveries insert, so a rejected delivery left no row,
no counter and no log anywhere in Paperclip. When the alertmanager plugin
latched into `error` on 2026-08-18, the only surviving evidence that ~15h of
alert batches had been turned away lived in Alertmanager's own logs
(BLO-20813) — the system of record for alerting could not answer "how many
did we bounce, and for which plugins?".
BLO-28659 makes that sharper rather than softer: rejection became deferral,
so senders now retry instead of failing loudly, and a plugin bouncing every
batch for hours is indistinguishable from one receiving none.
Both arms of the guard now increment
paperclip_plugin_webhook_delivery_rejected_total{plugin_key,response_class,
plugin_status} on the scraped registry before responding, so the volume is
alertable and recoverable from a Prometheus range query. retryable (503) and
terminal (410) stay on separate series — one says the payloads are coming
back, the other says they are gone.
Counter rather than a row, because this route is public and unauthenticated:
an insert keyed on a caller-supplied pluginId is a write-amplification vector.
Labels are read from the resolved database row, never from `:pluginId`, so an
unknown plugin is rejected 404 a step earlier and mints no series at all. A
64-key cap collapses any overflow to "other", holding the hard ceiling at
(64+1) x 5 series regardless of request volume. Per-request detail goes on a
paired structured log line, where it cannot become cardinality.
No change to the status->response mapping shipped in BLO-28659.
Co-Authored-By: Paperclip <noreply@paperclip.ing>
Co-Authored-By: Paperclip <noreply@paperclip.ing>
d7456f6 to
958587a
Compare
There was a problem hiding this comment.
Ally — Consolidated PR Review
Lenses: pr-review-toolkit (code, tests, comments, errors, types) + gstack/review + native-codex.
Reviewed head: 958587a
Critical Issues (0)
Important Issues (1)
- [native-codex]
server/src/__tests__/plugin-webhook-not-ready-retryable.test.ts:464— the coalescing test calls barevi.useFakeTimers()and then performs four real supertest HTTP round-trips against a liveapp. Vitest's defaulttoFakeincludessetImmediate/clearImmediate(andserver/vitest.config.tssets nofakeTimersoverride), while Node's http/stream internals schedule onsetImmediate— so faked immediates sit underneath genuine socket I/O for the wholetryblock. The code under test schedules nothing:logPluginWebhookDeliveryRejectiononly readsDate.now()(server/src/services/metrics.ts:1099) and registers no timer, so the full timer fake buys nothing and is the only new test carrying this hazard. It also has not been exercised in CI at any head to date —General testswasskippedatd7456f62(thepolicyattribution gate failed and skipped every downstream lane), and the lane at this head is still pending — so nothing has yet demonstrated it terminates.- Fake only what the coalescer actually reads:
vi.useFakeTimers({ toFake: ["Date"] }). That preserves theadvanceTimersByTime(60_000)window semantics exactly while leavingsetImmediatereal, removing the interaction with supertest entirely. If the pending lane goes green as-is, this reduces from a correctness risk to flake-hardening — but the one-line narrowing is worth taking either way.
- Fake only what the coalescer actually reads:
Suggestions (2)
- [gstack/review]
server/src/services/metrics.ts:3134—recordPluginWebhookDeliveryRejecteddocuments that it "must not throw: a metrics fault has no business converting a considered 503 into a 500", and wraps the counter.inc()(plusensureRegistry(), correctly the riskier half) intry/catch. The pairedlogPluginWebhookDeliveryRejectioncall sits outside that guard. With today's inputs the payload is string/number-only sologger.warnwill not realistically throw, and the route handler isasync, so a throw would surface as a rejected handler rather than a clean 500 — but the asymmetry reads as an oversight against the function's own stated contract rather than a decision.- Move the log call inside the same
try, or give it its own guard, so both surfaces honour the documented invariant.
- Move the log call inside the same
- [pr-review-toolkit/errors]
server/src/services/metrics.ts:1114— the suppressed-count summary is emitted lazily, only when the next rejection arrives after the interval has elapsed. When a flood stops, the final window'ssuppressedtally is never flushed, so the logs undercount the tail of exactly the incident shape BLO-20813 describes. The counter still carries exact volume, so the BLO-28803 requirement itself holds — this is a log-fidelity gap, not a metrics one.- Worth a line acknowledging the trade-off, or flushing the residual on a timer/scrape if the tail matters for reconstruction.
Strengths
- Labels are read from the resolved plugins row rather than the caller-supplied
:pluginId, withboundWebhookRejectionPluginKeyas an explicit second cardinality bound — the right ordering of defences for a public unauthenticated route, and the abuse bound is pinned by its own test. - The documented
(64 + 1) * 5series ceiling checks out:WEBHOOK_TERMINAL_PLUGIN_STATUSESis{uninstalled},response_classis functionally determined byplugin_status, andreadynever reaches the guard. retryable(503) andterminal(410) are kept on separate series, with a test asserting they never aggregate — the one distinction an incident reconstruction actually needs.- The log-coalescing state map is keyed on the bounded plugin key, so it inherits the same ≤130-entry ceiling rather than reintroducing unbounded growth behind the metric.
- Tests assert against rendered Prometheus exposition rather than the in-process registry, which is the property the ticket actually asks for, and
__resetMetricsForTestclears both new module-level maps.
Recommended Action
- Narrow the fake-timer scope in the coalescing test before merge, and confirm the
General testslane goes green at this head — it has not run for this change yet. - Consider the two Suggestions opportunistically.
There was a problem hiding this comment.
Ally — Consolidated PR Review
Lenses: pr-review-toolkit (code, tests, comments, errors, types) + gstack/review + native-codex.
Reviewed head: 958587a
Verdict reconciliation at unchanged head — no code changed since the previous review of this same SHA. That review raised one Important finding whose stated basis was explicitly evidential: the new coalescing test "has not been exercised in CI at any head to date" and "the lane at this head is still pending — so nothing has yet demonstrated it terminates." It also pre-committed to the downgrade rule: "If the pending lane goes green as-is, this reduces from a correctness risk to flake-hardening." That lane has since completed. General tests (server 2/4) logs ✓ src/__tests__/plugin-webhook-not-ready-retryable.test.ts (23 tests) 449ms at 08:38:28Z, roughly two hours after the review was written, and all four server shards plus verify are green at this head. The basis is falsified on its own stated terms, so the finding reduces to Suggestion tier below rather than standing as a merge blocker.
Critical Issues (0)
Important Issues (0)
Suggestions (3)
- [native-codex]
server/src/__tests__/plugin-webhook-not-ready-retryable.test.ts:464— the coalescing test calls barevi.useFakeTimers()and then performs four real supertest HTTP round-trips. Vitest 4's defaulttoFakeincludessetImmediate/clearImmediateandserver/vitest.config.tssets nofakeTimersoverride, so faked immediates sit underneath genuine socket I/O for the wholetryblock. The code under test schedules nothing —logPluginWebhookDeliveryRejectiononly readsDate.now()(server/src/services/metrics.ts:1099) and registers no timer — so the full timer fake buys nothing beyond theDatecontrol the test actually uses. Empirically it does not bite: the suite ran in 449ms with no hang. One green run is not proof of determinism, so this stays worth taking, but as hardening rather than a blocker.- Fake only what the coalescer reads:
vi.useFakeTimers({ toFake: ["Date"] }). That preserves theadvanceTimersByTime(60_000)window semantics exactly while leavingsetImmediatereal, removing the interaction with supertest entirely.
- Fake only what the coalescer reads:
- [gstack/review]
server/src/services/metrics.ts:3134—recordPluginWebhookDeliveryRejecteddocuments that it "must not throw: a metrics fault has no business converting a considered 503 into a 500", and wrapsensureRegistry()plus the counter.inc()intry/catch. The pairedlogPluginWebhookDeliveryRejectioncall sits outside that guard, after the closing brace. With today's inputs the payload is string/number-only sologger.warnwill not realistically throw, and the route handler isasync, so a throw would surface as a rejected handler rather than a clean 500 — but the asymmetry reads as an oversight against the function's own stated contract rather than a decision.- Move the log call inside the same
try, or give it its own guard, so both surfaces honour the documented invariant.
- Move the log call inside the same
- [pr-review-toolkit/errors]
server/src/services/metrics.ts:1114— the suppressed-count summary is emitted lazily, only when the next rejection arrives after the interval has elapsed. When a flood stops, the final window'ssuppressedtally is never flushed, so the logs undercount the tail of exactly the incident shape BLO-20813 describes. The counter still carries exact volume, so the BLO-28803 requirement itself holds — this is a log-fidelity gap, not a metrics one.- Worth a line acknowledging the trade-off, or flushing the residual on a timer/scrape if the tail matters for reconstruction.
Strengths
- Labels are read from the resolved plugins row rather than the caller-supplied
:pluginId, withboundWebhookRejectionPluginKeyas an explicit second cardinality bound — the right ordering of defences for a public unauthenticated route, and the abuse bound is pinned by its own test. - The documented
(64 + 1) * 5series ceiling checks out:WEBHOOK_TERMINAL_PLUGIN_STATUSESis{uninstalled},response_classis functionally determined byplugin_status, andreadynever reaches the guard. retryable(503) andterminal(410) are kept on separate series, with a test asserting they never aggregate — the one distinction an incident reconstruction actually needs.- The log-coalescing state map is keyed on the bounded plugin key, so it inherits the same ≤130-entry ceiling rather than reintroducing unbounded growth behind the metric.
- Tests assert against rendered Prometheus exposition rather than the in-process registry, which is the property the ticket actually asks for, and
__resetMetricsForTestclears both new module-level maps.
Recommended Action
- No blockers remain at this head. The three Suggestions are opportunistic; the one-line
toFake: ["Date"]narrowing is the most worthwhile of them. - This PR is authored by the
allyblockcastGitHub App, which GitHub bars from approving its own pull request, so this verdict is delivered as a formalCOMMENTEDreview rather than an approval. That is the artifact of record for the ally gate.
Rebase status for BLO-32249 — head
|
Correction to my 11:23Z comment — I overstated the blockerRun Measured this run, head
The status is still genuinely stale, and that part of the earlier comment stands: it is pinned at The one real defect at this head is mine, and it is not a merge gate either. Two operative Ally App reviews stand at Two things worth recording about that check:
I am deliberately not posting a third consolidated review to "refresh" anything — that would take I1 from 2 to 3. The attestation at this head exists and is correct. Net: no code blocker (the 11:13Z review is clean; the three Suggestions, including the |
Thinking Path
Linked Issues or Issue Description
fix/BLO-28659-webhook-not-ready-503, notmaster, because theretryable/terminalpartition this records against only exists on that branch. Retarget tomasteronce fix(plugins): webhook ingestion answers 503, not 400, when a plugin is not ready (BLO-28659) #1403 merges.What Changed
Both arms of the readiness guard now record before responding:
response_class503+Retry-Afterretryable410 GoneterminalThese stay on separate series — summing them would hide the only distinction an incident reconstruction actually needs.
server/src/services/metrics.ts—paperclip_plugin_webhook_delivery_rejected_total{plugin_key,response_class,plugin_status}on the existing scraped prom-client registry, plusrecordPluginWebhookDeliveryRejected(). The record path is wrapped so a metrics fault can never convert a considered 503 into a 500 the sender reads as something else.server/src/routes/plugins.ts— call it on both arms; route docblock states the contractserver/src/__tests__/plugin-webhook-not-ready-retryable.test.ts— 7 new cases (20 total)Live exposition, rendered through
renderMetrics()(the same path/metricsserves). The13is deliberate — it is thenum_alerts=13batch observed during the outage:The question BLO-20813 could not answer from Paperclip is now one query:
Retention and abuse posture (stated deliberately)
The issue asked for this to be decided explicitly rather than inherited. A counter, not a
plugin_webhook_deliveriesrow — this route is public and unauthenticated by design, and an insert keyed on a caller-suppliedpluginIdis a write-amplification vector. A counter costs an increment on an existing series; abuse buys the attacker nothing.The bound, in two layers:
:pluginId. A POST naming a plugin that does not exist is rejected404one step earlier and mints no series at all. Cardinality is therefore bounded by thepluginstable, which is operator-controlled.boundWebhookRejectionPluginKeyadmits at most 64 distinct keys per process and collapses the rest toother. Ceiling:(64 + 1) × 5 = 325series — five becausereadynever reaches the guard — independent of the plugins table and of request volume.Per-request detail (
pluginIdas supplied,endpointKey, the HTTP status sent) goes on a paired structured log line, where it cannot become cardinality.Deliberately unchanged: the status→response mapping from #1403. The diff is purely additive — 352 insertions, 0 deletions.
Out of scope, per the issue: replay/backfill of deferred payloads. Alertmanager re-notifies from current state on recovery; a replay buffer is a much larger design question and is not implied here.
Verification
Both guards were falsified against the code they protect — a test that passes before and after would be worthless.
Reverting
server/src/routes/plugins.tsto its pre-change state (the defect itself):The 2 that still pass are correct and intentional:
mints no series for a plugin that does not existasserts absence (the abuse bound, which holds trivially without the fix), and the cap test is a pure unit test of the metrics helper.Labelling from the URL parameter instead of the resolved row — the cardinality bug the bound exists to prevent:
No regressions in adjacent suites:
npx vitest run server/src/__tests__/metrics-service.test.ts \ server/src/__tests__/metrics-ingest-route.test.ts \ server/src/__tests__/plugin-webhook-verification.test.ts \ server/src/__tests__/plugin-routes-authz.test.ts \ server/src/__tests__/plugin-scoped-api-routes.test.ts # Test Files 5 passed (5) Tests 186 passed (186)One pre-existing sandbox flake, reported honestly. Running the full file locally,
answers 503 with Retry-After when plugin status is "installed"— the first test to execute — times out at its 20s budget while paying ~20s of one-time module transform. I confirmed this is not caused by this change by stashing the diff and re-running on the unmodified tree: it fails identically there (× ... 20345ms,12 passed (13)). Same file was 13/13 and CI 20/20 green on #1403. Left alone deliberately rather than fixed here — #1403 owns this file and is still open, so widening my footprint invites a conflict. Every other test in the file passes: 19/20.Risks
Low, and named honestly:
Retry-Afterbackoff.otherrather than evicting earlier ones. Chosen because real installs are few and long-lived; the fleet runs well under 20.Model Used
claude-opus-4-5), 1M context window, extended thinking, tool use (repo edit, local Vitest/tsc execution, falsification runs against reverted code).Checklist
Fixes: #/Closes #/Refs #OR (b) described the issue in-PR following the relevant issue templatePaperclip issue: https://paperclip.blockcast.net/BLO/issues/BLO-28803