(An Untitled Masterwork)
ActivePublic
Actions

Authored by EBernhardson on Wed, Aug 5, 6:56 PM.

Project Tags

None

Referenced Files

	F97293529: raw-paste-data.txt
	Wed, Aug 5, 6:56 PM

Subscribers

None

	# Root cause: `auto_expand_replicas` × `TargetPoolAllocationDecider` on every join

	## Summary

	The master election storms are not primarily caused by cluster state size. They
	are caused by a per-node-join CPU cost that scales with the number of indices
	carrying `auto_expand_replicas`, via a code path that **does not exist in
	OpenSearch 1.3.x**. State size makes it worse, but is not the trigger.

	## The hot path

	`_nodes/<master>/hot_threads` during a reproduced storm, `clusterManagerService#updateTask`
	at 97.5% CPU (confirmed independently on two master-eligible nodes):

	```
	JoinTaskExecutor.execute (JoinTaskExecutor.java:314)
	└ AllocationService.adaptAutoExpandReplicas (AllocationService.java:372)
	└ AutoExpandReplicas.getAutoExpandReplicaChanges (:192)
	└ AutoExpandReplicas.getDesiredNumberOfReplicas (:150) per index
	└ AllocationDeciders.shouldAutoExpandToNode (:170) x per node
	└ TargetPoolAllocationDecider.shouldAutoExpandToNode (:122)
	└ TargetPoolAllocationDecider.canAllocateInTargetPool (:126)
	└ RoutingPool.getIndexPool (RoutingPool.java:65)
	└ FeatureFlags.isEnabled (FeatureFlags.java:180)
	└ System.getProperty (System.java:967)
	└ SecurityManager.checkPermission
	└ AccessController.getStackAccessControlContext [native]
	```

	For psi that is 1733 indices × 10 nodes ≈ 17,000 decider calls per join task,
	each performing a native stack walk through the SecurityManager.

	## Why the 1.3.20 -> 2.19.5 upgrade started it

	- `TargetPoolAllocationDecider` and `RoutingPool` are OpenSearch 2.x additions,
	part of the searchable-snapshot / remote-store "routing pool" concept. In 1.3.x,
	`shouldAutoExpandToNode` never reached `FeatureFlags` or `System.getProperty`.
	- WMF runs with the Java SecurityManager active (`-Djava.security.manager=allow`
	plus OpenSearch's own policy), which is what makes each `System.getProperty`
	expensive instead of nearly free.
	- Nearly every WMF index sets `auto_expand_replicas`, so the loop runs at full
	width:

	\| cluster \| indices \| with `auto_expand_replicas` \|
	\| --- \| --- \| --- \|
	\| chi \| 885 \| 829 (823 at `0-2`) \|
	\| omega \| 1732 \| 1732 \|
	\| psi \| 1739 \| 1733 (1732 at `0-2`) \|

	## Why it becomes a storm rather than just a slow join

	The join task takes longer than `cluster.election.initial_timeout` (100 ms
	default, never overridden in puppet). So:

	1. A node wins election for term N and begins the join task.
	2. The task burns CPU in `adaptAutoExpandReplicas` before it can publish.
	3. Another candidate times out at 100 ms and starts an election for N+1.
	4. The higher term reaches the current master, which reverts to candidate.
	5. Goto 1. Winning an election resets `ElectionSchedulerFactory`'s backoff, so
	the backoff never engages -- hence production's 84 ms median gap between
	elections, sitting right at the un-backed-off initial timeout.

	`cluster.publish.timeout` (30 s) is never reached; failures land in
	milliseconds. Anyone grepping for publication timeouts will find nothing.

	## Controlled experiment isolating the variable

	Three runs, each on a freshly created cluster (volumes wiped) with production-default
	config and no mitigations. Arms A and B use synthetic indices -- 1739 indices, one
	keyword field each, no analysis block, no aliases -- so that index count is held
	at the production value while state size is cut to a fifth.

	\| \| prod indices \| A: `auto_expand_replicas: 0-2` \| B: fixed `number_of_replicas: 2` \|
	\| --- \| --- \| --- \| --- \|
	\| indices \| 1739 \| 1739 \| 1739 \|
	\| shard copies \| 5204 \| 5217 \| 5217 \|
	\| cluster state \| 21.5 MB \| 4.20 MB \| 4.14 MB \|
	\| index load time \| 467 s (full mappings) \| 467 s \| 230 s \|
	\| elections \| 6684 \| 2183 \| 3 \|
	\| `FailedToCommit` \| 55329 \| 17817 \| 8 \|
	\| coordinator term \| +19000 \| +5007 \| +1 \|
	\| election storm \| never ended \| 282 s \| none \|
	\| time to green \| never (>900 s) \| not within 600 s \| 171 s \|
	\| verdict \| REPRODUCED \| REPRODUCED \| NOT REPRODUCED \|

	Two conclusions, each from a controlled comparison rather than inference:

	- State size is not the cause. Arm A removed every mapping and every inlined
	analysis block, cutting the state to 4.2 MB, and stormed just as hard. What
	size governs is escape: at 4.2 MB the livelock broke on its own after ~5
	minutes; at 21.5 MB it never did and needed manual intervention.
	- `auto_expand_replicas` is the trigger. It is the only difference between A
	and B. Removing it takes a master restart from 2183 elections and no recovery
	to 3 elections and a clean 171-second failover. Index count alone is not
	sufficient -- Arm B has all 1739 indices.

	The 2x difference in index load time (467 s vs 230 s) corroborates this
	independently: index creation is also a cluster state update, and without
	`auto_expand_replicas` there is no per-index x per-node decider sweep to pay on
	each one.

	Note that `auto_expand_replicas: 0-2` on a cluster that always has at least three
	nodes resolves to 2 every time -- it buys nothing over a fixed
	`number_of_replicas: 2`, while costing the sweep on every join.

	## Two hypotheses the reproduction killed

	- "The storm is sustained by the restarted node needing a full cluster state."
	Wrong. Stopping the rejoining node mid-storm changed nothing; the remaining
	nodes kept storming at the same rate.
	- "Cluster state size is the trigger." Only an aggravator. The trigger is
	per-join CPU proportional to index count. Size determines how much slower
	publication is once you are already losing the race.

	## Diagnostic gotchas found while measuring this

	Both cost real time and would mislead anyone debugging this in production:

	1. *`metadata.cluster_coordination.term` is the last accepted* term**, not the
	coordinator's live term. It only advances when a publication commits, so
	during a storm it freezes. Observed: pinned at 916 for 15 minutes while
	the real term climbed past 19,000. A frozen term is evidence of a storm.
	The live term is only visible in logs, as `minimumTerm=` on JoinRequests.

	2. `filter_path` does not avoid serializing what you filtered out. It is
	applied while generating XContent, so
	`_cluster/state/metadata?filter_path=metadata.cluster_coordination.term`
	still walks all ~20 MB: 3.08 s. Restricting the index expression --
	`_cluster/state/metadata/zzz-nomatch-*?allow_no_indices=true&filter_path=...`
	-- returns the identical answer in 0.039 s, 79x faster. Any monitoring
	that polls `_cluster/state` unrestricted is adding load to a master that is
	already the bottleneck.

	## Candidate mitigations, cheapest first

	1. Drop `auto_expand_replicas`, setting an explicit `number_of_replicas`.
	Removes the hot path entirely; config-only, no upstream patch, no restart.
	Verified: Arm B above, 3 elections vs 2183, clean 171 s failover.
	`./mitigate.py --disable-auto-expand` applies it to a running cluster.
	2. Raise `cluster.election.initial_timeout` above the join-task duration.
	Treats the symptom -- the join still costs the same, but candidates stop
	preempting each other. Cheap and reversible, and being a static NodeScope
	setting it is the only lever that works on an already-livelocked cluster.
	Verified: at 10s, a cluster that could not form at all came up and
	reached green with 1 election total, against 6684 unmitigated.
	Caveat: OpenSearch caps this at 10s (`Setting.MinMaxTimeValueParser`)
	and rejects larger values at startup rather than clamping -- a node
	configured with 30s exits on boot. If the join task ever exceeds 10s, this
	mitigation cannot help, which is why #1 is the more durable fix.
	3. Dedicated master-eligible nodes that hold no data. Does not reduce the
	per-join cost (it is driven by index count, not local shards) but removes
	the competing search/indexing load on the same JVM.
	4. Upstream: `FeatureFlags.isEnabled` should cache rather than call
	`System.getProperty` under a SecurityManager on every decider invocation.

	Mitigations 1 and 2 are testable with this harness; see README.

Event Timeline

EBernhardson created this paste.Wed, Aug 5, 6:56 PM

EBernhardson mentioned this in T434008: Cirrussearch: Ensure master-eligibles can restart without losing quorum.

(An Untitled Masterwork)ActivePublicActions

Event Timeline

(An Untitled Masterwork)
ActivePublic
Actions