Repository navigation
Description
Summary
When the lock of a running orchestration turn expires, nothing stops the turn. It runs to its end and only then finds out, because the provider rejects its commit. In the meantime another dispatcher slot can fetch the instance and replay it. That slot can be in the same process. So two replays of one instance can be alive in one process at the same time.
The provider keeps the stored data safe: the commit of the replay without the lock is rejected. But the overlap is a trap for any code that keeps per-instance state in the process.
The Node.js and Python SDKs had such a bug (microsoft/duroxide-node#17, microsoft/duroxide-python#17). A context map keyed by instance ID let the old replay write KV changes into the context of the new replay. The new replay held a valid lock and committed them. The next replay failed with nondeterministic: kv set mismatch.
Where
spawn_orchestration_lock_renewal_task: on any renewal error the task logs atdebuglevel and stops. The turn is not told.duroxide/src/runtime/dispatchers/orchestration.rs
Lines 319 to 328 in 6a45886
Err(e) => { tracing::debug!( target: "duroxide::runtime::dispatchers::orchestration", lock_token = %token, error = %e, "Failed to renew orchestration lock (may have been acked/abandoned)" ); // Stop renewal - lock is gone or expired break; } - The dispatcher loop: each slot fetches on its own. Nothing checks whether this runtime still runs a turn for the same instance.
duroxide/src/runtime/dispatchers/orchestration.rs
Lines 388 to 482 in 6a45886
loop { // Check shutdown flag before fetching if shutdown.load(Ordering::Relaxed) { // debug!("Orchestration worker {} exiting", worker_id); break; } let min_interval = rt.options.dispatcher_min_poll_interval; let poll_timeout = rt.options.dispatcher_long_poll_timeout; let start_time = std::time::Instant::now(); let mut work_found = false; match rt .history_store .fetch_orchestration_item( rt.options.orchestrator_lock_timeout, poll_timeout, cap_filter.as_ref(), ) .await { Ok(Some((item, lock_token, attempt_count))) => { // Reset error counter on success consecutive_retryable_errors = 0; // Runtime-side compatibility check (defense-in-depth). // Even if the provider filter missed this item (bug, provider ignoring filter), // we validate the pinned version before attempting replay. // The pinned version is extracted from the OrchestrationStarted event // (always event_id=1, always a known event type on any version). let pinned_version = item.history.iter().find_map(|e| { if matches!(&e.kind, crate::EventKind::OrchestrationStarted { .. }) { semver::Version::parse(&e.duroxide_version).ok() } else { None } }); if let Some(pinned) = pinned_version && !supported_range.contains(&pinned) { tracing::warn!( target: "duroxide::runtime", instance = %item.instance, pinned_version = %pinned, supported_range = %format!(">={}, <={}", supported_range.min, supported_range.max), attempt_count = attempt_count, "Execution pinned at incompatible version, abandoning (runtime-side check)" ); // Abandon with a short delay to prevent tight spin loops when // a single runtime encounters incompatible items. The item still // reaches max_attempts quickly (e.g., 10 × 1s = 10s) while // avoiding CPU burn and starvation of compatible work items. let _ = rt .history_store .abandon_orchestration_item(&lock_token, Some(Duration::from_secs(1)), false) .await; continue; } // pinned_version == None means no history yet (brand new instance) // — always compatible, proceed normally. // Spawn lock renewal task for this orchestration let renewal_handle = spawn_orchestration_lock_renewal_task( Arc::clone(&rt.history_store), lock_token.clone(), rt.options.orchestrator_lock_timeout, rt.options.orchestrator_lock_renewal_buffer, Arc::clone(&shutdown), ); // TEST HOOK: Inject delay after spawning renewal task // This simulates slow processing to test lock renewal #[cfg(feature = "test-hooks")] if let Some(delay) = crate::runtime::test_hooks::get_orch_processing_delay(&item.instance) { tracing::debug!( instance = %item.instance, delay_ms = delay.as_millis(), "Test hook: injecting orchestration processing delay" ); tokio::time::sleep(delay).await; } // Process orchestration item atomically // Provider ensures no other worker has this instance locked rt.process_orchestration_item(item, &lock_token, attempt_count, &worker_id) .await; // Stop lock renewal task now that orchestration turn is complete renewal_handle.abort(); work_found = true; }
How the lock gets lost
- The process stalls for longer than
orchestrator_lock_timeout(5 s by default). Causes are memory pressure, a long pause of the process, CPU starvation, or a suspended VM. - One renewal call fails or is slow. With a 5 s lock the renewal runs every 3 s, and the renewal task stops at the first error. One miss is enough.
How this was checked
The regression tests in the two SDK PRs reproduce the overlap. The test process stops itself (SIGSTOP) for 7 s in the middle of a turn, with 2 dispatcher slots and the default 5 s lock. After it continues, the old replay and a new replay of the same instance run at the same time in one process.
Suggested fix
- Retry a failed renewal while the lock can still be valid. Do not stop at the first retryable error.
- Tell the turn when its lock is lost. At least skip the commit, its logs and its metrics. Better: cancel the turn.
- Keep a set of the instances that are in flight in this runtime. A slot that fetches an instance from that set abandons the item with a short delay and does not start a second replay.
- Log a lost lock at
warnlevel, with the instance ID.
Tracked in #55.
Activity