Remove post-persist ambiguity and have events match emitted state - #1350
Conversation
e4d6dcc to
4c45612
Compare
4c45612 to
4750557
Compare
| attempt = CASE | ||
| WHEN river_job.state = 'running' | ||
| AND NOT (job_input.state IN ('retryable','scheduled') AND river_job.metadata ? 'cancel_attempted_at') | ||
| AND NOT (job_input.state IN ('available','retryable','scheduled') AND river_job.metadata ? 'cancel_attempted_at') |
There was a problem hiding this comment.
These are kind of a related fix that's also adjacent. A job completer may set a job back to available if the scheduled time was very short in the future. Adding available here makes it so that a pending cancel wins if this was about to occur which is the more correct behavior (it was a bug before that this was wasn't considered).
4750557 to
11ee66d
Compare
|
@bgentry This does seem like a useful fix for previously somewhat ambiguous behavior. Seem okay? |
|
I tested this branch in combination and #1219 and it fixes all the issues I encountered while rebasing it. Thanks! BTW, from code it looks to me like |
42c03ed to
109e32e
Compare
Thx. Fixed.
Yeah, basically by the time we hit |
| Reason riverdriver.JobSetStateReason | ||
| } | ||
|
|
||
| func newCompleterJobUpdated(job *rivertype.JobRow, stats *jobstats.JobStatistics, requestedReason riverdriver.JobSetStateReason) CompleterJobUpdated { |
There was a problem hiding this comment.
I might opt to have this method be only focused on the state/reason since afaict that's all it's actually returning, but it's minor so up to you for sure!
There was a problem hiding this comment.
Renamed: completerJobUpdatedFromStateAndReason
| ### Fixed | ||
|
|
||
| - Write timestamps in SQLite to always include three digits after the second like `.000`. Previously, they may have been truncated down to just `.0` in the case of trailing zeroes. [PR #1349](https://github.com/riverqueue/river/pull/1349) | ||
| - Job completion events now reflect the job's persisted outcome when it differs from the transition requested by the worker. For example, a job completed with `JobCompleteTx` before its worker returns an error emits `job_completed`, and a remotely cancelled job whose worker errors or snoozes emits `job_cancelled`. [PR #1350](https://github.com/riverqueue/river/pull/1350) |
There was a problem hiding this comment.
Do you think this deserves any further detail on how this might impact people whose programs are written against these states?
There was a problem hiding this comment.
I added this sentence to the existing changelog to clarify that aspect:
Applications subscribed only to
job_failedorjob_snoozedshould note that these events may instead be delivered tojob_completedorjob_cancelledsubscribers.
TBH though, I am kind of hoping that this will be quite rare for users. It's good to be complete in the changelog, but the chances of someone catching a bug by reviewing what happened made in the changelog is probably fairly low. Albeit, maybe substantially higher if AI's involved in the upgrade.
This one's aimed at fixing [1] in which for some sequences in workers, we'd emit a surprising event based on the state that was actually persisted to the database. This contract was also not stable, and changed subtly with the introduction of #1290. From [1], this is best illustrated by a short example where we error after invoking `JobCompleteTx`: func (w *Worker) Work(ctx context.Context, job *river.Job[Args]) error { tx, _ := w.dbPool.Begin(ctx) defer tx.Rollback(ctx) river.JobCompleteTx[*riverpgxv5.Driver](ctx, tx, job) // row -> completed tx.Commit(ctx) return errors.New("boom") // executor reports an error, but its UPDATE is an IfRunning no-op } This used to emit a `job_completed`, but has changed in `master` to emit a `job_failed`. Here, we try to correct the emitted event and officially standardize it: | Scenario | Persisted state | Previous event | New event | |---|---:|---:|---:| | `JobCompleteTx` commits, then worker returns an error | `completed` | `job_failed` | `job_completed` | | Remote cancellation, then worker requests a retry | `cancelled` | `job_failed` | `job_cancelled` | | Remote cancellation, then worker snoozes | `cancelled` | `job_snoozed` | `job_cancelled` | Unambiguous persisted states always take precedence, though we retain reason (added in #1290) to distinguish possible states of `available`, which may be (1) an immediate retry after failure, (2) a short snooze, or (3) an interruption caused by client shutdown. [1] #1290 (comment)
109e32e to
a397b29
Compare
|
Thanks! |
Durable-truth fix, not a timing knob. probe.go's cross-client/same-client/ Release() cancellation sequence already converges deterministically without depending on NOTIFY delivery — Release() is pure in-memory, and a job cancelled through it reliably persists state=cancelled via River's own explicit river.JobCancel() routing. The one link that stayed fragile was the FINAL confirmation step: waitForEvent(..., EventKindJobCancelled), strictly filtered on River's own emitted event stream. Upstream PR riverqueue/river#1350 (the actual PR body, not just the changelog) documents a v0.40 event-routing bug matching exactly this scenario: "remote cancellation, then worker requests a retry" persists the job as cancelled but emits job_failed, not job_cancelled. A strict wait on EventKindJobCancelled can hang even though the database write was already correct — the row is the truth, the event stream just didn't reliably reflect it in this version. waitForCancelledRow replaces the single waitForEvent call: it races the event stream (used immediately when it arrives with the right kind, so the normal fast path is unchanged) against a ticker that polls client.JobGet's persisted State via River's stable public API, on the same opts.FetchPollInterval the harness already uses elsewhere for the identical class of purpose (not a new timing knob — and not "wait longer": convergence happens on whichever check sees the true state first, an event or a poll, never after some elapsed duration). Explicitly a liveness cadence, not a correctness window: it bounds how promptly a lost signal is caught, not whether it eventually is. This closes the confirmation-step gap under both v0.40 and v0.44 River semantics without depending on the version bump (CHAOS-4064, separate follow-up) to fix it. Verified: go build/vet/gofmt clean; a full real end-to-end run (all three modes, all phases) passes with the normal fast event path unchanged; combined with the pool-split commit, the CPU-constrained repro that caught the original pool-exhaustion failure ran 10/10 clean under the exact same constraint that produced it.
Durable-truth fix, not a timing knob. probe.go's cross-client/same-client/ Release() cancellation sequence already converges deterministically without depending on NOTIFY delivery — Release() is pure in-memory, and a job cancelled through it reliably persists state=cancelled via River's own explicit river.JobCancel() routing. The one link that stayed fragile was the FINAL confirmation step: waitForEvent(..., EventKindJobCancelled), strictly filtered on River's own emitted event stream. Upstream PR riverqueue/river#1350 (the actual PR body, not just the changelog) documents a v0.40 event-routing bug matching exactly this scenario: "remote cancellation, then worker requests a retry" persists the job as cancelled but emits job_failed, not job_cancelled. A strict wait on EventKindJobCancelled can hang even though the database write was already correct — the row is the truth, the event stream just didn't reliably reflect it in this version. waitForCancelledRow replaces the single waitForEvent call: it races the event stream (used immediately when it arrives with the right kind, so the normal fast path is unchanged) against a ticker that polls client.JobGet's persisted State via River's stable public API, on the same opts.FetchPollInterval the harness already uses elsewhere for the identical class of purpose (not a new timing knob — and not "wait longer": convergence happens on whichever check sees the true state first, an event or a poll, never after some elapsed duration). Explicitly a liveness cadence, not a correctness window: it bounds how promptly a lost signal is caught, not whether it eventually is. This closes the confirmation-step gap under both v0.40 and v0.44 River semantics without depending on the version bump (CHAOS-4064, separate follow-up) to fix it. Verified: go build/vet/gofmt clean; a full real end-to-end run (all three modes, all phases) passes with the normal fast event path unchanged; combined with the pool-split commit, the CPU-constrained repro that caught the original pool-exhaustion failure ran 10/10 clean under the exact same constraint that produced it.
…nd cancellation-confirmation flake (#1849) * CHAOS-4011: split the shared pgxpool so neither client starves the other Structural fix, not another flat pool-size bump. probe.go's "inserter" and "client"/worker river.Client instances shared one pgxpool (MaxConns 6). A CPU-constrained repro caught the mechanism directly: a plain job insert timing out acquiring a connection before any cancellation logic even ran ("error beginning transaction: timeout: context deadline exceeded") — the pool was exhausted by standing demand, not a race. Tracing why: inserter's Config has no Queues set, so per river@v0.40.0 client.go's willExecuteJobs() gate it never starts any background service at all — it only ever does synchronous Insert/JobCancel calls. client, by contrast, runs everything: 1 notifier (a single persistent LISTEN connection multiplexing all pub/sub — the elector and the producer's control-channel listener both ride it, not one connection each), 1 elector, 6 independent maintenance services on their own tickers (jobCleaner, jobRescuer, jobScheduler, periodicJobEnqueuer, queueCleaner, reindexer), 1 completer, and the fetch/execute loop itself. Sharing one pool meant inserter's own synchronous calls competed with all of that standing demand for the same 6 slots — and under CPU contention (this repro pinned harness containers to a shared 2-core cpuset + GOMAXPROCS=2, matching CI's ~2 vCPU runners), connections that would normally cycle fast linger longer, making that contention worse, not incidental. - Split into two pools: InserterPoolMaxConns=2 (generous for its synchronous calls; documented derivation in the constant's comment) and WorkerPoolMaxConns=10 (documented, service-by-service derivation citing the exact client.go line ranges, not a bare number — same principle as the #1843 drift guard this extends). - Updated pgbouncer-session's DEFAULT_POOL_SIZE+RESERVE_POOL_SIZE to 12 (10+2) to match. - Extended ci/check_river_compat_static.sh's drift guard to derive from both named constants (previously just poolConfig.MaxConns, which no longer exists as a single literal now that pool construction is parameterized) and assert the pooler budget covers their sum. Verified both directions: passes against the fixed values, fails with the expected message when DEFAULT_POOL_SIZE is dropped back to 5. - The two BackendConnections/NewConnections gates were hardcoded to "<= 6" independently of poolConfig.MaxConns — a second, undetected drift risk of the exact kind #1843 was meant to prevent. Rekeyed both to the same named constants (BackendConnectionDeltaAtMostSix against the combined budget, since it reads whole-database pg_stat_database; NewConnectionsAtMostSix against the worker pool alone, since that's what it measures). Wire-format JSON key names kept stable (consumed by run.sh and the static check) rather than renamed. Red/green evidence: the CPU-constrained repro that caught the pool exhaustion (10 bounded iterations, containers pinned to a shared 2-core cpuset + GOMAXPROCS=2) ran 10/10 clean after this fix, under the exact same constraint. A full real end-to-end pass (unconstrained) also passes clean. go build/vet/gofmt, shellcheck, and ci/check_river_compat_static.sh all clean. * CHAOS-4011: converge cancellation confirmation on the persisted job row Durable-truth fix, not a timing knob. probe.go's cross-client/same-client/ Release() cancellation sequence already converges deterministically without depending on NOTIFY delivery — Release() is pure in-memory, and a job cancelled through it reliably persists state=cancelled via River's own explicit river.JobCancel() routing. The one link that stayed fragile was the FINAL confirmation step: waitForEvent(..., EventKindJobCancelled), strictly filtered on River's own emitted event stream. Upstream PR riverqueue/river#1350 (the actual PR body, not just the changelog) documents a v0.40 event-routing bug matching exactly this scenario: "remote cancellation, then worker requests a retry" persists the job as cancelled but emits job_failed, not job_cancelled. A strict wait on EventKindJobCancelled can hang even though the database write was already correct — the row is the truth, the event stream just didn't reliably reflect it in this version. waitForCancelledRow replaces the single waitForEvent call: it races the event stream (used immediately when it arrives with the right kind, so the normal fast path is unchanged) against a ticker that polls client.JobGet's persisted State via River's stable public API, on the same opts.FetchPollInterval the harness already uses elsewhere for the identical class of purpose (not a new timing knob — and not "wait longer": convergence happens on whichever check sees the true state first, an event or a poll, never after some elapsed duration). Explicitly a liveness cadence, not a correctness window: it bounds how promptly a lost signal is caught, not whether it eventually is. This closes the confirmation-step gap under both v0.40 and v0.44 River semantics without depending on the version bump (CHAOS-4064, separate follow-up) to fix it. Verified: go build/vet/gofmt clean; a full real end-to-end run (all three modes, all phases) passes with the normal fast event path unchanged; combined with the pool-split commit, the CPU-constrained repro that caught the original pool-exhaustion failure ran 10/10 clean under the exact same constraint that produced it. * CHAOS-4011: redact job IDs from traces; require both pool constants codex review (P2 x2): - The cancellation-trace breadcrumb printed the River job ID directly. redact_diagnostic_stream doesn't strip it, so it would reach CI stderr verbatim — README.md's failure-log redaction contract explicitly lists River job IDs among what must not appear there. Dropped the ID from the trace line; the mode + stage name is enough context. - ci/check_river_compat_static.sh's guard piped both greps into one stream and summed whatever came out. If a rename ever silently broke one grep, jq -s add would sum only the surviving value and the non-null check would still pass — validating the pooler budget against one pool's ceiling instead of both. Extracted each constant into its own variable, require both non-empty explicitly, then sum with plain arithmetic (also drops the jq dependency for this check). Verified: shellcheck --severity=style clean on both files; static check passes on the fixed values; go build/vet/gofmt clean; full real end-to-end run passes.
Sequenced after CHAOS-4011's real fix (pool-budget structural split +
durable-truth cancellation confirmation), per the owner's ruling —
bumping first would have masked the lost-NOTIFY mechanism that fix
addresses rather than fixing it.
- go.mod/go.sum: river, riverdriver, riverdriver/riverpgxv5, rivertype,
rivershared v0.40.0 -> v0.44.0; rivercontrib/otelriver v0.11.0 ->
v0.12.0 (the latest release, targeting river v0.41.0 as its own
go.mod floor — Go's MVS resolves the shared river packages to our
higher v0.44.0 requirement; verified by building the whole repo, not
just the version bump in isolation).
- probe.go: RiverVersion/RiverDriverVersion constants bumped to
v0.44.0 (probe.go verifies these against the actual linked
dependency at runtime via debug.ReadBuildInfo, so a stale constant
fails every operation immediately — this is why direct-matrix failed
on the first local run of this change, with zero stderr output by
design: main.go deliberately keeps error detail off stderr to avoid
leaking credentials, encoding only a sanitized {status, phase} to
stdout instead). Re-verified and updated the CHAOS-4011 pool-sizing
derivation's line-number citations against v0.44.0's actual
client.go (same six maintenance services, same notifier/elector
structure — just shifted lines) rather than leaving stale references.
- run.sh: the four golden .river_version/.river_driver_version
assertions for the CURRENT-version side (direct/session matrix,
external-consume, both schema-7 N-1 orientation checks) updated to
v0.44.0. The N-1 side's three v0.39.0 assertions are untouched (that
tests River's OLD version, unrelated to this bump). The frozen
ci/evidence/go-worker-migration/v1-river-spike/local-harness-results.json
evidence artifact and its ci/check_river_compat_static.sh assertions
are also untouched — that's a point-in-time historical record of a
specific past run, not a live contract that should track the
currently-pinned version.
Event-subscription audit (v0.41-v0.44 changelog + direct source diff
against v0.40.0, not just changelog headlines):
- Upstream riverqueue/river#1350 (v0.44) fixes exactly the event-kind
routing bug CHAOS-4011 found and worked around: v0.40's
distributeJobEvent derived the emitted EventKind by switching on the
job's persisted State as read back after the write; v0.44 replaces
that with an explicit riverdriver.JobSetStateReason the completer/driver
reports directly, closing the race where a job's actual persisted
outcome could diverge from what the emitted event implied. Retires
the specific vulnerability probe.go's waitForCancelledRow works
around — but that function is kept as-is (not reverted to plain
waitForEvent): reading the persisted row is strictly more robust
than trusting the event stream regardless of which River version is
running, so there's no reason to give back a safety margin that
costs nothing on the fast path.
- Upstream riverqueue/river#1290 (v0.44, new EventKindJobInterrupted)
is unrelated to CHAOS-4011's remote-cancellation testing despite
surface-level similarity: verified via source diff that its new
isSoftStopCancelError() checks specifically for
context.Cause(ctx) == rivercommon.ErrStop (client graceful-shutdown
cancellation), which is a different, mutually exclusive cause from
rivertype.ErrJobCancelledRemotely (our JobCancel()-driven remote-cancel
path) — zero overlap with the cross-client/same-client cancellation
flow CHAOS-4011 fixed. probe.go's own `defer client.StopAndCancel()`
could theoretically hit this new path, but only if a job is still
running at that point, which normal operation never leaves.
- What the bump does NOT retire (confirmed unchanged by diffing v0.40.0
against v0.44.0 source directly, not assumed from changelog silence):
the notifier's silent exponential backoff on any listener error
(internal/notifier/notifier.go, 0.5s-64s, identical code); the total
absence of a polling fallback for remote job-cancel delivery
(producer.go's control-topic listening is still LISTEN-only); and
JobRescuer's default 1-hour RescueStuckJobsAfter window when
unconfigured (identical constant, identical default-computation).
These are exactly why CHAOS-4011's pool-budget and durable-truth
fixes are structural, not version-specific, and remain necessary
after this bump.
- Whole-codebase sweep (not just the probe): `.Subscribe(` on a
river.Client's event stream appears in exactly one place in the
entire non-test Go codebase — tests/compatibility/river/go/probe.go.
No production code path subscribes to River events at all. Production
job-outcome handling (internal/joboutbox/strand_repair.go,
terminal_delivery_repair.go) reads rivertype.JobState directly from
the persisted row — the same durable-truth pattern CHAOS-4011's fix
adopted for the probe — so it was never exposed to the #1350
event-routing ambiguity in the first place. Of probe.go's five
event-waits, only the cancellation-confirmation one (already fixed
under CHAOS-4011) was ever in the exposed shape; the other four
(execute-sample completion, recovery job failure/completion,
external-consume completion) involve no cancellation/JobCompleteTx
race and were never vulnerable.
Verified: whole-repo `go build ./...` and `go vet ./...` clean with
zero code changes required outside the three files above; full real
end-to-end river-compat harness run (all three profiles, all phases)
passes; ci/check_river_compat_static.sh clean; `ci/check_go.sh ci`
(the exact CI go-quality gate) passes, exit 0.
This one's aimed at fixing [1] in which for some sequences in workers,
we'd emit a surprising event based on the state that was actually
persisted to the database. This contract was also not stable, and
changed subtly with the introduction of #1290.
From [1], this is best illustrated by a short example where we error
after invoking
JobCompleteTx:This used to emit a
job_completed, but has changed inmasterto emita
job_failed.Here, we try to correct the emitted event and officially standardize it:
JobCompleteTxcommits, then worker returns an errorcompletedjob_failedjob_completedcancelledjob_failedjob_cancelledcancelledjob_snoozedjob_cancelledUnambiguous persisted states always take precedence, though we retain
reason (added in #1290) to distinguish possible states of
available,which may be (1) an immediate retry after failure, (2) a short snooze,
or (3) an interruption caused by client shutdown.
[1] #1290 (comment)