Set dedupe lock timeout on CacheDeploySpecJob - #1494
Conversation
The Unique lock's Redis expiration is self.class.timeout, defaulting to 10 seconds when unset. CacheDeploySpecJob never set it, while its median runtime is over a minute: the lock expired mid-run, so on_duplicate :drop never dropped anything and duplicate jobs for the same stack piled up concurrently, each performing a redundant clone and spec evaluation. Set timeout to 15 minutes so the lock outlives the runtime and at most one spec-cache job runs per stack. Since BackgroundJob also uses timeout as a Timeout.timeout execution cap, this additionally stops pathological runs from squatting on a worker thread indefinitely, preserving the invariant that execution never outlives the lock (as GithubSyncJob already does with timeout = 60). Trade-off: a worker killed mid-run (e.g. OOM) leaves the lock held until expiry, delaying that stack's next spec refresh by up to 15 minutes. The next push re-enqueues regardless.
bd21220 to
3eadede
Compare
5a7c4a5 to
47daa31
Compare
timothysmith0609
left a comment
There was a problem hiding this comment.
Approving. The diagnosis is well-evidenced and I verified it against BackgroundJob::Unique — expiration: self.class.timeout || DEFAULT_TIMEOUT with no timeout set really does give a 10s lock over a ~65s job, so the dedupe was protecting the first 15% of every run. The GithubSyncJob precedent for "execution can never outlive the lock" is the right invariant to point at.
Two notes, one of which I'd like to see land close behind this.
🔴 Combined with #1495, this removes the self-healing property
Neither PR causes this alone; together they produce a state where the cached spec is stale with no outstanding work to fix it:
t=0— push A → J1 starts, reads head = A, holds the lock for its full ~65s runtime (previously 10s).t=30s— push B changesshipit.yml→GithubSyncJobsees head movement → enqueues J2. J2'sacquire_lockhits the held lock,on_duplicate :dropswallows it, the job reports success.t=65s— J1 writes the spec for head A.- Afterwards — every no-op sync now returns early (#1495: head unchanged +
cached_deploy_spec.present?). Stale until the next head movement or a manual Refresh.
Before this stack there were two nets: the 10s lock meant J2 almost always ran, and every sync re-cached unconditionally so a miss self-healed on the next webhook. This PR widens the drop window from 10s to the whole runtime (p99 42 min under contention); #1495 removes the net that used to catch it.
I don't think that should block this PR — the concurrency fix is clearly worth more than the freshness regression, and the regression is bounded by the next push. But the smallest fix is a few lines and could ride along:
def perform(stack)
return if stack.inaccessible?
commit = stack.commits.reachable.last
stack.update!(cached_deploy_spec: Commands.for(stack).cacheable_deploy_spec(commit:))
# A duplicate enqueued while we held the lock was dropped; if the head moved
# under us, that dropped job's work is still outstanding.
CacheDeploySpecJob.perform_later(stack) if stack.commits.reachable.last&.id != commit&.id
endThe more durable version: persist the sha the spec was computed from and make #1495's skip condition compare against that rather than cached_deploy_spec.present?. That makes the whole thing self-healing and also fixes the refresh race I flagged on #1495. Migration-first, so probably a follow-up rather than a change here.
🟢 The Timeout.timeout side is a small new failure mode, not only a benefit
Timeout::Error is raised asynchronously from a watchdog thread at an arbitrary point in the job. Dir.mktmpdir's ensure cleans up the directory, but Shipit::Command spawns via PTY, so a raise at the wrong instant can orphan a git clone child. GithubSyncJob already accepts this, so it's fine — just worth naming in the trade-offs section alongside the delayed-refresh one, since "hard-caps pathological runs" reads as unambiguously good right now.
🟢 Test nit
The duplicate-drop test exercises Redis::Lock but not the around_perform wiring, and neither test pins the thing the PR is actually about — that the lock's expiration is now 900 rather than 10. Asserting Redis::Lock receives expiration: 900 would nail it directly. The timeout > DEFAULT_TIMEOUT assertion covers the intent well enough that I wouldn't hold the PR for it.
With the dedupe lock now covering the full runtime, a job enqueued for a newer head while an older run is in flight is dropped, and the conditional enqueue in GithubSyncJob no longer re-caches on the next no-op sync. Together that could leave the cached spec stale until the next head movement. Hand off the dropped job's work at the end of the run instead. Also pins the Redis lock expiration in a test and covers both re-enqueue directions.
|
Addressed in
The durable version (persist the computed sha, make the skip condition exact) is deliberately deferred — migration-first, and it obsoletes both this band-aid and the refresh fix on #1495; tracked as a follow-up. |
Stacked on #1493.
What
Set
self.timeout = 15.minutes.to_ionCacheDeploySpecJob.Why
The job declares
on_duplicate :drop, but the dedupe is backed by a Redis lock whose expiration isself.class.timeout || DEFAULT_TIMEOUT— and this job never set a timeout, so the lock evaporates after 10 seconds while the job's median runtime is ~65 seconds.Result: the dedupe only protects the first 10 seconds of every run. After that, each newly enqueued job for the same stack finds the lock free and starts a full clone alongside the still-running one. Under sustained push volume this is unbounded per-stack concurrency — in shipit-production this job piled up to ~130 concurrent worker threads (from <1 in healthy state), starving
PerformTaskJobon the shareddeploysqueue and driving the workers' memory to the cgroup limit (chronic OOMKills, ~48 restarts/hour).With the lock outliving the runtime, duplicates arriving mid-run are dropped in microseconds and at most one spec-cache job runs per stack, which is all the freshness this cache needs.
The dual effect of
timeoutBackgroundJob#performalso usestimeoutas aTimeout.timeoutexecution cap, so this change additionally hard-caps runs at 15 minutes. That's the same invariantGithubSyncJobalready maintains (self.timeout = 60): execution can never outlive the lock, which is what makes the dedupe sound. It also stops pathological runs (p99 was 42 minutes under contention) from squatting on worker threads.Trade-offs
Tests
Unique::DEFAULT_TIMEOUTand equals 15 minutes.