feat(bb-async-job): opt-in job status tracking with transition history - #281
feat(bb-async-job): opt-in job status tracking with transition history#281ahmedhamouda78 wants to merge 6 commits into
Conversation
Observing a job go from queued to processing to complete used to require padding the handler with an artificial delay. There was no status API at all, so the README told people to write their own state into a KVStore from inside the handler. That state is a single mutable value, and a handler that finishes in a millisecond passes through processing faster than any client can poll it, so the delay existed purely to widen that window. Pass trackStatus: true and AsyncJob records the lifecycle itself, into a nested DistributedTable keyed by jobId with a 24 hour TTL. Two methods read it: getStatus(jobId) for the current state plus the full history, and waitUntilComplete(jobId, options?) to await a terminal state with timeoutMs, pollIntervalMs and AbortSignal support, following the shape KnowledgeBase.waitUntilSynced already established. Transitions are appended rather than overwritten, which is what removes the race: a caller that reads the record once, after the job settled, still sees that it passed through processing. A retry appends another processing entry instead of a second terminal state, so attempt counts stay legible. Tracking is opt-in because it is not free. It adds a table per job plus a write on submit and one per transition, and it would turn submitBatch from one native SQS batch into an extra batch write. With the flag off nothing is provisioned, submit stays a single SQS call, and the status methods throw StatusNotTracked. Status writes on the handler path are logged rather than thrown: failing before the handler would retry work that was fine, and failing after it succeeded would re-run work that had already completed. Fixes #223
🦋 Changeset detectedLatest commit: c6e22f4 The changes in this PR will be included in the next version bump. This PR includes changesets to release 3 packages
Not sure what this means? Click here to learn what changesets are. Click here if you're a maintainer who wants to add another changeset to this PR |
… deployed e2e Review follow-up on three points. Concurrency. Appending a transition is a read-modify-write, and two writers really can hold the same record at once. The likely case is submit versus delivery: in AWS the job id is the SQS message id, so the queued write cannot happen until SendMessage returns, by which point SQS may already have delivered the message and the handler may already have created the record. An unconditional queued write then overwrote the processing entry and stranded a running job at queued forever, which surfaces as waitUntilComplete timing out on a job that succeeded. The rarer case is a duplicate delivery on an at-least-once queue, where two appends race and last-write-wins drops one. batchSize turned out not to be a factor, since a batch carries distinct messages and therefore distinct partition keys. Both are now guarded. Appends compare-and-swap on a version counter and retry on a lost swap; recordQueued is conditional on the record not existing and treats losing the race as success. recordQueuedBatch issues parallel conditional writes instead of a putBatch, because BatchWriteItem cannot carry a condition. Two unit tests cover it, and both fail without the guards. Deployed coverage. The mock stores the nested transitions list and the numeric fields natively, so it cannot prove they survive DynamoDB. Added a tracked AsyncJob plus a failing one to the comprehensive test app and an e2e that runs in every environment: locally against the mock, and against a real table in sandbox or production. It asserts the transition sequence, that attempt and attempts come back as numbers rather than strings, that the error string round-trips on the failed path, and that the TTL and version attributes never surface. The failing job uses maxRetries 1 so the first failure is terminal in both runtimes and the test does not depend on redrive timing. Docs. waitUntilComplete's timeout is now documented as status unknown rather than still running, since a dropped terminal write leaves a finished job without a terminal state. Added guidance to check the job's own effect when certainty is needed, a D-AJ-8 decision record for the concurrency design, and a mock parity row noting that neither a CAS retry nor a dropped write is reachable locally.
| for (let cas = 1; ; cas++) { | ||
| const existing = await this.table.get({ jobId }); | ||
| const now = new Date().toISOString(); | ||
| const base = existing ?? this.queuedRecord(jobId, now); |
There was a problem hiding this comment.
[minor] When recordTransition backfills a missing record (handler wins the race against submit()'s queued write), submittedAt gets set to now, i.e. the processing time, not the actual submission time. When recordQueued() shows up afterward it loses the conditional write (ifNotExists fails) and just gets swallowed, so that correct submittedAt is thrown away for good. The record's submittedAt/transitions[0].at end up permanently wrong for any job that hits this race, even though the README documents submittedAt as "ISO 8601 timestamp of submission."
Probably fine to leave as "time first observed" if that's the intended semantics, but worth a doc note, or alternatively have recordQueued patch just submittedAt/the first transition's at on the existing record instead of a no-op when it loses the race.
There was a problem hiding this comment.
Good catch. Went with option (b): recordQueued now corrects submittedAt and the queued transition's timestamp on the existing record when the handler wins the race, rather than no-op'ing. It reuses the same CAS-on-version pattern as the rest of the tracker and only ever moves the timestamp earlier, so it stays idempotent under SQS retries. The README semantics for submittedAt still hold. Added tests for the race (handler backfills first, then the late queued write corrects it) and confirmed they fail without the fix. Pushed in 2fbc2a5.
…e race The job id is the SQS message id, so `queued` can only be written after SendMessage returns, and the handler can create the status record first. Its backfill has to date the submission from the moment it first observed the job, which is processing time, not submission time. recordQueued then lost its conditional write and returned, so the one accurate submission time anybody held was discarded and `submittedAt` permanently reported when the job started being processed. The README documents it as the time of submission. recordQueued now corrects the record instead of no-op'ing on a lost race. It rewrites `submittedAt` and the `queued` transition together, since callers are entitled to expect `transitions[0].at` to equal `submittedAt`. The correction is a read-modify-write, so it takes the same compare-and-swap on `version` that recordTransition uses: a handler appending a transition concurrently cannot lose it to this write, nor this correction to theirs. It only ever moves the timestamp earlier, which keeps it idempotent under CAS retries and stops a duplicate write from dragging the submission forward. A record that has already been reaped is left alone rather than resurrected. Failures here are logged, not thrown. By this point the message is on the queue and the job will run, so a failed metadata fix must not turn a successful submit() into a throw.
osama-rizk
left a comment
There was a problem hiding this comment.
Excellent PR — the append-only reframe is the correct fix for #223 (not just a wider delay window), the CAS/ordering reasoning is sound, and the test suite reaches the concurrency paths the mock can't. Nothing blocking; Finding 1 is the one I'd want addressed, even if only as a doc caveat.
What I verified
Redrive alignment — this is where the feature breaks silently, so I checked it: CDK sets maxReceiveCount = maxRetries (same option, both default 3), and the handler records failed exactly when receiveCount >= maxRetries. So failed lands on the same delivery that exhausts redrive — not early (which would falsely mark a job dead mid-retry), not never.
Tests reach the paths the mock can't. The mock processes in-process and can never reproduce the AWS submit-loses-the-create-race ordering, so there are direct JobStatusTracker tests for concurrent appends not losing a transition, the late queued write not clobbering an earlier processing, backdating, and TTL-reaped records not being resurrected. And disabling the append to watch 5 tests fail is the vacuity control — proof the sequence assertions actually bite.
1. A job killed by Lambda (timeout/OOM) reaches the DLQ but never records failed
failed is only recorded inside the handler's catch. But the most common reasons a job exhausts retries and hits the DLQ are not catchable throws — Lambda timeout, OOM kill, or a process crash. In those cases the invocation is terminated by the platform, the catch never runs, no failed is written, and the record is stranded at processing until its 24h TTL. A caller then sits in waitUntilComplete until it throws Timeout (default 30s) on a job that actually died — which is exactly the "terminal state not observable" shape #223 was about, relocated from complete to failed.
This is inherent to in-handler recording (you can't catch a SIGKILL), so I'm not asking for a full fix here. But it should be explicit, because the docs currently imply failed is reliable:
- Document the gap — "
failedis recorded for handler exceptions; a job killed by Lambda timeout/OOM lands in the DLQ without afailedtransition, andwaitUntilCompletewill time out. Monitor the DLQ for those." - At minimum, have
waitUntilComplete'sTimeoutmessage hint that a timeout may mean the job died without recording — so the caller doesn't read "timeout" as "still running."
2. Both the failed decision and attempt numbers ride on ApproximateReceiveCount
ctx.receiveCount is SQS's ApproximateReceiveCount, which the SQS docs say can read higher than the true delivery count (e.g. a message becomes visible again after a visibility-timeout expiry on a long-running handler, with no real failure). Two consequences:
- The
receiveCount >= maxRetriesgate could firefaileda delivery early if the count inflated — recordingfailedwhile SQS still has a real attempt left, so a job could showfailedand then a laterprocessing/completeappended after it. The append-only model tolerates this, butstatus.statebriefly lies. attemptnumbers are therefore approximate, not a true retry count. The type doc says "delivery attempt that produced this transition" — worth softening to "approximate delivery count (SQSApproximateReceiveCount)" so nobody builds exact retry accounting on it.
Not a bug you introduced — SQS semantics — but hinging the terminal-state decision on an approximate counter deserves a comment where the >= compare lives.
3. waitUntilComplete read cost (non-blocking)
At 250ms over a 30s budget, a single wait is up to ~120 DynamoDB GetItems; N concurrent waiters multiply that. The ±20% jitter correctly prevents synchronized stampedes but not absolute volume. Inherent to poll-based waiting, and mirroring KnowledgeBase.waitUntilSynced() for one idiom is the right consistency call — keep it. Worth a doc line that a tight pollIntervalMs against many jobs has an RCU implication (ties to the G14/G18 hidden-cost reasoning the PR already invokes for opt-in).
4. Transition array is unbounded in principle (low severity)
Every delivery appends a processing, and the whole record is rewritten on each CAS. Trivial at the default maxRetries of 3, but a high maxRetries (or receive-count inflation per #2) grows the array toward DynamoDB's 400KB item ceiling. Worth knowing, not worth fixing — a one-line doc note if maxRetries can be set arbitrarily high.
Security note
Handler error messages are stored in error and returned by getStatus, persisted for 24h and readable by anyone who can call it. Probably fine for first-party use, but a one-line caution ("don't put secrets in thrown error messages; they're persisted") would match the care elsewhere.
Nits
- The mock passes
sentAttorecordQueuedwhile AWS passes a fresh timestamp at send time — functionally equivalent, but the mock always wins the create race so it can't exercise backdating (which is exactly why the direct-tracker tests exist). Noting only that happy-path mock coverage ≠ AWS-path coverage here; the author clearly knew this. - The
blocksError/err.namehelper duplicates a patternisBlocksErrorconsumes — if a sharedcreateBlocksError(name, message)exists in core, prefer it. Not worth churning otherwise.
Also: the CDK-key-type trap you found and pinned with a test (validate({jobId:0}) probing → N provisioning) is a genuinely good catch — exactly the kind of cross-layer footgun that's invisible until it bites at runtime.
…ate attempt count Review follow-ups on #281. Both are caveats on behaviour that already ships, so this is documentation only. A delivery killed by a Lambda timeout, an OOM kill, or a hard crash never unwinds through the handler's catch, so no `failed` transition is written and the record sits at `processing` for good. waitUntilComplete() then reports Timeout, which reads as status unknown rather than as the dead job it is. Recorded as a known limitation next to the existing Timeout guidance, with where to look instead (the DLQ, and the handler's own logs). Detecting it in AsyncJob is follow-up work, not part of this change. `receiveCount` is SQS's ApproximateReceiveCount, so it can move without a matching attempt, and `attempt` / `attempts` inherit that. Noted under Handler Context, including that the mock's in-process counter is exact, which is how a test asserting an exact attempt number passes locally and still breaks in AWS.
|
Good catches, both documented in c6e22f4. The killed-delivery gap is real and you described it exactly: On |
| @@ -0,0 +1,21 @@ | |||
| --- | |||
| "@aws-blocks/bb-async-job": minor | |||
There was a problem hiding this comment.
Why a minor bump? Is there a breaking change in this PR?
Fixes #223
The problem
Watching a job go from
queuedtoprocessingtocompleterequired padding the handler with an artificialsetTimeout(1500). There was no status API at all, so the README told people to write their own state into a KVStore from inside the handler, andtest-apps/comprehensivedoes exactly that plus a 20x100ms poll loop.The catch is that hand-rolled state is a single mutable value. A handler that finishes in a millisecond passes through
processingfaster than any client can poll it, so the delay was not really about notifications, it was there to widen the window enough to be caught. Any tuned value races against the reader's cadence, which is what #223 saw: intermediate states missed, or the transitions racing each other.The fix
Pass
trackStatus: trueand AsyncJob records the lifecycle itself:Two new methods:
getStatus(jobId)returns the current state plus the full transition history, ornullfor an unknown id.waitUntilComplete(jobId, options?)waits forcompleteorfailed, withtimeoutMs(default 30000),pollIntervalMs(default 250, +/-20% jitter) and anAbortSignal. It follows the shapeKnowledgeBase.waitUntilSynced()already established so there is one poll-until idiom in the repo rather than two.Transitions are appended, not overwritten. That is the part that actually removes the race: a caller reading the record once, long after the job settled, still sees that it went through
processing. No timing assumption anywhere, and nothing to tune. A retry appends anotherprocessingentry instead of a second terminal state, so attempt counts stay readable:Storage is a nested
DistributedTablekeyed byjobIdwith a 24 hour TTL, composed the same way bb-agent, bb-auth-cognito and bb-realtime already compose child blocks: identical child id and options in the runtime and CDK constructors. BecauseDistributedTablehas its own conditional exports, there is one status code path for both mock and AWS rather than two.Why opt-in
Tracking is not free. It adds a DynamoDB table per job plus a write on submit and one per transition, and it would turn
submitBatchfrom a single native SQS batch into an extra batch write, which is exactly the kind of hidden cost G14/G18 warn about. With the flag off nothing is provisioned,submit()stays a single SQS call, existing deployments gain no resources, and the status methods throwStatusNotTrackedpointing at the flag. Flipping the default on later is a non-breaking change if you would rather have it always on, so this is the reversible direction.Happy to switch it to always-on if you prefer that trade, it is a small change.
Two details worth a look
Status writes never decide a job's fate. On the handler path they are logged, not thrown. Throwing before the handler would retry work that was fine; throwing after it succeeded would re-run work that had already completed. The
queuedwrite insubmit()does propagate, since the caller explicitly asked for tracking and failing there is safe.Terminal failure is deferred to SQS. A handler error only records
failedoncereceiveCounthas reachedmaxRetries. SQS redrive owns the retry decision, so earlier failures record nothing and the next delivery just appends anotherprocessingentry.Testing
15 new tests in
packages/bb-async-job/src/status.test.ts. No handler in the file contains asetTimeout, which is the whole point: the transition-sequence assertions pass against handlers that return immediately.Covered: the queued/processing/complete sequence, reading the history only after the job settled, transition ordering and timestamps, the retry path recording
processingtwice thenfailed,queuedobservable while a job is delayed,submitBatchtracking every job,getStatusreturningnullfor an unknown id,waitUntilCompletetiming out mid-flight and then succeeding once the job finishes, rejecting with the signal's abort reason (both live and pre-aborted),StatusNotTrackedwhen the flag is off, and isolation between two tracked jobs.Two of them guard a trap I hit while writing this: the CDK layer infers a key's DynamoDB attribute type by probing
validate({ jobId: 0 })and reads "no issue for that field" as numeric, so a pass-through schema would have provisionedjobIdasNand every runtime write would have failed against it. The status schema rejects a numericjobId, and there is now a test pinning that, since per-block cdk parity is not covered byconditional-exports.test.ts.To check the tests are not toothless I disabled the append (
transitions: [transition], the old mutable-value behaviour) and re-ran: 5 of them fail. Restored, all 35 pass.Verification
npm run build:packagesnpm test -w packages/bb-async-jobnpm test -w packages/blocksnpm test(all workspaces)npm run check:apiAPI.mdregenerated vianpm run update:apiand committed for both bb-async-job and blockschangeset-guard validate-structurechangeset-guard verify-coveragechangeset-guard block-majornpm run lint/lint:depscould not run here, the bundled biome binary needs GLIBC 2.28+ and this host is older. The new dependency is declared (@aws-blocks/bb-distributed-tableindependencies,@standard-schema/specstays a devDependency as it is type-only) and the tsconfig project reference is added, so I expect it clean in CI.Changeset is
bb-async-job: minorplusblocks: patch, since the umbrella re-exports the new types and itsAPI.mdchanged too.