[BUG] org.opensearch.indices.replication.SegmentReplicationTargetServiceTests.testShardAlreadyReplicating is flaky

[kotwanikunal]

Describe the bug

• org.opensearch.indices.replication.SegmentReplicationTargetServiceTests.testShardAlreadyReplicating is flaky
• Sample run: https://build.ci.opensearch.org/job/gradle-check/21062/testReport/org.opensearch.indices.replication/SegmentReplicationTargetServiceTests/testShardAlreadyReplicating/
• Failed twice on [BUG] org.opensearch.remotestore.RemoteStoreRefreshListenerIT.testRemoteRefreshRetryOnFailure is flaky #8506

To Reproduce

REPRODUCE WITH: ./gradlew ':server:test' --tests "org.opensearch.indices.replication.SegmentReplicationTargetServiceTests.testShardAlreadyReplicating" -Dtests.seed=D8312943A799670E -Dtests.security.manager=true -Dtests.jvm.argline="-XX:TieredStopAtLevel=1 -XX:ReservedCodeCacheSize=64m" -Dtests.locale=ar-AE -Dtests.timezone=America/Manaus -Druntime.java=20

Expected behavior

• Test to pass

[dreamer-89]

Tried with given seed, but test passes locally. Running test in repeat mode until failure.

[dreamer-89]

No failure observed in 10k runs with given seed.

Next steps: Running test class on repeat

[dreamer-89]

From failure stack trace , the test fails on Assertion here

com.carrotsearch.randomizedtesting.UncaughtExceptionError: Captured an uncaught exception in thread: Thread[id=486, name=opensearch[org.opensearch.indices.replication.SegmentReplicationTargetServiceTests][generic][T#2], state=RUNNABLE, group=TGRP-SegmentReplicationTargetServiceTests]
	at __randomizedtesting.SeedInfo.seed([D3ADB03B1A04B5E3:F074352090C37CEA]:0)
Caused by: java.lang.AssertionError: Should not succeed

There are no logs which can help debugging this failure.

[2023-07-25T15:44:46,986][INFO ][o.o.t.TransportService   ] [testShardAlreadyReplicating] Remote clusters initialized successfully.
[2023-07-25T15:44:46,994][INFO ][o.o.i.r.SegmentReplicationTargetServiceTests] [testShardAlreadyReplicating] before test
[2023-07-25T15:44:47,015][INFO ][o.o.i.r.SegmentReplicationTargetServiceTests] [testShardAlreadyReplicating] after test

[dreamer-89]

Not much success with running tests at class level.

[dreamer-89]

On doing a closer look on the test, it assumes the first round of segment replication is active for the test to pass. This assumption may not hold everytime and it is possible that first round of segment replication completes before control goes to start another round. An easy way to reproduce this issue locally is to add a wait post first startReplication invocation. Test fails reliably after adding a 10ms wait time.

    public void testShardAlreadyReplicating() {
   1 -->     sut.startReplication(replicaShard, mock(SegmentReplicationTargetService.SegmentReplicationListener.class));
   2 -->    sut.startReplication(replicaShard, new SegmentReplicationTargetService.SegmentReplicationListener() {
            @Override
            public void onReplicationDone(SegmentReplicationState state) {
                Assert.fail("Should not succeed");
            }

            @Override
            public void onReplicationFailure(SegmentReplicationState state, ReplicationFailedException e, boolean sendShardFailure) {
                assertEquals("Shard " + replicaShard.shardId() + " is already replicating", e.getMessage());
                assertFalse(sendShardFailure);
            }
        });
    }

[dreamer-89]

This test is still failing, reopening

[dreamer-89]

This test fails while expecting call to processLatestReceivedCheckpoint.

From https://build.ci.opensearch.org/job/gradle-check/22784

Wanted but not invoked:
segmentReplicationTargetService.processLatestReceivedCheckpoint(
    org.opensearch.index.shard.IndexShard@35f0ec9a,
    <any>
);
-> at org.opensearch.indices.replication.SegmentReplicationTargetServiceTests.testShardAlreadyReplicating(SegmentReplicationTargetServiceTests.java:295)

However, there were exactly 5 interactions with this mock:
segmentReplicationTargetService.startReplication(
    org.opensearch.indices.replication.SegmentReplicationTarget$MockitoMock$CY6zJxTo@54ccd0b4
);
-> at org.opensearch.indices.replication.SegmentReplicationTargetServiceTests.testShardAlreadyReplicating(SegmentReplicationTargetServiceTests.java:291)

segmentReplicationTargetService.onNewCheckpoint(
    ReplicationCheckpoint{shardId=[index][0], primaryTerm=88, segmentsGen=3, version=8, size=0, codec=Lucene95},
    org.opensearch.index.shard.IndexShard@35f0ec9a
);
-> at org.opensearch.indices.replication.SegmentReplicationTargetServiceTests.testShardAlreadyReplicating(SegmentReplicationTargetServiceTests.java:294)

segmentReplicationTargetService.updateLatestReceivedCheckpoint(
    ReplicationCheckpoint{shardId=[index][0], primaryTerm=88, segmentsGen=3, version=8, size=0, codec=Lucene95},
    org.opensearch.index.shard.IndexShard@35f0ec9a
);
-> at org.opensearch.indices.replication.SegmentReplicationTargetService.onNewCheckpoint(SegmentReplicationTargetService.java:216)

segmentReplicationTargetService.startReplication(
    org.opensearch.index.shard.IndexShard@35f0ec9a,
    ReplicationCheckpoint{shardId=[index][0], primaryTerm=88, segmentsGen=3, version=8, size=0, codec=Lucene95},
    org.opensearch.indices.replication.SegmentReplicationTargetService$1@4c9dfcab
);
-> at org.opensearch.indices.replication.SegmentReplicationTargetService.onNewCheckpoint(SegmentReplicationTargetService.java:245)

segmentReplicationTargetService.startReplication(
    org.opensearch.indices.replication.SegmentReplicationTarget@10dfa5d1
);
-> at org.opensearch.indices.replication.SegmentReplicationTargetService.startReplication(SegmentReplicationTargetService.java:419)

[Rishikesh1159]

Not able to reproduce the test failure. Tried running entire test suite class but still not able to reproduce. This flaky test might be fixed from some changes happened in last 2 months. I will unmute the test for now with PR #10660 (as we are not able to repro) and I am adding trace logging with test, so next time if we see this test failing we can get more info from logs.

[reta]

Wanted but not invoked:
segmentReplicationTargetService.processLatestReceivedCheckpoint(
    org.opensearch.index.shard.IndexShard@4876cf44,
    <any>
);
-> at org.opensearch.indices.replication.SegmentReplicationTargetServiceTests.testShardAlreadyReplicating(SegmentReplicationTargetServiceTests.java:316)

However, there were exactly 5 interactions with this mock:
segmentReplicationTargetService.startReplication(
    org.opensearch.indices.replication.SegmentReplicationTarget$MockitoMock$8gnjoQCG@b2e2a95
);
-> at org.opensearch.indices.replication.SegmentReplicationTargetServiceTests.testShardAlreadyReplicating(SegmentReplicationTargetServiceTests.java:312)

segmentReplicationTargetService.onNewCheckpoint(
    ReplicationCheckpoint{shardId=[index][0], primaryTerm=95, segmentsGen=3, version=8, size=0, codec=Lucene99},
    org.opensearch.index.shard.IndexShard@4876cf44
);
-> at org.opensearch.indices.replication.SegmentReplicationTargetServiceTests.testShardAlreadyReplicating(SegmentReplicationTargetServiceTests.java:315)

segmentReplicationTargetService.updateLatestReceivedCheckpoint(
    ReplicationCheckpoint{shardId=[index][0], primaryTerm=95, segmentsGen=3, version=8, size=0, codec=Lucene99},
    org.opensearch.index.shard.IndexShard@4876cf44
);
-> at org.opensearch.indices.replication.SegmentReplicationTargetService.onNewCheckpoint(SegmentReplicationTargetService.java:273)

segmentReplicationTargetService.startReplication(
    org.opensearch.index.shard.IndexShard@4876cf44,
    ReplicationCheckpoint{shardId=[index][0], primaryTerm=95, segmentsGen=3, version=8, size=0, codec=Lucene99},
    org.opensearch.indices.replication.SegmentReplicationTargetService$1@aa0c9f5
);
-> at org.opensearch.indices.replication.SegmentReplicationTargetService.onNewCheckpoint(SegmentReplicationTargetService.java:302)

segmentReplicationTargetService.startReplication(
    org.opensearch.indices.replication.SegmentReplicationTarget@3fec1515
);
-> at org.opensearch.indices.replication.SegmentReplicationTargetService.startReplication(SegmentReplicationTargetService.java:498)

[getsaurabh02]

@dreamer-89 Are we still actively looking into this one?