[BUG] Infinite loop of S3 GET/LIST requests during segment replication recovery after node loss/restart

[fullykubed]

Describe the bug

After S3 remote-backed storage was fixed in v3, we enabled it with segment replication. After doing so, we noticed our OpenSearch cluster began issuing millions of S3 ListObjectsV2 and GetObject requests per hour to the configured S3 bucket.

This behavior appears pathological and triggered only after the shutdown of one OpenSearch node, leading to:

• Persistent get and list requests to the /<index_uuid>/0/segments/metadata/metadata prefixes across all indices
• Sustained high CPU usage on one surviving node (likely due to the looping requests)

This causes a HUGE spike in cluster costs ($1,000+ / month) even for our very small dataset (<100MB) since over the course of a month this has generated 200M requests to S3 (and we got fairly lucky since this fortunately wasn't occurring all the time ):

In our debugging, here is what we have observed:

• This behavior is not observed during normal operations, only when a node is lost.
• It doesn't appear to matter whether the lost node is a leader or follower.
• In a three-node cluster, will only impacts one of the remaining two nodes.
• It doesn't occur all the time (~25% incident rate for us).
• The issue cannot be fixed without deleting the malfunctioning node.
• Oddly, the cluster itself appears to be functioning fine even while this is occurring -- even for indices with shards on the degenerate node.

Related component

Storage:Remote

To Reproduce

1. Deploy a 3-node opensearch cluster on kubernetes using these opensearch.yml settings:

"cluster.allocator.existing_shards_allocator.batch_enabled": true
"cluster.indices.replication.strategy": "SEGMENT"
"cluster.initial_cluster_manager_nodes":
  - "opensearch-7d0b-0"
  - "opensearch-7d0b-1"
  - "opensearch-7d0b-2"
"cluster.name": "opensearch-7d0b"
"cluster.remote_store.publication.enabled": true
"cluster.remote_store.routing_table.path.prefix": "routing/"
"cluster.remote_store.state.enabled": true
"cluster.remote_store.state.path.prefix": "state/"
"cluster.routing.allocation.balance.prefer_primary": true
"cluster.routing.allocation.disk.watermark.high": "90%"
"cluster.routing.allocation.shard_movement_strategy": "PRIMARY_FIRST"
"discovery.seed_hosts":
  - "opensearch-7d0b-headless"
"indices.recovery.max_bytes_per_sec": "0mb"
"logger._root": "WARN"
"logger.org.opensearch.alerting.util.destinationmigration.DestinationMigrationCoordinator": "WARN"
"network.host": "0.0.0.0"
"node.attr.remote_store.repository.s3.settings.bucket": "default-opensearch-7d0b-storage-15cf133175f73b63"
"node.attr.remote_store.repository.s3.settings.region": "us-east-2"
"node.attr.remote_store.repository.s3.type": "s3"
"node.attr.remote_store.routing_table.repository": "s3"
"node.attr.remote_store.segment.repository": "s3"
"node.attr.remote_store.state.repository": "s3"
"node.attr.remote_store.translog.repository": "s3"
"node.roles":
  - "cluster_manager"
  - "ingest"
  - "data"
  - "remote_cluster_client"
"s3.client.default.endpoint": "s3.us-east-2.amazonaws.com"
"s3.client.default.region": "us-east-2"
"segrep.pressure.enabled": true

2. Launch each node with the following bash script:

#!/usr/bin/env bash

set -euo pipefail
./bin/opensearch-plugin install -b repository-s3

echo "$AWS_ACCESS_KEY_ID" | ./bin/opensearch-keystore add --stdin --force s3.client.default.access_key
echo "$AWS_SECRET_ACCESS_KEY" | ./bin/opensearch-keystore add --stdin --force s3.client.default.secret_key

# Set JVM heap size dynamically to 50% of container memory request
HEAP_SIZE=$((CONTAINER_MEMORY_REQUEST / 2000000))
export OPENSEACH_JAVA_OPTS="-Xmx${HEAP_SIZE}M -Xms${HEAP_SIZE}M --enable-native-access=ALL-UNNAMED"

./bin/opensearch \
  -Enode.name="$POD_NAME" \
  -Eplugins.query.datasources.encryption.masterkey="$OPENSEARCH_MASTER_KEY"

3. Deploy the demo data that comes with the OpenSearch Dashboard

4. Restart a node (doesn't occur every restart -- looks to occur 25% of the time for us).

Expected behavior

The infinite loop of requests should not occur.

Additional Details

Plugins

• repository-s3

Screenshots

Host/Environment (please complete the following information):

• Environment: AWS EKS 1.30
• OS: Bottlerocket
• Version: 3.0.0

Additional context

Count of the list requests that occurred in a single minute based on the CloudTrail events logs:

   1220 1vO1bkUERFWvJp2p9vNo9w/0/segments/metadata/metadata
   1195 eFMZ2857RDKzqWOKoEhjmg/0/segments/metadata/metadata
   1166 LZcXfsUHQoOfZ-VAe82Smw/0/segments/metadata/metadata
   1142 UZA4K5ruT-Opx6EmbOKbvg/0/segments/metadata/metadata
   1138 TaxiBYmZS4ypJ2DrGdxZEw/0/segments/metadata/metadata
   1105 NlAaRqFzRku2H2A7ABCYlA/0/segments/metadata/metadata
   1088 EkPLvxHwTZOWIWkS6_UgEA/0/segments/metadata/metadata
   1077 tJPUeD9ESA6X1XsPZxUxcg/0/segments/metadata/metadata
   1068 04mQ2jgvSMejOlTaUB9k6Q/0/segments/metadata/metadata
   1050 OJMqg9FsSy2m76o3vxZvVQ/0/segments/metadata/metadata

I also capture all the DEBUG logs across the entire cluster during a 5-minute segment when this issue occurred. Due to the insane amount of requests, the log file is quite large (2GB): log file.

[andrross]

FYI @ashking94

[ashking94]

Thanks for reporting the issue @fullykubed. Let me go through this.

[ashking94]

I have found the root cause for this issue. Before going deeper into the same, let me tell what the issue is - After node drops, a replica shard get stuck in a infinite loop of segment replication even when there is no indexing happening on that shard. This leads to infinite cycle of LIST and GET calls on the configured underlying remote store. Since there is no additional segment files to copy in these segment replication rounds, the number of calls made to remote store can be quite high.

Now, to understand the issue, we need to understand a little of how segment replication works. Whenever a refresh happens on the primary shard, the primary shard notifies the replica shards about the latest checkpoint and the replica shards starts pulling latest segments from the primary shard or remote store depending on the type of cluster. The time it takes for segment replication can depend on multiple factors and hence it is possible that another refresh can happen on the primary shard and it will again notify the replicas about the latest checkpoint. If the replica shard is already occupied with segment replication from an older checkpoint, then the latest received checkpoint is cached in-memory. When the segment replication of the older checkpoint finishes, then it checks the latest received checkpoints against the latest checkpoint tracked by replication tracker. The latest checkpoint in the replication tracker is updated only after refresh happens with reference changing in the reader manager.

Replica shard updates the latest received on receiving a new checkpoint:

OpenSearch/server/src/main/java/org/opensearch/indices/replication/SegmentReplicationTargetService.java

Lines 295 to 303 in 6154ffe

	public synchronized void onNewCheckpoint(final ReplicationCheckpoint receivedCheckpoint, final IndexShard replicaShard) {
	logger.debug(() -> new ParameterizedMessage("Replica received new replication checkpoint from primary [{}]", receivedCheckpoint));
	// if the shard is in any state
	if (replicaShard.state().equals(IndexShardState.CLOSED)) {
	// ignore if shard is closed
	logger.trace(() -> "Ignoring checkpoint, Shard is closed");
	return;
	}
	updateLatestReceivedCheckpoint(receivedCheckpoint, replicaShard);

The latest received checkpoint is updated in SegmentReplicator only if it is ahead of the previous latest received checkpoint:

OpenSearch/server/src/main/java/org/opensearch/indices/replication/SegmentReplicator.java

Lines 195 to 201 in b1d6f55

	public void updateReplicationCheckpointStats(final ReplicationCheckpoint latestReceivedCheckPoint, final IndexShard indexShard) {
	ReplicationCheckpoint primaryCheckPoint = this.primaryCheckpoint.get(indexShard.shardId());
	if (primaryCheckPoint == null || latestReceivedCheckPoint.isAheadOf(primaryCheckPoint)) {
	this.primaryCheckpoint.put(indexShard.shardId(), latestReceivedCheckPoint);
	calculateReplicationCheckpointStats(latestReceivedCheckPoint, indexShard);
	}
	}

Segment replication is done only if the received checkpoint is ahead of latest replication checkpoint (tracked via ReplicationTracker):

OpenSearch/server/src/main/java/org/opensearch/indices/replication/SegmentReplicationTargetService.java

Lines 331 to 332 in 6154ffe

	if (replicaShard.shouldProcessCheckpoint(receivedCheckpoint)) {
	startReplication(replicaShard, receivedCheckpoint, new SegmentReplicationListener() {

OpenSearch/server/src/main/java/org/opensearch/index/shard/IndexShard.java

Lines 1935 to 1951 in b1d6f55

	public final boolean shouldProcessCheckpoint(ReplicationCheckpoint requestCheckpoint) {
	if (isSegmentReplicationAllowed() == false) {
	return false;
	}
	final ReplicationCheckpoint localCheckpoint = getLatestReplicationCheckpoint();
	if (requestCheckpoint.isAheadOf(localCheckpoint) == false) {
	logger.trace(
	() -> new ParameterizedMessage(
	"Ignoring new replication checkpoint - Shard is already on checkpoint {} that is ahead of {}",
	localCheckpoint,
	requestCheckpoint
	)
	);
	return false;
	}
	return true;
	}

OpenSearch/server/src/main/java/org/opensearch/index/shard/IndexShard.java

Lines 1792 to 1794 in b1d6f55

	public ReplicationCheckpoint getLatestReplicationCheckpoint() {
	return replicationTracker.getLatestReplicationCheckpoint();
	}

Now even if the segment replication succeeds or fails, the processLatestReceivedCheckpoint method is invoked which triggers segment replication again on the cached latest received checkpoint:

OpenSearch/server/src/main/java/org/opensearch/indices/replication/SegmentReplicationTargetService.java

Lines 334 to 351 in 6154ffe

	public void onReplicationDone(SegmentReplicationState state) {
	logger.debug(
	() -> new ParameterizedMessage(
	"[shardId {}] [replication id {}] Replication complete to {}, timing data: {}",
	replicaShard.shardId().getId(),
	state.getReplicationId(),
	replicaShard.getLatestReplicationCheckpoint(),
	state.getTimingData()
	)
	);
	// update visible checkpoint to primary
	updateVisibleCheckpoint(state.getReplicationId(), replicaShard);
	// if we received a checkpoint during the copy event that is ahead of this
	// try and process it.
	processLatestReceivedCheckpoint(replicaShard, thread);
	}

OpenSearch/server/src/main/java/org/opensearch/indices/replication/SegmentReplicationTargetService.java

Lines 354 to 364 in 6154ffe

	public void onReplicationFailure(
	SegmentReplicationState state,
	ReplicationFailedException e,
	boolean sendShardFailure
	) {
	logReplicationFailure(state, e, replicaShard);
	if (sendShardFailure == true) {
	failShard(e, replicaShard);
	} else {
	processLatestReceivedCheckpoint(replicaShard, thread);
	}

The short circuiting of this cyclic loop relies on the updation of latest checkpoint in replication tracker.

Now that we understand how segment replication works, it should be simpler to understand the root cause on why the infinite loop happens. So, with each successful segment replication, we trigger the finalizeReplication in IndexShard with the hope that the readermanager would be updated which means that local refresh happened successfully. On successful refresh with didRefresh true, the ReplicationCheckpointUpdater updates the replication checkpoint in Replication tracker.

OpenSearch/server/src/main/java/org/opensearch/index/shard/IndexShard.java

Lines 4978 to 4991 in b1d6f55

	private class ReplicationCheckpointUpdater implements ReferenceManager.RefreshListener {
	@Override
	public void beforeRefresh() throws IOException {}
	@Override
	public void afterRefresh(boolean didRefresh) throws IOException {
	if (didRefresh) {
	// We're only starting to track the replication checkpoint. The timers for replication are started when
	// the checkpoint is published. This is done so that the timers do not include the time spent by primary
	// in uploading the segments to remote store.
	updateReplicationCheckpoint();
	}
	}
	}

However, during the case of the node restarts (holding primary shards), it is observed that the refreshes on replica shards on new primary election is not leading to the update of directory reader. And this is happening because there is a check that compares the version of refreshed reader's segment infos against version of the latest segment infos. In the case of node restarts, it is being observed that the version is not changing but only the generation and primary term (which are expected as well). The reason this issue shows up only certain times is because there appears to be flakiness on the segment infos version bump.

I am raising a PR to fix this where the generation would be compared as well along with version.

Tagging few folks with context on this to help review this analysis - @sachinpkale @Bukhtawar @gbbafna @mch2 @andrross .

[ashking94]

The behaviour around the segment infos version not changing during node restarts was visible in the logs shared by @fullykubed :

[.ql-datasources][0]

opensearch-7d0b-2 opensearch [2025-06-25T01:01:19,381][DEBUG][o.o.i.r.SegmentReplicationTargetService] [opensearch-7d0b-2] Replica received new replication checkpoint from primary [ReplicationCheckpoint{shardId=[.ql-datasources][0], primaryTerm=228, segmentsGen=235, version=19, size=0, codec=Lucene101, timestamp=32335638388765}]
opensearch-7d0b-2 opensearch [2025-06-25T01:01:20,394][DEBUG][o.o.i.r.SegmentReplicationTargetService] [opensearch-7d0b-2] Replica received new replication checkpoint from primary [ReplicationCheckpoint{shardId=[.ql-datasources][0], primaryTerm=229, segmentsGen=236, version=19, size=0, codec=Lucene101, timestamp=14025570905521}]
opensearch-7d0b-2 opensearch [2025-06-25T01:01:20,400][DEBUG][o.o.i.r.SegmentReplicationTargetService] [opensearch-7d0b-2] Replica received new replication checkpoint from primary [ReplicationCheckpoint{shardId=[.ql-datasources][0], primaryTerm=229, segmentsGen=236, version=19, size=0, codec=Lucene101, timestamp=14025570905521}]
opensearch-7d0b-2 opensearch [2025-06-25T01:01:20,481][DEBUG][o.o.i.r.SegmentReplicationTargetService] [opensearch-7d0b-2] Replica received new replication checkpoint from primary [ReplicationCheckpoint{shardId=[.ql-datasources][0], primaryTerm=229, segmentsGen=236, version=19, size=0, codec=Lucene101, timestamp=14025570905521}]
opensearch-7d0b-2 opensearch [2025-06-25T01:01:20,534][DEBUG][o.o.i.r.SegmentReplicationTargetService] [opensearch-7d0b-2] Replica received new replication checkpoint from primary [ReplicationCheckpoint{shardId=[.ql-datasources][0], primaryTerm=229, segmentsGen=236, version=19, size=0, codec=Lucene101, timestamp=14025570905521}]
opensearch-7d0b-2 opensearch [2025-06-25T01:01:20,589][DEBUG][o.o.i.r.SegmentReplicationTargetService] [opensearch-7d0b-2] Replica received new replication checkpoint from primary [ReplicationCheckpoint{shardId=[.ql-datasources][0], primaryTerm=229, segmentsGen=236, version=19, size=0, codec=Lucene101, timestamp=14025570905521}]
opensearch-7d0b-2 opensearch [2025-06-25T01:01:20,634][DEBUG][o.o.i.r.SegmentReplicationTargetService] [opensearch-7d0b-2] Replica received new replication checkpoint from primary [ReplicationCheckpoint{shardId=[.ql-datasources][0], primaryTerm=229, segmentsGen=236, version=19, size=0, codec=Lucene101, timestamp=14025570905521}]
opensearch-7d0b-2 opensearch [2025-06-25T01:01:20,686][DEBUG][o.o.i.r.SegmentReplicationTargetService] [opensearch-7d0b-2] Replica received new replication checkpoint from primary [ReplicationCheckpoint{shardId=[.ql-datasources][0], primaryTerm=229, segmentsGen=236, version=19, size=0, codec=Lucene101, timestamp=14025570905521}]

[.plugins-ml-config][0]

opensearch-7d0b-2 opensearch [2025-06-25T00:59:37,346][DEBUG][o.o.i.r.SegmentReplicationTargetService] [opensearch-7d0b-2] Replica received new replication checkpoint from primary [ReplicationCheckpoint{shardId=[.plugins-ml-config][0], primaryTerm=233, segmentsGen=240, version=21, size=3859, codec=Lucene101, timestamp=32349645878799}]
opensearch-7d0b-2 opensearch [2025-06-25T01:01:19,386][DEBUG][o.o.i.r.SegmentReplicationTargetService] [opensearch-7d0b-2] Replica received new replication checkpoint from primary [ReplicationCheckpoint{shardId=[.plugins-ml-config][0], primaryTerm=233, segmentsGen=240, version=21, size=3859, codec=Lucene101, timestamp=32349645878799}]
opensearch-7d0b-2 opensearch [2025-06-25T01:01:34,054][DEBUG][o.o.i.r.SegmentReplicationTargetService] [opensearch-7d0b-2] Replica received new replication checkpoint from primary [ReplicationCheckpoint{shardId=[.plugins-ml-config][0], primaryTerm=234, segmentsGen=241, version=21, size=3859, codec=Lucene101, timestamp=14039385545419}]
opensearch-7d0b-2 opensearch [2025-06-25T01:01:34,054][DEBUG][o.o.i.r.SegmentReplicationTargetService] [opensearch-7d0b-2] Replica received new replication checkpoint from primary [ReplicationCheckpoint{shardId=[.plugins-ml-config][0], primaryTerm=234, segmentsGen=241, version=21, size=3859, codec=Lucene101, timestamp=14039385545419}]
opensearch-7d0b-2 opensearch [2025-06-25T01:01:34,206][DEBUG][o.o.i.r.SegmentReplicationTargetService] [opensearch-7d0b-2] Replica received new replication checkpoint from primary [ReplicationCheckpoint{shardId=[.plugins-ml-config][0], primaryTerm=234, segmentsGen=241, version=21, size=3859, codec=Lucene101, timestamp=14039385545419}]
opensearch-7d0b-2 opensearch [2025-06-25T01:01:34,309][DEBUG][o.o.i.r.SegmentReplicationTargetService] [opensearch-7d0b-2] Replica received new replication checkpoint from primary [ReplicationCheckpoint{shardId=[.plugins-ml-config][0], primaryTerm=234, segmentsGen=241, version=21, size=3859, codec=Lucene101, timestamp=14039385545419}]
opensearch-7d0b-2 opensearch [2025-06-25T01:01:34,361][DEBUG][o.o.i.r.SegmentReplicationTargetService] [opensearch-7d0b-2] Replica received new replication checkpoint from primary [ReplicationCheckpoint{shardId=[.plugins-ml-config][0], primaryTerm=234, segmentsGen=241, version=21, size=3859, codec=Lucene101, timestamp=14039385545419}]
opensearch-7d0b-2 opensearch [2025-06-25T01:01:34,404][DEBUG][o.o.i.r.SegmentReplicationTargetService] [opensearch-7d0b-2] Replica received new replication checkpoint from primary [ReplicationCheckpoint{shardId=[.plugins-ml-config][0], primaryTerm=234, segmentsGen=241, version=21, size=3859, codec=Lucene101, timestamp=14039385545419}]
opensearch-7d0b-2 opensearch [2025-06-25T01:01:34,507][DEBUG][o.o.i.r.SegmentReplicationTargetService] [opensearch-7d0b-2] Replica received new replication checkpoint from primary [ReplicationCheckpoint{shardId=[.plugins-ml-config][0], primaryTerm=234, segmentsGen=241, version=21, size=3859, codec=Lucene101, timestamp=14039385545419}]
opensearch-7d0b-2 opensearch [2025-06-25T01:01:34,543][DEBUG][o.o.i.r.SegmentReplicationTargetService] [opensearch-7d0b-2] Replica received new replication checkpoint from primary [ReplicationCheckpoint{shardId=[.plugins-ml-config][0], primaryTerm=234, segmentsGen=241, version=21, size=3859, codec=Lucene101, timestamp=14039385545419}]