Skip to content

Frames can be silently double-booked onto two hosts (multi-Cuebot): RUNNING frame released without killing RQD, then re-booked #2438

Description

@DiegoTavares

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):
    1. FrameDaoJdbc.lockFrameForUpdateSELECT pk_frame FROM frame WHERE pk_frame=? AND str_state='WAITING' AND int_version=? FOR UPDATE NOWAIT
    2. 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)
    3. 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 DataIntegrityViolationExceptionResourceDuplicationFailureException (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)
clearVirtualProcAssignementUPDATE 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:

  1. Run multiple Cuebot instances against one shared Postgres, with RQD host reports load-balanced across them.
  2. 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.
  3. Cuebot deletes B's proc and resets the frame to WAITING (EXIT_STATUS_DOWN_HOST, no retry bump, no RQD kill).
  4. The booking loop re-books the WAITING frame onto Host A while RQD-B is still rendering.
  5. 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):

  1. 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.

  2. 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.)

  3. 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.

Metadata

Metadata

Assignees

No one assigned

    Labels

    bugSomething isn't working

    Type

    No type

    Fields

    No fields configured for issues without a type.

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions