Describe the bug
A single frame can end up rendering on two hosts simultaneously with no indication in CueGUI — the surviving record shows the frame SUCCEEDED with 0 retries and normal logs. The only externally visible symptom is corrupted output (two processes writing the same image) and the presence of an extra …rqlog.1 log file for a frame that supposedly never retried.
In an observed production incident (3 Cuebot instances against one shared Postgres):
- Frame X was booked on Host B.
- ~5 seconds later the same frame was booked on Host A, which went on to SUCCEED and own the DB record.
- Host B's process kept rendering and was eventually killed with
FrameVerificationFailure ("…but the DB did not reflect this"), but only after it had already corrupted an output EXR (a downstream frame then failed, and itview could not open the image).
- The frame showed 0 retries and looked completely normal in CueGUI; the only trace of the second run was an
…rqlog.1 file.
Root cause — it is not a reservation race
It's tempting to assume two Cuebots reserved the same WAITING frame at the same instant. On a shared database that race is already closed, so it is not the cause:
DispatchSupportService.startFrameAndProc runs three guards in one transaction, before RQD is ever contacted (runFrame is @Transactional(NEVER), called only after commit):
FrameDaoJdbc.lockFrameForUpdate → SELECT pk_frame FROM frame WHERE pk_frame=? AND str_state='WAITING' AND int_version=? FOR UPDATE NOWAIT
- optimistic
UPDATE frame SET str_state='RUNNING', int_version=int_version+1 WHERE pk_frame=? AND str_state='WAITING' AND int_version=? (FrameDaoJdbc.java, UPDATE_FRAME_STARTED)
- a
UNIQUE constraint on proc(pk_frame) — c_proc_uk (V1__Initial_schema.sql:1181,1507); insertVirtualProc inserts a non-null pk_frame, so a second proc for the same frame raises DataIntegrityViolationException → ResourceDuplicationFailureException (ProcDaoJdbc.java).
For both RQDs to launch, both transactions must have committed, and c_proc_uk makes that impossible at the same time. Therefore the two procs existed at different times — the first proc was removed/cleared before the second was created.
The bug is a free-then-rebook: a RUNNING frame is released back to a bookable state while its RQD keeps rendering, then is legitimately re-booked onto another host.
Multiple code paths reset a running frame to WAITING and/or delete its proc, and none of them kill RQD first:
| Path |
Effect |
Frame → WAITING |
Proc cleared/deleted |
Kills RQD? |
Bumps retry? |
DispatchSupportService.lostProc (host marked DOWN via MaintenanceManagerSupport.clearDownProcs; orphaned via clearOrphanedProcs; failed kills) |
unbookProc + updateFrameStopped(WAITING) / updateFrameHostDown |
Yes |
Yes (DELETE) |
No |
No (EXIT_STATUS_DOWN_HOST) |
clearVirtualProcAssignement → UPDATE proc SET pk_frame=NULL (CLEAR_VIRTUAL_PROC_ASSIGN, ProcDaoJdbc.java) |
frees the unique slot |
No (frame stays RUNNING) |
clears slot |
No |
No |
HostReportHandler.verifyRunningFrameInfo orphan branch |
clearVirtualProcAssignement + unbookProc |
No |
Yes |
best-effort |
No |
The code's own comment states the trigger (HostReportHandler.java, in verifyRunningFrameInfo):
"The main reason why a proc no longer exists is that the cue thought the host went down and cleared out all running frames."
A single transient "unreachable"/DOWN report is enough — changeHardwareState writes host hardware state straight from the report. The cleanup deletes the proc and resets the frame to WAITING using EXIT_STATUS_DOWN_HOST, which does not increment retries (hence "0 retries, looks normal"), and never sends RQD a kill. The booking loop then re-dispatches the now-WAITING frame elsewhere.
Why running 3 Cuebots makes it worse: RQD reports are load-balanced across instances, so the "host looks down" report, the proc-clear, and the re-book can each be handled by a different, stateless Cuebot with a slightly stale view. The only coordination point is the DB, and the DB guards protect reservation, not release.
Why the existing safety net is too slow: verifyRunningFrameInfo is deliberately lenient — a 120s grace (FRAME_VERIFICATION_GRACE_PERIOD_SECONDS) before it tests anything, and its orphan-clear branch additionally requires isOrphan = no ping for 300s (IS_ORPHAN, ProcDaoJdbc.java). A zombie RQD can therefore run for 2–5+ minutes — long enough to corrupt output — before being killed.
To Reproduce
Hard to reproduce deterministically (timing/race dependent), but the conditions are:
- Run multiple Cuebot instances against one shared Postgres, with RQD host reports load-balanced across them.
- Have a host (B) running a frame transiently appear DOWN/unreachable to Cuebot (network blip, brief GC pause, dropped report) — or otherwise trigger one of the proc-clearing paths above (
lostProc / orphan-clear) while RQD-B is still alive and rendering.
- Cuebot deletes B's proc and resets the frame to WAITING (
EXIT_STATUS_DOWN_HOST, no retry bump, no RQD kill).
- The booking loop re-books the WAITING frame onto Host A while RQD-B is still rendering.
- Both RQDs write the same output → corruption. Cuebot eventually kills B via
FrameVerificationFailure, but only after the 120s/300s windows.
Expected behavior
A frame must never be returned to a bookable state while a real RQD process is still executing it. Releasing a frame for re-booking should be gated on RQD being confirmed dead (or provably unreachable), and a returning "zombie" RQD should be detected and killed deterministically and immediately — not after multi-minute grace/ping windows.
Version Number
Affects current master (Java Cuebot dispatcher). Observed against a 3-Cuebot deployment on a shared Postgres.
Additional context
Suggested fixes (in order of leverage):
-
Kill-before-release (the actual prevention). Make every free path (lostProc, clearVirtualProcAssignement, the verifyRunningFrameInfo orphan-clear branch) issue an RQD kill for (host, frameId, resource_id) before deleting the proc / resetting the frame. For a reachable host (the dangerous flapping case) the frame stops before becoming rebookable → no double render. For a genuinely dead host the kill times out, but then there is no live RQD, so release is safe. This is where the asymmetry lives today: the book side is fully guarded, the unbook side simply walks away.
-
Strict fencing using the proc id. resource_id is the proc id, regenerated per booking (ProcDaoJdbc, genKeyRandom()) and round-tripped through RunFrame / RunningFrameInfo / FrameCompleteReport. In verifyRunningFrameInfo, when a reported running frame's resource_id maps to no live proc, or to a proc whose frame/host now differs (frame provably owned elsewhere), that RQD is unambiguously a zombie → kill immediately, skipping the 120s grace and 300s isOrphan ping wait. The grace period should only shield the current proc's book→first-report propagation, never a frame demonstrably running under a different proc. (This is the "database fields to eliminate multiple Cuebots handing out the same frames" idea noted in TSC 2022-01-19 — the field largely already exists as resource_id.)
-
Complementary / structural. Host→Cuebot affinity (route a host's reports and bookings consistently to one instance) removes the cross-instance stale-view interleaving. The Rust scheduler already eliminates this class structurally (single-writer-per-cluster + pg_try_advisory_xact_lock(hashtext(host_id)) + INSERT … ON CONFLICT (pk_frame) DO NOTHING), so accelerating that migration is the durable answer.
Note: raising transaction isolation (e.g. SERIALIZABLE) or adding more locks around the reservation path will not fix this — that path is already correct; the gap is on the release path.
To confirm the exact trigger from logs, grep around the booking of the affected frame on the first host for: "cleared:" / "is #… cleared" (lostProc), "Removed by maintenance, orphaned" (clearOrphanedProcs), or a HardwareState … DOWN host-state-change event immediately preceding the second host's booking.
Describe the bug
A single frame can end up rendering on two hosts simultaneously with no indication in CueGUI — the surviving record shows the frame SUCCEEDED with 0 retries and normal logs. The only externally visible symptom is corrupted output (two processes writing the same image) and the presence of an extra
…rqlog.1log file for a frame that supposedly never retried.In an observed production incident (3 Cuebot instances against one shared Postgres):
FrameVerificationFailure("…but the DB did not reflect this"), but only after it had already corrupted an output EXR (a downstream frame then failed, anditviewcould not open the image).…rqlog.1file.Root cause — it is not a reservation race
It's tempting to assume two Cuebots reserved the same WAITING frame at the same instant. On a shared database that race is already closed, so it is not the cause:
DispatchSupportService.startFrameAndProcruns three guards in one transaction, before RQD is ever contacted (runFrameis@Transactional(NEVER), called only after commit):FrameDaoJdbc.lockFrameForUpdate→SELECT pk_frame FROM frame WHERE pk_frame=? AND str_state='WAITING' AND int_version=? FOR UPDATE NOWAITUPDATE frame SET str_state='RUNNING', int_version=int_version+1 WHERE pk_frame=? AND str_state='WAITING' AND int_version=?(FrameDaoJdbc.java,UPDATE_FRAME_STARTED)UNIQUEconstraint onproc(pk_frame)—c_proc_uk(V1__Initial_schema.sql:1181,1507);insertVirtualProcinserts a non-nullpk_frame, so a second proc for the same frame raisesDataIntegrityViolationException→ResourceDuplicationFailureException(ProcDaoJdbc.java).For both RQDs to launch, both transactions must have committed, and
c_proc_ukmakes that impossible at the same time. Therefore the two procs existed at different times — the first proc was removed/cleared before the second was created.The bug is a free-then-rebook: a RUNNING frame is released back to a bookable state while its RQD keeps rendering, then is legitimately re-booked onto another host.
Multiple code paths reset a running frame to WAITING and/or delete its proc, and none of them kill RQD first:
DispatchSupportService.lostProc(host marked DOWN viaMaintenanceManagerSupport.clearDownProcs; orphaned viaclearOrphanedProcs; failed kills)unbookProc+updateFrameStopped(WAITING)/updateFrameHostDownEXIT_STATUS_DOWN_HOST)clearVirtualProcAssignement→UPDATE proc SET pk_frame=NULL(CLEAR_VIRTUAL_PROC_ASSIGN,ProcDaoJdbc.java)HostReportHandler.verifyRunningFrameInfoorphan branchclearVirtualProcAssignement+unbookProcThe code's own comment states the trigger (
HostReportHandler.java, inverifyRunningFrameInfo):A single transient "unreachable"/
DOWNreport is enough —changeHardwareStatewrites host hardware state straight from the report. The cleanup deletes the proc and resets the frame to WAITING usingEXIT_STATUS_DOWN_HOST, which does not increment retries (hence "0 retries, looks normal"), and never sends RQD a kill. The booking loop then re-dispatches the now-WAITING frame elsewhere.Why running 3 Cuebots makes it worse: RQD reports are load-balanced across instances, so the "host looks down" report, the proc-clear, and the re-book can each be handled by a different, stateless Cuebot with a slightly stale view. The only coordination point is the DB, and the DB guards protect reservation, not release.
Why the existing safety net is too slow:
verifyRunningFrameInfois deliberately lenient — a 120s grace (FRAME_VERIFICATION_GRACE_PERIOD_SECONDS) before it tests anything, and its orphan-clear branch additionally requiresisOrphan= no ping for 300s (IS_ORPHAN,ProcDaoJdbc.java). A zombie RQD can therefore run for 2–5+ minutes — long enough to corrupt output — before being killed.To Reproduce
Hard to reproduce deterministically (timing/race dependent), but the conditions are:
lostProc/ orphan-clear) while RQD-B is still alive and rendering.EXIT_STATUS_DOWN_HOST, no retry bump, no RQD kill).FrameVerificationFailure, but only after the 120s/300s windows.Expected behavior
A frame must never be returned to a bookable state while a real RQD process is still executing it. Releasing a frame for re-booking should be gated on RQD being confirmed dead (or provably unreachable), and a returning "zombie" RQD should be detected and killed deterministically and immediately — not after multi-minute grace/ping windows.
Version Number
Affects current
master(Java Cuebot dispatcher). Observed against a 3-Cuebot deployment on a shared Postgres.Additional context
Suggested fixes (in order of leverage):
Kill-before-release (the actual prevention). Make every free path (
lostProc,clearVirtualProcAssignement, theverifyRunningFrameInfoorphan-clear branch) issue an RQD kill for(host, frameId, resource_id)before deleting the proc / resetting the frame. For a reachable host (the dangerous flapping case) the frame stops before becoming rebookable → no double render. For a genuinely dead host the kill times out, but then there is no live RQD, so release is safe. This is where the asymmetry lives today: the book side is fully guarded, the unbook side simply walks away.Strict fencing using the proc id.
resource_idis the proc id, regenerated per booking (ProcDaoJdbc,genKeyRandom()) and round-tripped throughRunFrame/RunningFrameInfo/FrameCompleteReport. InverifyRunningFrameInfo, when a reported running frame'sresource_idmaps to no live proc, or to a proc whose frame/host now differs (frame provably owned elsewhere), that RQD is unambiguously a zombie → kill immediately, skipping the 120s grace and 300sisOrphanping wait. The grace period should only shield the current proc's book→first-report propagation, never a frame demonstrably running under a different proc. (This is the "database fields to eliminate multiple Cuebots handing out the same frames" idea noted in TSC 2022-01-19 — the field largely already exists asresource_id.)Complementary / structural. Host→Cuebot affinity (route a host's reports and bookings consistently to one instance) removes the cross-instance stale-view interleaving. The Rust scheduler already eliminates this class structurally (single-writer-per-cluster +
pg_try_advisory_xact_lock(hashtext(host_id))+INSERT … ON CONFLICT (pk_frame) DO NOTHING), so accelerating that migration is the durable answer.Note: raising transaction isolation (e.g. SERIALIZABLE) or adding more locks around the reservation path will not fix this — that path is already correct; the gap is on the release path.
To confirm the exact trigger from logs, grep around the booking of the affected frame on the first host for:
"cleared:"/"is #… cleared"(lostProc),"Removed by maintenance, orphaned"(clearOrphanedProcs), or aHardwareState … DOWNhost-state-change event immediately preceding the second host's booking.