[SOLR-12201] TestReplicationHandler.doTestIndexFetchOnMasterRestart(): unexpected replication failures

• Type: Bug
• Status: Closed
• Priority: Major
• Resolution: Fixed
• Fix Version/s: 7.4, 8.0
• Assignee: Steven Rowe
• Reporter: Steven Rowe
• Created: 07/Apr/18 00:32
• Updated: 08/Jun/19 15:12
• Resolved: 11/Apr/18 02:16

Description

This is a BadApple'd test, and in local beasting failed 31/100 iterations.

E.g. from https://builds.apache.org/job/Lucene-Solr-BadApples-Tests-master/24/:

   [junit4]   1> SHALIN: {responseHeader={status=0,QTime=150},details={indexSize=11.2 KB,indexPath=/home/jenkins/jenkins-slave/workspace/PreCommit-SOLR-Build/sourcedir/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_C1A11EE85E7B0C57-001/solr-instance-008/./collection1/data/index/,commits=[{indexVersion=1523043739675,generation=2,filelist=[_0.fdt, _0.fdx, _0.fnm, _0.nvd, _0.nvm, _0.si, _0_FSTOrd50_0.doc, _0_FSTOrd50_0.tbk, _0_FSTOrd50_0.tix, segments_2]}],isMaster=false,isSlave=true,indexVersion=1523043739675,generation=2,slave={masterDetails={indexSize=11.27 KB,indexPath=/home/jenkins/jenkins-slave/workspace/PreCommit-SOLR-Build/sourcedir/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_C1A11EE85E7B0C57-001/solr-instance-007/./collection1/data/index/,commits=[{indexVersion=0,generation=1,filelist=[segments_1]}, {indexVersion=1523043739675,generation=2,filelist=[_0.fdt, _0.fdx, _0.fnm, _0.nvd, _0.nvm, _0.si, _0_FSTOrd50_0.doc, _0_FSTOrd50_0.tbk, _0_FSTOrd50_0.tix, segments_2]}],isMaster=true,isSlave=false,indexVersion=1523043739675,generation=2,master={confFiles=schema.xml,replicateAfter=[commit, startup],replicationEnabled=true,replicableVersion=1523043739675,replicableGeneration=2}},masterUrl=http://127.0.0.1:36880/solr/collection1,pollInterval=00:00:01,nextExecutionAt=Fri Apr 06 20:42:21 BST 2018,indexReplicatedAt=Fri Apr 06 20:42:20 BST 2018,indexReplicatedAtList=[Fri Apr 06 20:42:20 BST 2018, Fri Apr 06 20:42:17 BST 2018],replicationFailedAtList=[Fri Apr 06 20:42:17 BST 2018],timesIndexReplicated=2,lastCycleBytesDownloaded=11650,timesFailed=1,replicationFailedAt=Fri Apr 06 20:42:17 BST 2018,previousCycleTimeInSeconds=0,currentDate=Fri Apr 06 20:42:21 BST 2018,isPollingDisabled=false,isReplicating=false}}}
[...]
   [junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=TestReplicationHandler -Dtests.method=doTestIndexFetchOnMasterRestart -Dtests.seed=C1A11EE85E7B0C57 -Dtests.multiplier=2 -Dtests.slow=true -Dtests.badapples=true -Dtests.locale=en -Dtests.timezone=Europe/Isle_of_Man -Dtests.asserts=true -Dtests.file.encoding=UTF-8
   [junit4] FAILURE 9.39s J1 | TestReplicationHandler.doTestIndexFetchOnMasterRestart <<<
   [junit4]    > Throwable #1: java.lang.AssertionError: expected:<1> but was:<2>
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([C1A11EE85E7B0C57:1956DA0CF5A0CE0B]:0)
   [junit4]    > 	at org.apache.solr.handler.TestReplicationHandler.doTestIndexFetchOnMasterRestart(TestReplicationHandler.java:666)
   [junit4]    > 	at java.lang.Thread.run(Thread.java:748)

The failed assertion is on line 666:

TestReplicationHandler.java

666:    assertEquals(1, Integer.parseInt(getSlaveDetails("timesIndexReplicated")));
667:    String timesFailed = getSlaveDetails("timesFailed");
668:    assertEquals(0, Integer.parseInt(timesFailed != null ?  timesFailed : "0"));

getSlaveDetails() prints out the properties it retrieves as JSON following "SHALIN:" – see the log excerpt above. timesIndexReplicated is 2 instead of 1 because there was an unexpected replication failure: timesFailed is 1; if the assertion at line 666 were not there, then the one asserting zero replication failures, at line 668, would fail.

Issue Links

• relates to: SOLR-9036 Solr slave is doing full replication (entire index) of index after master restart
• relates to: SOLR-12078 Reproducable Failure in TestReplicationHandler.doTestIndexFetchOnMasterRestart