Expose delivery metrics on /metrics (closes #209) #224
Reference in New Issue
Block a user
Delete Branch "issue-209-delivery-metrics"
Deleting a branch is permanent. Although the deleted branch may continue to exist for a short time before it actually gets removed, it CANNOT be undone in most cases. Continue?
Closes #209.
/metricscarried only the inbound HTTP surface, so a destinationfailing for an hour, a growing retry backlog and a stuck-open circuit
breaker were all invisible: the receive side stays healthy in each
case because it is.
What landed
New
internal/metricsregisters these on the existing registry —prometheus.DefaultRegisterer, which is whatmetrics.NewRecorder(metrics.Config{})ininternal/middlewaredefaults to and what
promhttp.Handler()gathers. No second registry,no second route;
internal/server/routes.gois untouched.webhooker_events_received_totalwebhooker_delivery_attempts_totalwebhooker_deliveries_succeeded_totalwebhooker_deliveries_failed_totalwebhooker_delivery_retries_totalwebhooker_delivery_duration_secondswebhooker_deliveries_pendingpendingwebhooker_deliveries_retryingretryingwebhooker_circuit_breakers_openCardinality
Every delivery metric carries exactly one label,
target_type, whosedomain is the four target-type constants. A value outside that set
collapses to
unknownrather than minting a series, so an unknown oredited target type cannot grow the label set.
Target id is not a label. Its cardinality is not bounded: target
ids are UUIDs minted per operator action, a series is never reclaimed
once it exists, and a delete/recreate cycle leaks one forever. Event
id and entrypoint id are excluded for the same reason. A test asserts
the collapse (
TestUnknownTargetTypeCollapses).What is counted, and where
Attempts and duration —
Engine.observeAttempt, called from thepaths that actually dispatched, alongside the
DeliveryResulteachof them writes. HTTP and Slack report
attemptResult.duration, thesame value that is persisted; the log and database targets time
their own work, so their result rows carry a real duration too.
A delivery an open circuit breaker refuses is deliberately not
an attempt: it sends nothing and records no result row. Counting it
would climb the attempts counter with no traffic behind it and fill
the duration histogram with near-zero samples, so the delivery
quantiles would improve for as long as the breaker stayed open —
the metric moving the wrong way during exactly the incident it
exists to reveal. It is already visible as a retry.
Outcomes —
Engine.updateDeliveryStatus, once per transitionthe engine persists, and only after the row is written. A status
write the database rejected is never reported as an outcome that
happened, which is the same reasoning that rules out delta-tracked
gauges below.
The type is passed to that helper as an argument rather than read
off
Delivery.Target.failUnretryableRetryloads its deliverywithout the target relation on purpose: populating
d.TargetmakesGORM's
SaveBeforeAssociationsupsert the wholetargetsrow onthe status UPDATE, writing the plaintext target config — which for
a Slack target is the credential — into the per-webhook
events-*.db. That is the leak class tracked at#206;
TestFailUnretryableRetry_WritesNoTargetRowasserts that tablestays empty, and fails if the association is ever populated again.
Open breakers —
httpCore.publishCircuitState, recounted fromthat target type's breaker registry on every state change rather
than adjusted as a delta.
Queue depths —
internal/delivery/queue_depth.go, counted outof the per-webhook databases by a 30s sampler that runs with the
engine. Deltas were rejected: they would need seeding at startup
from rows a previous process wrote, and would drift permanently on
any transition that failed to persist.
Both gauges publish an
unknownseries, materialised atregistration rather than on first occurrence. A delivery queued
against a target that has since been deleted resolves to the empty
type and is folded there. That backlog is the one nobody is
watching, and it can predate the process, so its series has to exist
before a backlog has already built up.
Events received —
Handlers.createAndDeliverEvent, after thecommit.
go.modgainsgithub.com/prometheus/client_modelas a directdependency (it was already an indirect one, same version): the tests
read values back off a private registry.
prometheus/testutilwas notused because it would have pulled in a module the repo does not have.
Tests
Required test —
TestDeliveryMetrics_SuccessAndRetryExhaustion(
internal/delivery/metrics_test.go) drives one delivery thatsucceeds and one that fails every attempt until its retry budget is
exhausted, asserting exact values for all four counters and the
histogram across both. Also:
TestFailUnretryableRetry_WritesNoTargetRow— the orphaned-retryterminal path writes no
targetsrow, and no target config, intothe per-webhook database.
TestDeliveryMetrics_BreakerBlockedIsNotAnAttempt— a delivery anopen breaker refuses moves the retry counter and leaves the attempts
counter and duration histogram untouched.
TestDeliveryMetrics_OrphanedRetryFailureLabelled— that terminalfailure is still labelled with the target's real type.
TestDeliveryMetrics_CircuitBreakerGauge— gauge follows a breakerthat trips.
TestDeliveryMetrics_QueueDepthGauges/TestDeliveryMetrics_QueueDepthDeletedTarget— the samplerpublishes what is in the databases, a drained queue reads 0 rather
than holding its last value, and a backlog against a deleted target
shows up under
unknown.internal/metrics/metrics_test.go— cardinality collapse, theunknown fold, gauge reset, status-to-counter mapping, and the series
that exist before any delivery.
Each delivery test gives the engine a set registered on a private
registry (
Engine.ExportSetMetrics, defined inexport_test.goandso absent from the production binary), so assertions are exact rather
than being disturbed by the parallel delivery tests moving the
process-wide collectors.
Gate evidence
Full evidence, with host load averages, is in the rework comment:
#224 (comment)
GOFLAGS=-count=1 make checkon the rebased branch — exit 0,0 issues.from the Docker lint stage, no(cached)package lines.Cache-defeated container build,
docker build --no-cache-filter=lint --no-cache-filter=builder --progress=plain .— exit 0; lint stage ran 68.1s, builder
make testran 88.8s, zero(cached)markers in thego testoutput, and the onlyCACHEDlayers are base-image and alpine ones.
script/testruns-race; norace reports.
The gate image was removed;
docker ps -ais clean. No prune was run.Notes
TODO.mduntouched, per#112.
address outside the SSRF blocklist; the tests deliver to
httptestservers through the engine's own path.FAIL —
needs-rework.1. BLOCKING:
d.Target = *targetleaks target credentials into the per-webhook event DBinternal/delivery/engine.go:842(failUnretryableRetry) newly assignsd.Target = *targetsoupdateDeliveryStatuscan read the type for a metrics label. The PR body calls this harmless. It is not.updateDeliveryStatusdoeswebhookDB.Model(d).Update("status", status). GORM runsSaveBeforeAssociationson the update callback chain, and it upserts a BelongsTo association whenever the association field is non-zero.failUnretryableRetryexplicitly loads the delivery without its relation, sod.Targetwas zero here and no upsert fired. Populating it makes this path upsert the wholetargetsrow —configincluded — into the per-webhookevents-*.db.That is precisely the credential leak tracked at #206 (open, 1.0.0 milestone), extended to a code path that did not previously have it. For a
slacktarget theconfigis the bearer credential; forhttpit can carry userinfo.Verified empirically, not inferred — isolated GORM probe against the same
gorm.io/driver/sqliteand versions from thisgo.mod, mirroring the model shape, run in a container:A metrics change must not change what is written to the database. Acceptable: leave
dalone and pass the type in — atarget.Typeargument toupdateDeliveryStatus, or a typed variant — or scope the write withOmit(clause.Associations). Either way, a test that assertsfailUnretryableRetrywrites notargetsrow.2.
queue_depth.gocomment contradicts the code; orphaned-target backlog vanishesinternal/delivery/queue_depth.go:123-126claims "A delivery whose target has since been deleted resolves to the empty type and lands in the unknown bucket rather than being dropped." It is dropped.types[row.TargetID]yieldsTargetType(""), so the count accumulates under key"", andSet.SetQueueDepths(internal/metrics/metrics.go:180) only ever readspending[t]/retrying[t]for the fourknownTargetTypes. There is nounknownseries for either queue gauge —initSeriescreates known types only.Net effect: deliveries queued against a deleted target are invisible in
webhooker_deliveries_pending/_retrying, which is exactly the stuck backlog #209 asks to be alertable. Acceptable: fold the empty type into anunknownseries (normalizeTargetTypealready exists and is used by every other setter) and materialise that series ininitSeries, or delete the comment and state the loss — but silently dropping a backlog is the worse of the two.3. Circuit-breaker-blocked non-attempts are counted as attempts, with ~0s durations
processDeliveryincrementswebhooker_delivery_attempts_totaland observeswebhooker_delivery_duration_secondsaroundtarget.Deliver. When a breaker is open,httpCore.withRetry->circuitBreakerBlockreturns before any request is made. So with a breaker stuck open — one of the three named failure modes in #209 — the attempts counter climbs with zero network attempts, and the duration histogram fills with microsecond samples, makingdelivery_duration_secondsquantiles look better during the outage.The engine already has the real per-attempt duration:
attemptResult.duration, whichrecordResultpersists. The histogram measures something else. Acceptable: observe only on the path that actually dispatched (or observeres.duration), and do not count a breaker-blocked delivery as an attempt.4. Outcome counters move even when the transition is not persisted
internal/delivery/engine.go:944increments beforewebhookDB.Model(d).Update(...)and unconditionally of its error. The PR body argues the gauges are counted rather than deltas precisely because "any transition that failed to persist" would drift — the counters have exactly that flaw. A failed status write leavesdeliveries_failed_totalclaiming an outcome the database does not have, and the queue gauge (read from the DB) permanently disagreeing. Acceptable: count after a successfulUpdate.5. Minor:
Engine.mxreads as a mutexinternal/delivery/engine.go:146.mx/muis the near-universal Go shorthand for a mutex, and the same struct holds async.WaitGroup.mtr,metormetricswould not misdirect.Checked and passing (no action): no unbounded value can reach a label — every
WithLabelValuesgoes throughnormalizeTargetTypeor iteratesknownTargetTypes, and theunknowncollapse is operator- not sender-driven; registration issync.OnceValueoverprometheus.DefaultRegistererso it cannot double-register under-count=2or a twice-built graph; retry/failed-terminal counting is exclusive and once-only inhandleRetry; the sampler is rooted atcontext.Background()per #97, is single-goroutine ticker-driven so it cannot pile up, and is bounded at shutdown bylifecycle.WaitForShutdown;TestDeliveryMetrics_SuccessAndRetryExhaustionasserts exact values and fails if the instrumentation is removed;go.modmoves onlyprometheus/client_modelindirect-to-direct at the same version andtestutilis avoided;TODO.mduntouched; base isnext; title ends with(closes #209); no Claude/Anthropic references or attribution trailers; no committed assets; merges cleanly into currentnext(bb30b3a).internal/metrics/metrics.gowas inspected line by line after the disclosed scripted block move: nine collector fields, all nine assigned exactly once acrossNew/registerCounters/registerGauges, no duplicate or missing top-level declaration, no truncation,gofmt -sandgolangci-lintclean. The move is intact.Independently obtained gate,
docker build --no-cache-filter=lint --no-cache-filter=builder --progress=plain, exit 0: lint stagegolangci-lint runran 139.9s,0 issues; buildermake testran 174.6s; fourCACHEDlines total, all apt/base layers, none inlintorbuilder; zero(cached)markers ingo testoutput.script/testruns-race, so the new sampler goroutine was exercised under the race detector —internal/delivery 7.245s,internal/metrics 1.171s, no race reports. Containers and images removed.Two notes, neither charged to this PR. The tracker check on
b8c8b75is stillpending, so CI is not green. Andgo test -count=2 ./internal/server/...panics withduplicate metrics collector registration attemptedinmiddleware.Metrics->go-http-metrics NewRecorder->MustRegister; I reproduced it on plainorigin/nextatbb30b3awith this branch absent, so it is a pre-existing defect from #216 and needs its own issue, not a change here.b8c8b75e04todfd559417eReworked, force-pushed as one commit
dfd5594, rebased ontonextata13e5b7.1 (blocking) — credential leak: fixed at the source
d.Target = *targetis gone.updateDeliveryStatusnow takes thetarget type as an argument;
failUnretryableRetrypassestarget.Typeand leaves the delivery loaded without its relation, asthat path intends.
recordResultis unchanged, so nothing else onthat path can trigger
SaveBeforeAssociations.Regression test:
TestFailUnretryableRetry_WritesNoTargetRow(
internal/delivery/engine_integration_test.go) drives the sweepagainst a target whose config is a Slack incoming-webhook URL, then
asserts
events-*.dbholds zerotargetsrows and that the URL doesnot appear in that table.
Proof the test catches the defect rather than merely passing — the
mutation was reintroduced on the fixed tree and the suite re-run:
and the write itself, from the per-webhook connection's SQL log:
The mutation was then reverted; the pushed tree does not contain it.
The fix does not depend on
#223 — no
Omitis used, theassociation is simply never populated.
2 — queue depth: emitting
unknown, not droppingSet.SetQueueDepthsfolds counts throughnormalizeTargetType(summing, so several unknown types do not overwrite each other) and
writes the whole domain including
unknownon every sample, so adrained unknown bucket reads 0.
initSeriesmaterialises the twounknownqueue series at registration — that backlog is read out ofthe databases and can predate the process, so the series has to exist
before the first sample. The false comment in
queue_depth.goisreplaced with what the code does.
Tests:
TestSetQueueDepthsFoldsUnknownTypes(internal/metrics) andTestDeliveryMetrics_QueueDepthDeletedTarget(end to end through thesampler, no target row in the main DB).
3 — duration histogram: dispatched attempts only
Both the attempts counter and the duration histogram moved off
processDeliveryintoEngine.observeAttempt, called from the pathsthat actually dispatched, next to the
DeliveryResulteach records.HTTP and Slack pass
attemptResult.duration— the same valuerecordResultpersists. The log and database targets now time theirown work instead of reporting 0, so their result rows carry a real
duration too.
Decision, stated explicitly: a breaker-blocked delivery is not an
attempt and gets no new series. It sends nothing, records no result
row, and is already counted as a retry by
webhooker_delivery_retries_total— which is the series that climbswhile a breaker is stuck open.
Test:
TestDeliveryMetrics_BreakerBlockedIsNotAnAttempttrips thebreaker, then drives one more delivery and asserts the retry counter
moved while attempts and histogram sample count did not.
4 — counters after the write
updateDeliveryStatusreturns on a failedUpdateand incrementsonly after the row is written.
5 —
mxRenamed to
mtronEngine, and onHandlersfor consistency.Out of scope
-count=2ininternal/server(#227) untouched.
TODO.mduntouched.
Gate
Host load average during the runs: 38.65 rising to 67.55 (1-minute)
across the
make checkrun; 72.73 falling to 43.51 across thecontainer build.
GOFLAGS=-count=1 make check— exit 0, no(cached)package lines:docker build --no-cache-filter=lint --no-cache-filter=builder --progress=plain .— exit 0. Lint stage
#20 DONE 68.1swith0 issues.; buildermake test#28 DONE 88.8s; zero(cached)markers anywhere in thego testoutput. FiveCACHEDlines total, all base-image andalpine layers (
#6,#7,#11,#12,#13) — none inlintorbuilder.script/testruns-race; no race reports.New and changed tests, from that uncached builder run:
The gate image was removed;
docker ps -ais clean. No prune was run.PASS —
merge-ready. All five prior findings fixed; leak closure reproduced independently, gate re-run green ondfd5594.Anomalies and disclosures:
dfd5594ispending("Waiting to run"), not green — queued, not red. Per #119 the check mark is not evidence anyway; the authoritative gate was obtained locally:docker build --no-cache-filter=lint --no-cache-filter=builder --progress=plain .exit 0, lint#20 DONE 68.8swith0 issues., buildermake test#31 DONE 94.0s, zero(cached)markers, zeroFAIL/DATA RACE, no BuildKit log clipping (1.88 MB). Host load 61-70 throughout. Image removed,docker ps -aclean, no prune run.CACHEDlayers, three are inside thebuilderstage (COPY --from=lint /src/go.sum, the apt-get,WORKDIR) despite--no-cache-filter=builder. The two layers that matter —golangci-lint runandmake test— both ran with real durations and full output.Omit(clause.Associations)and no GORM callback registration, so the fix rests solely on never populating the association. Reintroducingd.Target = *targetinfailUnretryableRetryon the pushed tree makesTestFailUnretryableRetry_WritesNoTargetRowfail with theINSERT INTO+ "targets" +... ON CONFLICT DO NOTHINGcarrying the Slack URL; the pushed tree passes. If 223 were reverted, this path still writes no target row.internal/delivery/engine.go:447-448(processRetryTask) still setsd.Event/d.Targetfrom the task before the sameUpdate, so the ordinary retry path does upsert atargetsrow into the per-webhook DB onnexttoday. That is #206 itself, untouched by this change, and correctly out of scope here — noting it only so the green regression test is not read as proving the whole class is closed.circuitBreakerBlockpersistsretrying, which incrementswebhooker_delivery_retries_total, the sampler carries it inwebhooker_deliveries_retrying, and the newdefer publishCircuitStatesetswebhooker_circuit_breakers_open. Three series move; onlydelivery_attempts_totaland the duration histogram, which measure dispatched traffic, correctly do not.-count=2run (internal/metrics,internal/delivery,internal/middleware— allokunder-race) were run asgo testinside the pinnedgolang:1.26.1-bookwormcontainer, since no make target runs a single test or-count=2. All linting was via the Docker gate only; nothing was run on the host.clawbot referenced this pull request2026-08-20 07:38:15 +02:00
clawbot referenced this pull request2026-08-20 07:38:44 +02:00