UNOMI-967: Harden clustered scheduler locks, recovery, and tests - #830
Merged
Conversation
Fix peer lock wipe and terminal OCC races, executor-aware recovery, exclusive defaults, shutdown orphan locks, and expand manager/multi-node unit coverage plus scheduler manual docs.
Fixes two critical concurrency bugs and five secondary issues found in review of the clustered scheduler locking hardening: - TaskLockManager.releaseLock() used a blind overwrite to clear locks, leaving a TOCTOU window where it could wipe a peer's freshly acquired lock; it now goes through compare-and-set via a new shutdown-aware SchedulerServiceImpl.saveTaskWithRefresh(task, allowDuringShutdown) overload. - SchedulerServiceImpl.preDestroy() discarded the return value of the shutdown-time CRASHED-state persist and logged failures at DEBUG with no stack trace; both now surface at WARN. - Deduplicated OCC seq_no/primary_term copy logic between TaskExecutionManager and TaskRecoveryManager into TaskLockManager.copyOccMetadata(). - Logged previously-swallowed persistence failures in TaskLockManager.releaseLock(), TaskExecutionManager.persistTerminalState(), and TaskRecoveryManager's resume/restart safety-net saves. - Fixed an orphaned javadoc block in TaskExecutionManager and a stale troubleshooting entry in the scheduler manual that contradicted the documented allowParallelExecution default. - Added TaskLockManagerTest#testPeerStealDuringVerificationWindowIsNotClobberedByLoser and SchedulerServiceClusterRaceTest#testConcurrentShutdownRacingPeerRecoveryDoesNotDoubleDispatch to cover the two race windows called out in review but not previously under test. Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com>
The 10-iteration full-suite flakiness check (run against fc8186a) found SchedulerServiceClusterRaceTest#testLockStealAfterExpiryUsesOccAndSingleWinner failing ~20% of the time with two nodes both executing the same exclusive task. Isolated 30-run comparisons against the pre-fix baseline commit (0/30 failures) confirmed this was a real regression, not pre-existing flakiness. Root cause: TaskExecutionManager.createTaskWrapper()'s cleanup finally block unconditionally did a blind saveTask(task) to clear executingNodeId, even when this node's own terminal transition had been correctly skipped because a peer already reclaimed/restarted the task. That blind write clobbered the peer's newer state with this node's stale local view (status still RUNNING), reviving an already-resolved race and letting the peer's restart re-dispatch and double-execute. This block predates this PR's changes, but the previous commit's CAS-based releaseLock() changed the surrounding timing enough to make the pre-existing window trigger far more often. Fix: clear executingNodeId via saveTaskWithRefresh() (CAS) instead of a blind overwrite, so a stale write now fails harmlessly instead of clobbering a peer's progress. Verified with 30 more isolated runs (1/30 failures, down from 6/30 — consistent with baseline-level flakiness rather than a regression). Updated two TaskExecutionManagerTest assertions that expected the old "never called" behavior. Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com>
…eal race testLockStealAfterExpiryUsesOccAndSingleWinner still failed ~1/30 after the CAS release/cleanup fixes: a peer's recovery could legitimately steal an expired lock while the original holder was still genuinely executing, because a fixed-timeout lease cannot distinguish "owner died" from "execution ran longer than lockTimeout". Blocking on executingNodeId instead would strand tasks from truly-dead nodes forever, so the ambiguity is removed at the source: while a node executes a persistent exclusive task it now heartbeats the lock. TaskExecutionManager schedules a periodic TaskLockManager.renewLock() (interval max(100ms, lockTimeout/3)) that fresh-reads the store, verifies ownership, and CAS-refreshes lockDate, syncing the renewed date and post-save OCC tokens back onto the executing task. Lock expiry now only ever means the owner actually stopped renewing: renewal deliberately uses the shutdown-sensitive load/save paths so locks age out normally once shutdown begins and peers can recover the work. Renewal is stopped (with an in-flight-tick handshake) before every terminal transition's fresh OCC read — a renewal write landing after that read would advance the store version, fail the terminal compare-and-set, and strand a finished task as RUNNING. Verification: target test 30/30 green in isolated runs (previously ~1/30 failing); full scheduler suite 190/190 green including 5 new renewLock unit tests. Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
…s in-memory double rewrite Base commit 166ee60 rewrote InMemoryPersistenceServiceImpl's save() to only enforce OCC when alwaysOverwrite=false (matching real ES/OS, where plain save(item) defaults to a blind overwrite and never sends if_seq_no/ if_primary_term). Three unit tests broke as a result and were mistakenly carried forward as 'known pre-existing flaky tests, out of scope' in this branch's handoff notes - they are not pre-existing relative to master and must be fixed before merge: - shouldRejectUpdateWithIncorrectSequenceNumber / shouldRejectUpdateWithIncorrectPrimaryTerm: called plain save(), which is no longer OCC-enforced. Switched to the save(item, false, false) overload, matching how PersistenceSchedulerProvider.saveTaskCompareAndSet() actually invokes it. - shouldAllowUpdateWithCorrectSequenceNumberAndPrimaryTerm: was passing vacuously via blind-put rather than exercising the CAS success path; switched to the same explicit overload. - Added shouldBlindlyOverwriteRegardlessOfSequenceNumberByDefault to lock in the other side of the contract: plain save() must keep succeeding on a stale seq_no, since TaskLockManager and other legacy callers depend on it. Guards against a future 'fix' reintroducing this branch's double-execution regression by re-enforcing OCC on the default overload. - SegmentServiceImplTest.testCustomEventConditionTypeWithBooleanParent: root-caused via bisection (confirmed by temporarily no-op'ing the new deepCopyItem(), which flips the test back to green) plus an Explore-agent trace of the segment-membership code path. Not an identity bug in production code or the double: the test was already relying on implicit, incidental timing to clear the 1s refresh-delay simulation window without ever calling persistenceService.refresh() after eventService.send() - every sibling test in this file that aggregates over a just-sent event does call it. deepCopyItem()'s added Java-serialization overhead simply shifted that latent race to fail deterministically. Fixed by adding the same refresh() call already used by sibling tests in this file. Verification: full services module suite 790/790 green (was 789 run / 3 failing before this commit). Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
…n teardown Manual docs now cover heartbeat renewal, refresh-interval timing limits, and pool sizing. clear-*.sh also unset UNOMI_DISTRIBUTION so they fully reverse setup-*.sh.
…rvation ITs were logging sustained, once-per-second 'Lock verification failed for task ... after CAS; releasing if still owned' WARNs for the same task IDs throughout a run. Root cause: scheduler.thread.poolSize defaults to 5, sized for the near-instant in-memory unit-test double, not a single Karaf node driving a real ES/OS backend. The task checker (runs every 1s), every task execution, and every lease-renewal heartbeat (added last session) all share that one pool. Under real IT latency the pool can saturate, starving a task's heartbeat; its lock then genuinely ages past lockTimeout even though the execution is still alive, so TaskRecoveryManager.recoverRunningTasks() (checkTasks() -> every tick) legitimately reclaims it via a fresh CAS - which then loses verification against the original execution's own delayed write once the pool frees up, and the cycle repeats every tick. No evidence of actual double-execution was found (the CAS protocol fails closed as designed), but the starved retries are a real liveness cost and exactly the operational bound documented in scheduler.adoc's 'Renewal timing limits' section. Widened the IT-only pool size override (org.apache.unomi.scheduler.thread.poolSize=10) using the same etc/custom.system.properties mechanism already used for other IT tuning (rollover.maxDocs, taskWaitingPollingInterval, etc.). Verified: itests module compiles clean against this change (mvn -pl itests -P integration-tests test-compile). Full IT suite run not yet performed by this session - please re-run and confirm the WARN spam is gone. Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
Full reactor unit test run (1304 tests, 0 failures/errors) reviewed for unexpected results and noisy warnings. No test failures found; the only build failure was the pre-existing, unrelated karaf-maven-plugin:verify issue on downstream KAR/feature modules (documented in CLAUDE.md as known stale-build-state noise, not a regression). Two warning sources fixed after ranking WARN frequency across the full run: - ConditionContextHelper: a mismatch against a custom/registry-only parameter type (e.g. "comparisonOperator", validated in production by ComparisonOperatorValueTypeValidator via OSGi DS) was always logged at WARN even when no validator was registered to actually confirm the mismatch (e.g. plain unit tests with no OSGi container). Since AbstractMultiTypeCachingService builds and evaluates this exact condition on every tenant-scoped cache load, this fired constantly. Added a KNOWN_PRIMITIVE_TYPES set matching what isTypeCompatible() can actually judge; only WARN when the expected type is one of those (a confirmed mismatch), DEBUG otherwise (inconclusive, not confirmed). Verified: persistence-spi 132/132, services 790/790, 0 remaining occurrences of the message (was recurring dozens of times per run). - GoalsServiceImplTest: an anonymous ActionType subclass declared inside an instance method implicitly captured a reference to the enclosing (non-Serializable) test class, so InMemoryPersistenceServiceImpl's Java-serialization-based deep copy failed with NotSerializableException and silently fell back to sharing the live instance instead of an isolated copy - a real, if minor, test-isolation gap the log surfaced, not just log spam. Fixed by extracting it to a named static nested class (GoalMatchedActionType), which has no implicit outer reference. Verified: 5/5 tests pass, warning no longer occurs. Other frequent warnings surveyed (OCC conflicts, lock CAS races, invalid IP/date parsing, unresolved condition/action types, schema validation errors) are deliberate test-scenario signal - the same log lines that would fire in production for the same conditions - and were left as-is. Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
testUserAgentDetectionPerformance ran 25,000,000 parseUserAgent() calls (5 batches of 5M) through a 3000-thread pool with no assertions at all - just logged elapsed time. This made it one of the slowest tests in the whole reactor while verifying nothing (a broken parser would still pass as long as it didn't throw). Replaced with testUserAgentDetectionUnderConcurrency: 200 parses across 20 threads, asserting every concurrent result is correctly parsed - a correctness- under-concurrency check instead of an unbounded, assertion-free benchmark. Runtime for the whole test class dropped from (unmeasured, but on the order of minutes given the iteration count) to ~3 seconds. testFirstUserAgentDetection previously only logged agent.toString() with no assertions. Verified real parser output (Yauaa) for the existing mobile UA string and a newly added desktop UA string, then asserted on the actual parsed fields (browser name/version, OS, device category/brand/name) for both. Also fixed UserAgent.toString(): it built a StringBuffer but returned super.toString() instead of it, so the diagnostic log lines in this test have never actually shown parsed field values. Verified: 3/3 tests pass, full module suite green. Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
testRunOnAllNodesExecutesOnEveryNodeWithIsolatedViews asserted status equality across nodes immediately after a 200ms-period task's first execution round completed. Parallel-execution tasks (forced by runOnAllNodes()) give each node an independent, uncoordinated status write with no cross-node synchronization point, so the assertion could observe one node mid RUNNING->SCHEDULED transition while another had already landed - intermittent, not a real product bug. Cancel the task on all three nodes right after the completion latch fires: cancellation is idempotent and terminal, so it converges every node on the same shared-store status before the isolation assertions run, without weakening what the test actually verifies (per-node deep-copy isolation, not real-time status sync). Verified with 15 repeated isolated runs, 0 failures.
166ee60 flipped TaskBuilder's default allowParallelExecution from true to false, so this one-shot async reassign task started going through full exclusive distributed locking with no opt-out. Unlike a periodic task, a one-shot task has no natural retry if its single lock-acquisition attempt loses a transient race, which was causing ProfileMergeIT timeouts waiting for the background rewrite. The underlying operation (bulk update-by-query-and-script / anonymizeBrowsingData) is idempotent, so exclusivity buys nothing here while adding a real risk of the rewrite silently never running.
…y paths Root-causing the live-IT-only "Lock verification failed... after CAS" WARN spam (continuous for an entire test run, not intermittent noise as previously assumed) required visibility this branch didn't have: the in-memory unit-test double never exercises real ES/OS latency or consistency behavior, and the prior diagnosis relied on static reading of TaskLockManager/TaskRecoveryManager without live evidence. Adds DEBUG-level "LOCK-DIAG"-tagged logging across the full lock lifecycle (acquire/release/renew/expire in TaskLockManager, crash and locked-task recovery in TaskRecoveryManager, tick-level dispatch decisions in SchedulerServiceImpl/TaskExecutionManager), each line carrying the task id and enough state (lockOwner, lockDate, seq_no, primary_term) to reconstruct the exact sequence of events from a real IT run's karaf.log. BaseIT.java bumps org.apache.unomi.services.impl.scheduler to DEBUG for ITs only so this is actually captured (root logger stays INFO otherwise). This logging is what surfaced the actual root cause fixed in the following commit.
…k acquisition Live IT logging (previous commit) showed TaskLockManager.acquireDistributedLock()'s post-CAS verification step - a delayed re-read compared against a custom "lockVersion" field - failing on essentially every attempt for persistent exclusive tasks, continuously, for an entire IT run on a single node with zero real contention. That verification step was never actually necessary: schedulerService.saveTaskWithRefresh()'s own boolean result is already authoritative proof of exclusive acquisition, since every PersistenceService implementation applies the seq_no/ primary_term CAS precondition atomically (renewLock() and releaseLock() already trusted their own CAS results this way; only acquisition had the extra, redundant re-verification). The re-verification instead added a real race window of its own: a concurrent renewal or recovery write landing between the CAS and the re-read could flip the comparison and produce a false "lost the lock" verdict for an acquisition that had, in fact, already succeeded - triggering a releaseLock() + retry storm that starved the scheduler thread pool. Removes the custom lockVersion field, the verification sleep/re-read/ recheck dance, and the isLockVerificationSuccessful() helper. A successful CAS write now returns true immediately; the backend's own post-write seq_no/primary_term (already tracked for the CAS precondition) doubles as the fencing token, with no separate counter needed. Moves the seq_no/primary_term system-metadata key constants onto PersistenceService (persistence-spi) rather than duplicating them as a private literal in TaskLockManager or exposing them on the generic Item domain class: they're a persistence-implementation detail specific to how PersistenceService.save(Item, Boolean, Boolean)'s CAS contract works, shared by every current and planned implementation (Elasticsearch, OpenSearch, and an in-progress PostgreSQL prototype), not a generic Item concept. TaskLockManagerTest: removed/simplified the tests that specifically exercised the now-deleted verification mechanics (interrupt-during-sleep, transient-visibility-miss recheck, peer-steal-during-verification-window); added a regression test asserting a successful acquisition makes exactly one getTask() call and one CAS write, with no post-write re-read.
…ing race it masked Removing TaskLockManager's redundant post-CAS re-verification (previous commit) surfaced two previously-hidden bugs, both exposed only once lock acquisition became fast and single-shot instead of taking a guaranteed 100ms+ and getting a second look: 1. InMemoryPersistenceServiceImpl.save()'s compare-and-set path had no synchronization around its read-check-write sequence: two real concurrent threads (as in a genuine two-node scheduler test) could both read the same pre-write state, both pass the CAS precondition check, and both "successfully" write - a real double-acquisition bug this test double has apparently had for a while, silently masked because TaskLockManager's now-removed re-verification step happened to catch the resulting double-acquisition after the fact and back one of the two callers out. Real ES/OS never needed that masking because they enforce per-document write ordering atomically at the shard level and never had this race to begin with. Fixed with per-key locking around the critical section, mirroring the existing fileLocks pattern already used elsewhere in this class. 2. SchedulerServiceImplTest#testTaskRecovery has a task that executes immediately on schedule() and always crashes on that first natural attempt (no "crashTime" yet), which asynchronously increments failureCount and reschedules via handleTaskError()'s own save. The test's own simulated-crash setup does a blind saveTask() that can race that background write; whichever lands last wins. The previous, slower acquisition path made it very likely (though never guaranteed) that the natural crash-retry cycle settled before the test got to its own manipulation. Now that acquisition is fast, the test's blind save could land first and get silently overwritten by the natural retry's later save, permanently stranding the task in a retry-delayed SCHEDULED state that never re-triggers recovery. Fixed by waiting for the natural attempt to record failureCount >= 1 (proof its save has already landed) before manipulating the task. Verified: mvn -pl services clean test is 787/787, 0 failures, 0 errors. User confirmed successful live IT runs against both Elasticsearch and OpenSearch.
… move save(Item, Boolean, Boolean)'s CAS-contract javadoc still linked to Item#SYSTEM_METADATA_SEQ_NO/PRIMARY_TERM from an earlier iteration of this change; those constants ended up on PersistenceService itself (edba845), not Item, breaking the maven-javadoc-plugin build. Fix the links to self-reference within PersistenceService.
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
1 participant
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
Plain-language summary
Unomi can run the same background job on more than one node at once, or leave a job stuck after a node stops. That makes exclusive work unsafe in a cluster. This PR fixes those lock and recovery races and adds stronger unit tests so the bugs stay fixed.
What changed
runOnAllNodesturns parallel on automaticallyTest plan
mvn -pl services surefire:test -Dtest=TaskLockManagerTest,TaskExecutionManagerTest,TaskRecoveryManagerTest,PersistenceSchedulerProviderTest,SchedulerServiceClusterRaceTest,SchedulerServiceImplTest,TaskStateManagerTest,TaskValidationManagerTest,TaskMetricsManagerTest,TaskHistoryManagerTestReferences