Build: https://jenkins.thetaphi.de/job/Lucene-Solr-master-Solaris/1906/ Java: 64bit/jdk1.8.0 -XX:+UseCompressedOops -XX:+UseG1GC
6 tests failed. FAILED: org.apache.lucene.index.TestIndexWriterWithThreads.testIOExceptionDuringAbortWithThreadsOnlyOnce Error Message: MockDirectoryWrapper: cannot close: there are still 23 open files: {_m.cfs=1, _7.cfs=1, _c.cfs=1, _h.cfs=1, _6.cfs=1, _d.cfs=1, _i.cfs=1, _0.cfs=1, _5.cfs=1, _j.cfs=1, _9.cfs=1, _e.cfs=1, _a.cfs=1, _n.cfs=1, _b.cfs=1, _g.cfs=1, _c.nvd=1, _3.cfs=1, _4.cfs=1, _k.cfs=1, _f.cfs=1, _8.cfs=1, _c.cfe=1} Stack Trace: java.lang.RuntimeException: MockDirectoryWrapper: cannot close: there are still 23 open files: {_m.cfs=1, _7.cfs=1, _c.cfs=1, _h.cfs=1, _6.cfs=1, _d.cfs=1, _i.cfs=1, _0.cfs=1, _5.cfs=1, _j.cfs=1, _9.cfs=1, _e.cfs=1, _a.cfs=1, _n.cfs=1, _b.cfs=1, _g.cfs=1, _c.nvd=1, _3.cfs=1, _4.cfs=1, _k.cfs=1, _f.cfs=1, _8.cfs=1, _c.cfe=1} at __randomizedtesting.SeedInfo.seed([113D581A3E105A8A:466B7FFB9BA11FD4]:0) at org.apache.lucene.store.MockDirectoryWrapper.close(MockDirectoryWrapper.java:841) at org.apache.lucene.index.TestIndexWriterWithThreads._testMultipleThreadsFailure(TestIndexWriterWithThreads.java:341) at org.apache.lucene.index.TestIndexWriterWithThreads.testIOExceptionDuringAbortWithThreadsOnlyOnce(TestIndexWriterWithThreads.java:464) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1737) at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:934) at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:970) at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:984) at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49) at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45) at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48) at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64) at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368) at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817) at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468) at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:943) at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:829) at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:879) at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:890) at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41) at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40) at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53) at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47) at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64) at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368) at java.lang.Thread.run(Thread.java:748) Caused by: java.lang.RuntimeException: unclosed IndexInput: _n.cfs at org.apache.lucene.store.MockDirectoryWrapper.addFileHandle(MockDirectoryWrapper.java:732) at org.apache.lucene.store.MockDirectoryWrapper.openInput(MockDirectoryWrapper.java:776) at org.apache.lucene.codecs.lucene50.Lucene50CompoundReader.<init>(Lucene50CompoundReader.java:78) at org.apache.lucene.codecs.lucene50.Lucene50CompoundFormat.getCompoundReader(Lucene50CompoundFormat.java:70) at org.apache.lucene.index.SegmentCoreReaders.<init>(SegmentCoreReaders.java:100) at org.apache.lucene.index.SegmentReader.<init>(SegmentReader.java:82) at org.apache.lucene.index.ReadersAndUpdates.getReader(ReadersAndUpdates.java:172) at org.apache.lucene.index.ReadersAndUpdates.getReaderForMerge(ReadersAndUpdates.java:709) at org.apache.lucene.index.IndexWriter.mergeMiddle(IndexWriter.java:4362) at org.apache.lucene.index.IndexWriter.merge(IndexWriter.java:4050) at org.apache.lucene.index.ConcurrentMergeScheduler.doMerge(ConcurrentMergeScheduler.java:625) at org.apache.lucene.index.ConcurrentMergeScheduler$MergeThread.run(ConcurrentMergeScheduler.java:662) FAILED: org.apache.solr.metrics.rrd.SolrRrdBackendFactoryTest.testBasic Error Message: one expected:<101> but was:<100> Stack Trace: java.lang.AssertionError: one expected:<101> but was:<100> at __randomizedtesting.SeedInfo.seed([EE28ED6983405874:45D2F07C5C9CDE5A]:0) at org.junit.Assert.fail(Assert.java:93) at org.junit.Assert.failNotEquals(Assert.java:647) at org.junit.Assert.assertEquals(Assert.java:128) at org.junit.Assert.assertEquals(Assert.java:472) at org.apache.solr.metrics.rrd.SolrRrdBackendFactoryTest.testBasic(SolrRrdBackendFactoryTest.java:113) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1737) at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:934) at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:970) at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:984) at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57) at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49) at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45) at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48) at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64) at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368) at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817) at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468) at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:943) at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:829) at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:879) at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:890) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57) at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41) at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40) at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53) at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47) at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64) at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368) at java.lang.Thread.run(Thread.java:748) FAILED: org.apache.solr.cloud.autoscaling.sim.TestComputePlanAction.testNodeAdded Error Message: ComputePlanAction should have computed exactly 1 operation, but was: [org.apache.solr.client.solrj.request.CollectionAdminRequest$MoveReplica@bdef0c1, org.apache.solr.client.solrj.request.CollectionAdminRequest$MoveReplica@63853803] expected:<1> but was:<2> Stack Trace: java.lang.AssertionError: ComputePlanAction should have computed exactly 1 operation, but was: [org.apache.solr.client.solrj.request.CollectionAdminRequest$MoveReplica@bdef0c1, org.apache.solr.client.solrj.request.CollectionAdminRequest$MoveReplica@63853803] expected:<1> but was:<2> at __randomizedtesting.SeedInfo.seed([EE28ED6983405874:8BEBBB1E21E3F077]:0) at org.junit.Assert.fail(Assert.java:93) at org.junit.Assert.failNotEquals(Assert.java:647) at org.junit.Assert.assertEquals(Assert.java:128) at org.junit.Assert.assertEquals(Assert.java:472) at org.apache.solr.cloud.autoscaling.sim.TestComputePlanAction.testNodeAdded(TestComputePlanAction.java:313) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1737) at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:934) at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:970) at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:984) at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57) at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49) at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45) at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48) at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64) at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368) at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817) at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468) at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:943) at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:829) at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:879) at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:890) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57) at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41) at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40) at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53) at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47) at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64) at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368) at java.lang.Thread.run(Thread.java:748) FAILED: org.apache.solr.cloud.autoscaling.sim.TestComputePlanAction.testNodeAdded Error Message: ComputePlanAction should have computed exactly 1 operation, but was: [org.apache.solr.client.solrj.request.CollectionAdminRequest$MoveReplica@5b2fe6a6, org.apache.solr.client.solrj.request.CollectionAdminRequest$MoveReplica@6e2ddb1b] expected:<1> but was:<2> Stack Trace: java.lang.AssertionError: ComputePlanAction should have computed exactly 1 operation, but was: [org.apache.solr.client.solrj.request.CollectionAdminRequest$MoveReplica@5b2fe6a6, org.apache.solr.client.solrj.request.CollectionAdminRequest$MoveReplica@6e2ddb1b] expected:<1> but was:<2> at __randomizedtesting.SeedInfo.seed([EE28ED6983405874:8BEBBB1E21E3F077]:0) at org.junit.Assert.fail(Assert.java:93) at org.junit.Assert.failNotEquals(Assert.java:647) at org.junit.Assert.assertEquals(Assert.java:128) at org.junit.Assert.assertEquals(Assert.java:472) at org.apache.solr.cloud.autoscaling.sim.TestComputePlanAction.testNodeAdded(TestComputePlanAction.java:313) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1737) at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:934) at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:970) at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:984) at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57) at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49) at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45) at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48) at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64) at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368) at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817) at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468) at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:943) at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:829) at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:879) at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:890) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57) at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41) at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40) at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53) at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47) at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64) at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368) at java.lang.Thread.run(Thread.java:748) FAILED: org.apache.solr.cloud.autoscaling.sim.TestComputePlanAction.testNodeAdded Error Message: ComputePlanAction should have computed exactly 1 operation, but was: [org.apache.solr.client.solrj.request.CollectionAdminRequest$MoveReplica@1cbe7949, org.apache.solr.client.solrj.request.CollectionAdminRequest$MoveReplica@2c758027] expected:<1> but was:<2> Stack Trace: java.lang.AssertionError: ComputePlanAction should have computed exactly 1 operation, but was: [org.apache.solr.client.solrj.request.CollectionAdminRequest$MoveReplica@1cbe7949, org.apache.solr.client.solrj.request.CollectionAdminRequest$MoveReplica@2c758027] expected:<1> but was:<2> at __randomizedtesting.SeedInfo.seed([EE28ED6983405874:8BEBBB1E21E3F077]:0) at org.junit.Assert.fail(Assert.java:93) at org.junit.Assert.failNotEquals(Assert.java:647) at org.junit.Assert.assertEquals(Assert.java:128) at org.junit.Assert.assertEquals(Assert.java:472) at org.apache.solr.cloud.autoscaling.sim.TestComputePlanAction.testNodeAdded(TestComputePlanAction.java:313) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1737) at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:934) at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:970) at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:984) at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57) at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49) at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45) at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48) at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64) at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368) at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817) at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468) at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:943) at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:829) at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:879) at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:890) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57) at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41) at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40) at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53) at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47) at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64) at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368) at java.lang.Thread.run(Thread.java:748) FAILED: org.apache.solr.cloud.autoscaling.sim.TestComputePlanAction.testNodeAdded Error Message: ComputePlanAction should have computed exactly 1 operation, but was: [org.apache.solr.client.solrj.request.CollectionAdminRequest$MoveReplica@2200341b, org.apache.solr.client.solrj.request.CollectionAdminRequest$MoveReplica@25cbbe48] expected:<1> but was:<2> Stack Trace: java.lang.AssertionError: ComputePlanAction should have computed exactly 1 operation, but was: [org.apache.solr.client.solrj.request.CollectionAdminRequest$MoveReplica@2200341b, org.apache.solr.client.solrj.request.CollectionAdminRequest$MoveReplica@25cbbe48] expected:<1> but was:<2> at __randomizedtesting.SeedInfo.seed([EE28ED6983405874:8BEBBB1E21E3F077]:0) at org.junit.Assert.fail(Assert.java:93) at org.junit.Assert.failNotEquals(Assert.java:647) at org.junit.Assert.assertEquals(Assert.java:128) at org.junit.Assert.assertEquals(Assert.java:472) at org.apache.solr.cloud.autoscaling.sim.TestComputePlanAction.testNodeAdded(TestComputePlanAction.java:313) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1737) at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:934) at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:970) at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:984) at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57) at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49) at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45) at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48) at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64) at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368) at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817) at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468) at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:943) at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:829) at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:879) at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:890) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57) at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41) at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40) at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53) at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47) at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64) at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368) at java.lang.Thread.run(Thread.java:748) Build Log: [...truncated 1055 lines...] [junit4] Suite: org.apache.lucene.index.TestIndexWriterWithThreads [junit4] 2> NOTE: reproduce with: ant test -Dtestcase=TestIndexWriterWithThreads -Dtests.method=testIOExceptionDuringAbortWithThreadsOnlyOnce -Dtests.seed=113D581A3E105A8A -Dtests.slow=true -Dtests.locale=es-VE -Dtests.timezone=America/Tegucigalpa -Dtests.asserts=true -Dtests.file.encoding=UTF-8 [junit4] ERROR 0.22s J1 | TestIndexWriterWithThreads.testIOExceptionDuringAbortWithThreadsOnlyOnce <<< [junit4] > Throwable #1: java.lang.RuntimeException: MockDirectoryWrapper: cannot close: there are still 23 open files: {_m.cfs=1, _7.cfs=1, _c.cfs=1, _h.cfs=1, _6.cfs=1, _d.cfs=1, _i.cfs=1, _0.cfs=1, _5.cfs=1, _j.cfs=1, _9.cfs=1, _e.cfs=1, _a.cfs=1, _n.cfs=1, _b.cfs=1, _g.cfs=1, _c.nvd=1, _3.cfs=1, _4.cfs=1, _k.cfs=1, _f.cfs=1, _8.cfs=1, _c.cfe=1} [junit4] > at __randomizedtesting.SeedInfo.seed([113D581A3E105A8A:466B7FFB9BA11FD4]:0) [junit4] > at org.apache.lucene.store.MockDirectoryWrapper.close(MockDirectoryWrapper.java:841) [junit4] > at org.apache.lucene.index.TestIndexWriterWithThreads._testMultipleThreadsFailure(TestIndexWriterWithThreads.java:341) [junit4] > at org.apache.lucene.index.TestIndexWriterWithThreads.testIOExceptionDuringAbortWithThreadsOnlyOnce(TestIndexWriterWithThreads.java:464) [junit4] > at java.lang.Thread.run(Thread.java:748) [junit4] > Caused by: java.lang.RuntimeException: unclosed IndexInput: _n.cfs [junit4] > at org.apache.lucene.store.MockDirectoryWrapper.addFileHandle(MockDirectoryWrapper.java:732) [junit4] > at org.apache.lucene.store.MockDirectoryWrapper.openInput(MockDirectoryWrapper.java:776) [junit4] > at org.apache.lucene.codecs.lucene50.Lucene50CompoundReader.<init>(Lucene50CompoundReader.java:78) [junit4] > at org.apache.lucene.codecs.lucene50.Lucene50CompoundFormat.getCompoundReader(Lucene50CompoundFormat.java:70) [junit4] > at org.apache.lucene.index.SegmentCoreReaders.<init>(SegmentCoreReaders.java:100) [junit4] > at org.apache.lucene.index.SegmentReader.<init>(SegmentReader.java:82) [junit4] > at org.apache.lucene.index.ReadersAndUpdates.getReader(ReadersAndUpdates.java:172) [junit4] > at org.apache.lucene.index.ReadersAndUpdates.getReaderForMerge(ReadersAndUpdates.java:709) [junit4] > at org.apache.lucene.index.IndexWriter.mergeMiddle(IndexWriter.java:4362) [junit4] > at org.apache.lucene.index.IndexWriter.merge(IndexWriter.java:4050) [junit4] > at org.apache.lucene.index.ConcurrentMergeScheduler.doMerge(ConcurrentMergeScheduler.java:625) [junit4] > at org.apache.lucene.index.ConcurrentMergeScheduler$MergeThread.run(ConcurrentMergeScheduler.java:662) [junit4] 2> NOTE: test params are: codec=Asserting(Lucene70): {date=PostingsFormat(name=LuceneVarGapFixedInterval), field=PostingsFormat(name=LuceneVarGapFixedInterval), docid=Lucene50(blocksize=128), titleTokenized=BlockTreeOrds(blocksize=128), id=Lucene50(blocksize=128), body=PostingsFormat(name=LuceneVarGapFixedInterval), title=Lucene50(blocksize=128)}, docValues:{dv=DocValuesFormat(name=Direct), docid_intDV=DocValuesFormat(name=Asserting), field=DocValuesFormat(name=Direct), ___soft_deletes=DocValuesFormat(name=Direct), titleDV=DocValuesFormat(name=Lucene70)}, maxPointsInLeafNode=870, maxMBSortInHeap=7.22230497409389, sim=Asserting(org.apache.lucene.search.similarities.AssertingSimilarity@420105d1), locale=es-VE, timezone=America/Tegucigalpa [junit4] 2> NOTE: SunOS 5.11 amd64/Oracle Corporation 1.8.0_172 (64-bit)/cpus=3,threads=1,free=103234328,total=536870912 [junit4] 2> NOTE: All tests run in this JVM: [TestSimpleAttributeImpl, TestWeakIdentityMap, TestIntRange, TestDisjunctionMaxQuery, TestSimilarity, TestMultiDocValues, TestMergeSchedulerExternal, TestNRTThreads, TestBKD, Test2BPoints, TestStressIndexing2, TestLucene50LiveDocsFormat, MultiCollectorTest, TestNotDocIdSet, TestSearch, TestSimpleExplanations, TestIndexWriterDelete, TestPendingDeletes, TestSpansEnum, TestFilterIterator, TestCharTermAttributeImpl, TestNoDeletionPolicy, TestGraphTokenizers, TestDirectPacked, TestIndexingSequenceNumbers, TestNRTReaderWithThreads, TestDoubleRangeFieldQueries, TestIndependenceSaturated, TestTrackingDirectoryWrapper, TestCompetitiveFreqNormAccumulator, TestMultiPhraseEnum, TestLMDirichletSimilarity, TestNRTCachingDirectory, TestSetOnce, TestDeterminism, TestFieldInfos, TestDistributionSPL, TestIndexWriterMaxDocs, TestForUtil, TestStopFilter, TestParallelTermEnum, TestMultiFields, TestPointValues, TestCodecHoldsOpenFiles, TestTransactions, TestTwoPhaseCommitTool, TestDoubleRange, TestFastCompressionMode, TestDirectoryReaderReopen, TestMatchNoDocsQuery, TestIntArrayDocIdSet, TestMmapDirectory, TestSpanOrQuery, TestNoMergePolicy, TestEarlyTermination, TestFuzzyQuery, TestPositionIncrement, TestIntRangeFieldQueries, TestTermVectorsReader, TestSameTokenSamePosition, TestSortedSetSelector, TestPerSegmentDeletes, TestMultiTermConstantScore, TestMaxTermFrequency, TestBytesRef, TestPostingsOffsets, TestTryDelete, TestSoftDeletesRetentionMergePolicy, TestSegmentTermDocs, TestByteSlices, TestBinaryDocValuesUpdates, TestBlockPostingsFormat2, TestTopFieldCollectorEarlyTermination, TestNativeFSLockFactory, TestTermsEnum2, TestAxiomaticF1LOG, TestExitableDirectoryReader, TestTermStates, TestIntroSorter, TestIndexWriterCommit, TestBytesRefHash, TestSPIClassIterator, TestSpanCollection, TestTimSorter, TestMathUtil, TestFilterDirectory, Test2BPostings, TestReqExclBulkScorer, TestLucene50StoredFieldsFormatHighCompression, TestFixedBitSet, TestPolygon, TestSearcherManager, TestDelegatingAnalyzerWrapper, TestNewestSegment, TestLucene70NormsFormat, TestSimpleSearchEquivalence, TestUniqueTermCount, TestBlockMaxConjunction, TestIndexWriterExceptions2, TestMutableValues, TestIndexWriterForceMerge, TestComplexExplanationsOfNonMatches, TestTermsEnum, TestCharsRefBuilder, FuzzyTermOnShortTermsTest, TestMutablePointsReaderUtils, TestBasicModelIF, TestPointQueries, TestFieldType, TestIndexOrDocValuesQuery, TestCloseableThreadLocal, TestBinaryDocument, TestBytesRefAttImpl, TestAxiomaticF3LOG, TestConstantScoreQuery, TestTerms, TestFlex, TestVirtualMethod, TestBoolean2, TestLucene60FieldInfoFormat, TestFilterSpans, TestPerFieldDocValuesFormat, TestAutomatonQuery, TestIndexWriter, TestIndexWriterReader, TestFSTs, TestBytesStore, TestPackedInts, TestIndexWriterWithThreads] [junit4] Completed [247/495 (1!)] on J1 in 2.04s, 13 tests, 1 error <<< FAILURES! [...truncated 13422 lines...] [junit4] Suite: org.apache.solr.cloud.autoscaling.sim.TestComputePlanAction [junit4] 2> Creating dataDir: /export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.sim.TestComputePlanAction_EE28ED6983405874-001/init-core-data-001 [junit4] 2> 2874405 DEBUG (SUITE-TestComputePlanAction-seed#[EE28ED6983405874]-worker) [ ] o.a.s.c.a.s.SimClusterStateProvider --- new Overseer leader: 127.0.0.1:10001_solr [junit4] 2> 2874405 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Adding .auto_add_replicas and .scheduled_maintenance triggers [junit4] 2> 2874406 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 0 [junit4] 2> 2874406 WARN (SUITE-TestComputePlanAction-seed#[EE28ED6983405874]-worker) [ ] o.a.s.h.a.MetricsHistoryHandler Missing .system, keeping metrics history in memory [junit4] 2> 2874406 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 0, lastZnodeVersion -1 [junit4] 2> 2874406 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 0 [junit4] 2> 2874406 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger .auto_add_replicas - Initial livenodes: [127.0.0.1:10001_solr] [junit4] 2> 2874406 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers [junit4] 2> 2874408 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 0, lastZnodeVersion 0 [junit4] 2> 2874408 DEBUG (ScheduledTrigger-13048-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1 [junit4] 2> 2874410 DEBUG (TEST-TestComputePlanAction.testNodeLost-seed#[EE28ED6983405874]) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 1 [junit4] 2> 2874410 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 1 [junit4] 2> 2874411 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeLost markers [junit4] 2> 2874411 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers [junit4] 2> 2874411 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion 1 [junit4] 2> 2874412 INFO (TEST-TestComputePlanAction.testNodeLost-seed#[EE28ED6983405874]) [ ] o.a.s.c.a.s.SimCloudManager === Restarting OverseerTriggerThread and clearing object cache... [junit4] 2> 2874412 WARN (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting. [junit4] 2> 2874412 DEBUG (TEST-TestComputePlanAction.testNodeLost-seed#[EE28ED6983405874]) [ ] o.a.s.c.a.ScheduledTriggers Shutting down scheduled thread pool executor now [junit4] 2> 2874412 DEBUG (TEST-TestComputePlanAction.testNodeLost-seed#[EE28ED6983405874]) [ ] o.a.s.c.a.ScheduledTriggers Shutting down action executor now [junit4] 2> 2874413 DEBUG (TEST-TestComputePlanAction.testNodeLost-seed#[EE28ED6983405874]) [ ] o.a.s.c.a.ScheduledTriggers Awaiting termination for action executor [junit4] 2> 2874413 DEBUG (TEST-TestComputePlanAction.testNodeLost-seed#[EE28ED6983405874]) [ ] o.a.s.c.a.ScheduledTriggers Awaiting termination for scheduled thread pool executor [junit4] 2> 2874413 DEBUG (TEST-TestComputePlanAction.testNodeLost-seed#[EE28ED6983405874]) [ ] o.a.s.c.a.ScheduledTriggers ScheduledTriggers closed completely [junit4] 2> 2874413 DEBUG (TEST-TestComputePlanAction.testNodeLost-seed#[EE28ED6983405874]) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly [junit4] 2> 2874413 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Adding .auto_add_replicas and .scheduled_maintenance triggers [junit4] 2> 2874414 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 2 [junit4] 2> 2874414 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 2, lastZnodeVersion -1 [junit4] 2> 2874414 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 2 [junit4] 2> 2874414 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger .auto_add_replicas - Initial livenodes: [127.0.0.1:10001_solr] [junit4] 2> 2874414 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers [junit4] 2> 2874414 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 2, lastZnodeVersion 2 [junit4] 2> 2874414 DEBUG (ScheduledTrigger-13053-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1 [junit4] 2> 2874436 DEBUG (ScheduledTrigger-13053-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1 [junit4] 2> 2874457 DEBUG (ScheduledTrigger-13053-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1 [junit4] 2> 2874477 DEBUG (ScheduledTrigger-13053-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1 [junit4] 2> 2874497 DEBUG (ScheduledTrigger-13053-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1 [junit4] 2> 2874517 DEBUG (ScheduledTrigger-13053-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1 [junit4] 2> 2874529 DEBUG (simCloudManagerPool-13052-thread-1) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration [junit4] 2> 2874529 DEBUG (simCloudManagerPool-13052-thread-1) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 3 [junit4] 2> 2874530 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 3 [junit4] 2> 2874530 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers [junit4] 2> 2874530 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 3, lastZnodeVersion 3 [junit4] 2> 2874531 DEBUG (simCloudManagerPool-13052-thread-2) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration [junit4] 2> 2874532 DEBUG (simCloudManagerPool-13052-thread-2) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 4 [junit4] 2> 2874532 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 4 [junit4] 2> 2874532 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers [junit4] 2> 2874532 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 4, lastZnodeVersion 4 [junit4] 2> 2874537 DEBUG (ScheduledTrigger-13053-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1 [junit4] 2> 2874558 DEBUG (ScheduledTrigger-13053-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1 [junit4] 2> 2874578 DEBUG (ScheduledTrigger-13053-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1 [junit4] 2> 2874599 DEBUG (ScheduledTrigger-13053-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1 [junit4] 2> 2874619 DEBUG (ScheduledTrigger-13053-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1 [junit4] 2> 2874636 DEBUG (simCloudManagerPool-13052-thread-3) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration [junit4] 2> 2874636 DEBUG (simCloudManagerPool-13052-thread-3) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 5 [junit4] 2> 2874636 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 5 [junit4] 2> 2874637 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger node_lost_trigger - Initial livenodes: [127.0.0.1:10001_solr, 127.0.0.1:10002_solr] [junit4] 2> 2874637 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers [junit4] 2> 2874637 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 5, lastZnodeVersion 5 [junit4] 2> 2874637 DEBUG (ScheduledTrigger-13053-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 2 [junit4] 2> 2874637 DEBUG (simCloudManagerPool-13052-thread-4) [ ] o.a.s.c.o.ClusterStateMutator building a new cName: testNodeLost [junit4] 2> 2874639 DEBUG (ScheduledTrigger-13053-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 2874653 DEBUG (simCloudManagerPool-13052-thread-4) [ ] o.a.s.c.s.c.a.PolicyHelper Creating a new session [junit4] 2> 2874656 DEBUG (simCloudManagerPool-13052-thread-4) [ ] o.a.s.c.s.c.a.PolicyHelper New session created [junit4] 2> 2874658 DEBUG (ScheduledTrigger-13053-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 2 [junit4] 2> 2874659 DEBUG (ScheduledTrigger-13053-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 2874665 INFO (simCloudManagerPool-13052-thread-4) [ ] o.a.s.c.s.c.a.PolicyHelper returnSession, curr-time 3376357843 sessionWrapper.createTime 3376357387213516, this.sessionWrapper.createTime 3376357387213516 [junit4] 2> 2874665 DEBUG (simCloudManagerPool-13052-thread-4) [ ] o.a.s.c.s.c.a.PolicyHelper session set to NULL [junit4] 2> 2874679 DEBUG (ScheduledTrigger-13053-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 2 [junit4] 2> 2874680 DEBUG (ScheduledTrigger-13053-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 2874687 DEBUG (TEST-TestComputePlanAction.testNodeLost-seed#[EE28ED6983405874]) [ ] o.a.s.c.a.s.TestComputePlanAction -- cluster state: znodeVersion: 4 [junit4] 2> live nodes:[127.0.0.1:10001_solr, 127.0.0.1:10002_solr] [junit4] 2> collections:{testNodeLost=DocCollection(testNodeLost//clusterstate.json/3)={ [junit4] 2> "replicationFactor":"2", [junit4] 2> "pullReplicas":"0", [junit4] 2> "router":{"name":"compositeId"}, [junit4] 2> "maxShardsPerNode":"1", [junit4] 2> "autoAddReplicas":"false", [junit4] 2> "nrtReplicas":"2", [junit4] 2> "tlogReplicas":"0", [junit4] 2> "autoCreated":"true", [junit4] 2> "shards":{"shard1":{ [junit4] 2> "replicas":{ [junit4] 2> "core_node1":{ [junit4] 2> "core":"testNodeLost_shard1_replica_n1", [junit4] 2> "SEARCHER.searcher.maxDoc":0, [junit4] 2> "SEARCHER.searcher.deletedDocs":0, [junit4] 2> "INDEX.sizeInBytes":1, [junit4] 2> "node_name":"127.0.0.1:10002_solr", [junit4] 2> "state":"active", [junit4] 2> "type":"NRT", [junit4] 2> "SEARCHER.searcher.numDocs":0}, [junit4] 2> "core_node2":{ [junit4] 2> "core":"testNodeLost_shard1_replica_n2", [junit4] 2> "SEARCHER.searcher.maxDoc":0, [junit4] 2> "SEARCHER.searcher.deletedDocs":0, [junit4] 2> "INDEX.sizeInBytes":1, [junit4] 2> "node_name":"127.0.0.1:10001_solr", [junit4] 2> "state":"active", [junit4] 2> "type":"NRT", [junit4] 2> "SEARCHER.searcher.numDocs":0}}, [junit4] 2> "range":"80000000-7fffffff", [junit4] 2> "state":"active"}}}} [junit4] 2> 2874688 INFO (TEST-TestComputePlanAction.testNodeLost-seed#[EE28ED6983405874]) [ ] o.a.s.c.a.s.TestComputePlanAction Stopped_node : 127.0.0.1:10002_solr [junit4] 2> 2874689 DEBUG (simCloudManagerPool-13052-thread-8) [ ] o.a.s.c.a.s.SimClusterStateProvider -- elected new leader for testNodeLost / shard1: {"core_node2":{ [junit4] 2> "core":"testNodeLost_shard1_replica_n2", [junit4] 2> "leader":"true", [junit4] 2> "SEARCHER.searcher.maxDoc":0, [junit4] 2> "SEARCHER.searcher.deletedDocs":0, [junit4] 2> "INDEX.sizeInBytes":1, [junit4] 2> "node_name":"127.0.0.1:10001_solr", [junit4] 2> "state":"active", [junit4] 2> "type":"NRT", [junit4] 2> "SEARCHER.searcher.numDocs":0, [junit4] 2> "shard":"shard1", [junit4] 2> "collection":"testNodeLost"}} [junit4] 2> 2874704 DEBUG (ScheduledTrigger-13053-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 2 [junit4] 2> 2874705 DEBUG (ScheduledTrigger-13053-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 2874705 DEBUG (ScheduledTrigger-13053-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Tracking lost node: 127.0.0.1:10002_solr [junit4] 2> 2874705 DEBUG (ScheduledTrigger-13053-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Tracking lost node: 127.0.0.1:10002_solr [junit4] 2> 2874730 DEBUG (ScheduledTrigger-13053-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 2 [junit4] 2> 2874730 DEBUG (ScheduledTrigger-13053-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 2874750 DEBUG (ScheduledTrigger-13053-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 2 [junit4] 2> 2874750 DEBUG (ScheduledTrigger-13053-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 2874771 DEBUG (ScheduledTrigger-13053-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 2 [junit4] 2> 2874771 DEBUG (ScheduledTrigger-13053-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 2874794 DEBUG (ScheduledTrigger-13053-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 2 [junit4] 2> 2874795 DEBUG (ScheduledTrigger-13053-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 2874821 DEBUG (ScheduledTrigger-13053-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 2 [junit4] 2> 2874821 DEBUG (ScheduledTrigger-13053-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 2874842 DEBUG (ScheduledTrigger-13053-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 2 [junit4] 2> 2874842 DEBUG (ScheduledTrigger-13053-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 2874864 DEBUG (ScheduledTrigger-13053-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 2874865 DEBUG (ScheduledTrigger-13053-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 2 [junit4] 2> 2874865 DEBUG (ScheduledTrigger-13053-thread-3) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger firing registered processor for lost nodes: [127.0.0.1:10002_solr] [junit4] 2> 2874865 DEBUG (ScheduledTrigger-13053-thread-3) [ ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: { [junit4] 2> "id":"bfec807743e24T9m9xb0oetrzy4h43664fwmvb2", [junit4] 2> "source":"node_lost_trigger", [junit4] 2> "eventTime":3376359815790116, [junit4] 2> "eventType":"NODELOST", [junit4] 2> "properties":{ [junit4] 2> "eventTimes":[3376359815790116], [junit4] 2> "nodeNames":["127.0.0.1:10002_solr"]}} [junit4] 2> 2874865 DEBUG (ScheduledTrigger-13053-thread-3) [ ] o.a.s.c.a.ScheduledTriggers Pausing all triggers: [.auto_add_replicas, .scheduled_maintenance, node_lost_trigger] [junit4] 2> 2874866 DEBUG (simCloudManagerPool-13052-thread-9) [ ] o.a.s.c.o.ClusterStateMutator building a new cName: .system [junit4] 2> 2874881 DEBUG (simCloudManagerPool-13052-thread-9) [ ] o.a.s.c.s.c.a.PolicyHelper Creating a new session [junit4] 2> 2874882 DEBUG (simCloudManagerPool-13052-thread-9) [ ] o.a.s.c.s.c.a.PolicyHelper New session created [junit4] 2> 2874882 INFO (simCloudManagerPool-13052-thread-9) [ ] o.a.s.c.s.c.a.PolicyHelper returnSession, curr-time 3376368703 sessionWrapper.createTime 3376368678056816, this.sessionWrapper.createTime 3376368678056816 [junit4] 2> 2874882 DEBUG (simCloudManagerPool-13052-thread-9) [ ] o.a.s.c.s.c.a.PolicyHelper session set to NULL [junit4] 2> 2874883 WARN (ScheduledTrigger-13053-thread-3) [ ] o.a.s.c.a.SystemLogListener Exception sending event to collection .system [junit4] 2> java.io.IOException: java.util.concurrent.ExecutionException: java.io.IOException: org.apache.solr.common.SolrException: Collection .system doesn't exist. [junit4] 2> at org.apache.solr.cloud.autoscaling.sim.SimCloudManager.request(SimCloudManager.java:621) ~[test/:?] [junit4] 2> at org.apache.solr.cloud.autoscaling.SystemLogListener.onEvent(SystemLogListener.java:118) ~[java/:?] [junit4] 2> at org.apache.solr.cloud.autoscaling.ScheduledTriggers$TriggerListeners.fireListeners(ScheduledTriggers.java:789) ~[java/:?] [junit4] 2> at org.apache.solr.cloud.autoscaling.ScheduledTriggers$TriggerListeners.fireListeners(ScheduledTriggers.java:756) ~[java/:?] [junit4] 2> at org.apache.solr.cloud.autoscaling.ScheduledTriggers.lambda$add$4(ScheduledTriggers.java:282) ~[java/:?] [junit4] 2> at org.apache.solr.cloud.autoscaling.NodeLostTrigger.run(NodeLostTrigger.java:157) [java/:?] [junit4] 2> at org.apache.solr.cloud.autoscaling.ScheduledTriggers$TriggerWrapper.run(ScheduledTriggers.java:588) [java/:?] [junit4] 2> at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:1.8.0_172] [junit4] 2> at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308) [?:1.8.0_172] [junit4] 2> at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180) [?:1.8.0_172] [junit4] 2> at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294) [?:1.8.0_172] [junit4] 2> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_172] [junit4] 2> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_172] [junit4] 2> at java.lang.Thread.run(Thread.java:748) [?:1.8.0_172] [junit4] 2> Caused by: java.util.concurrent.ExecutionException: java.io.IOException: org.apache.solr.common.SolrException: Collection .system doesn't exist. [junit4] 2> at java.util.concurrent.FutureTask.report(FutureTask.java:122) ~[?:1.8.0_172] [junit4] 2> at java.util.concurrent.FutureTask.get(FutureTask.java:192) ~[?:1.8.0_172] [junit4] 2> at org.apache.solr.cloud.autoscaling.sim.SimCloudManager.request(SimCloudManager.java:619) ~[test/:?] [junit4] 2> ... 13 more [junit4] 2> Caused by: java.io.IOException: org.apache.solr.common.SolrException: Collection .system doesn't exist. [junit4] 2> at org.apache.solr.cloud.autoscaling.sim.SimClusterStateProvider.simUpdate(SimClusterStateProvider.java:1201) ~[test/:?] [junit4] 2> at org.apache.solr.cloud.autoscaling.sim.SimCloudManager.simHandleSolrRequest(SimCloudManager.java:691) ~[test/:?] [junit4] 2> at org.apache.solr.cloud.autoscaling.sim.SimCloudManager.lambda$request$15(SimCloudManager.java:618) ~[test/:?] [junit4] 2> at java.util.concurrent.FutureTask.run(FutureTask.java:266) ~[?:1.8.0_172] [junit4] 2> at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:209) ~[java/:?] [junit4] 2> ... 3 more [junit4] 2> Caused by: org.apache.solr.common.SolrException: Collection .system doesn't exist. [junit4] 2> at org.apache.solr.cloud.autoscaling.sim.SimClusterStateProvider.simSetShardValue(SimClusterStateProvider.java:1392) ~[test/:?] [junit4] 2> at org.apache.solr.cloud.autoscaling.sim.SimClusterStateProvider.simUpdate(SimClusterStateProvider.java:1195) ~[test/:?] [junit4] 2> at org.apache.solr.cloud.autoscaling.sim.SimCloudManager.simHandleSolrRequest(SimCloudManager.java:691) ~[test/:?] [junit4] 2> at org.apache.solr.cloud.autoscaling.sim.SimCloudManager.lambda$request$15(SimCloudManager.java:618) ~[test/:?] [junit4] 2> at java.util.concurrent.FutureTask.run(FutureTask.java:266) ~[?:1.8.0_172] [junit4] 2> at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:209) ~[java/:?] [junit4] 2> ... 3 more [junit4] 2> 2874885 DEBUG (AutoscalingActionExecutor-13054-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing actions for { [junit4] 2> "id":"bfec807743e24T9m9xb0oetrzy4h43664fwmvb2", [junit4] 2> "source":"node_lost_trigger", [junit4] 2> "eventTime":3376359815790116, [junit4] 2> "eventType":"NODELOST", [junit4] 2> "properties":{ [junit4] 2> "eventTimes":[3376359815790116], [junit4] 2> "_enqueue_time_":3376367850216666, [junit4] 2> "nodeNames":["127.0.0.1:10002_solr"]}} [junit4] 2> 2874886 DEBUG (AutoscalingActionExecutor-13054-thread-1) [ ] o.a.s.c.a.ComputePlanAction -- processing event: { [junit4] 2> "id":"bfec807743e24T9m9xb0oetrzy4h43664fwmvb2", [junit4] 2> "source":"node_lost_trigger", [junit4] 2> "eventTime":3376359815790116, [junit4] 2> "eventType":"NODELOST", [junit4] 2> "properties":{ [junit4] 2> "eventTimes":[3376359815790116], [junit4] 2> "_enqueue_time_":3376367850216666, [junit4] 2> "nodeNames":["127.0.0.1:10002_solr"]}} with context properties: {BEFORE_ACTION=[compute_plan]} [junit4] 2> 2874886 DEBUG (AutoscalingActionExecutor-13054-thread-1) [ ] o.a.s.c.s.c.a.PolicyHelper Creating a new session [junit4] 2> 2874886 DEBUG (AutoscalingActionExecutor-13054-thread-1) [ ] o.a.s.c.s.c.a.PolicyHelper New session created [junit4] 2> 2874887 INFO (AutoscalingActionExecutor-13054-thread-1) [ ] o.a.s.c.a.ComputePlanAction Computed Plan: action=MOVEREPLICA&collection=testNodeLost&targetNode=127.0.0.1:10003_solr&inPlaceMove=true&replica=core_node1 [junit4] 2> 2874887 INFO (AutoscalingActionExecutor-13054-thread-1) [ ] o.a.s.c.s.c.a.PolicyHelper returnSession, curr-time 3376368959 sessionWrapper.createTime 3376368906938716, this.sessionWrapper.createTime 3376368906938716 [junit4] 2> 2874887 DEBUG (AutoscalingActionExecutor-13054-thread-1) [ ] o.a.s.c.s.c.a.PolicyHelper session set to NULL [junit4] 2> 2874896 INFO (TEST-TestComputePlanAction.testNodeLost-seed#[EE28ED6983405874]) [ ] o.a.s.c.a.s.TestComputePlanAction -------------_ FINAL STATE -------------- [junit4] 2> 2874896 INFO (TEST-TestComputePlanAction.testNodeLost-seed#[EE28ED6983405874]) [ ] o.a.s.c.a.s.TestComputePlanAction * Node values: { [junit4] 2> "127.0.0.1:10001_solr":{ [junit4] 2> "sysprop.java.vendor":"Oracle Corporation", [junit4] 2> "cores":1, [junit4] 2> "host":"127.0.0.1", [junit4] 2> "freedisk":999, [junit4] 2> "sysprop.java.version":"1.8.0_172", [junit4] 2> "ip_1":"127", [junit4] 2> "ip_3":"0", [junit4] 2> "ip_2":"0", [junit4] 2> "ip_4":"1", [junit4] 2> "node":"127.0.0.1:10001_solr", [junit4] 2> "metrics:solr.jvm:buffers.direct.Count":0, [junit4] 2> "port":10001, [junit4] 2> "heapUsage":123450000, [junit4] 2> "sysLoadAvg":1.0, [junit4] 2> "metrics:solr.node:ADMIN./admin/authorization.clientErrors:count":0}, [junit4] 2> "127.0.0.1:10002_solr":{ [junit4] 2> "sysprop.java.vendor":"Oracle Corporation", [junit4] 2> "cores":1, [junit4] 2> "host":"127.0.0.1", [junit4] 2> "freedisk":999, [junit4] 2> "sysprop.java.version":"1.8.0_172", [junit4] 2> "ip_1":"127", [junit4] 2> "ip_3":"0", [junit4] 2> "ip_2":"0", [junit4] 2> "ip_4":"1", [junit4] 2> "node":"127.0.0.1:10002_solr", [junit4] 2> "metrics:solr.jvm:buffers.direct.Count":0, [junit4] 2> "port":10002, [junit4] 2> "heapUsage":123450000, [junit4] 2> "sysLoadAvg":1.0, [junit4] 2> "metrics:solr.node:ADMIN./admin/authorization.clientErrors:count":0}, [junit4] 2> "127.0.0.1:10003_solr":{ [junit4] 2> "sysprop.java.vendor":"Oracle Corporation", [junit4] 2> "cores":1, [junit4] 2> "host":"127.0.0.1", [junit4] 2> "freedisk":999, [junit4] 2> "sysprop.java.version":"1.8.0_172", [junit4] 2> "ip_1":"127", [junit4] 2> "ip_3":"0", [junit4] 2> "ip_2":"0", [junit4] 2> "ip_4":"1", [junit4] 2> "node":"127.0.0.1:10003_solr", [junit4] 2> "metrics:solr.jvm:buffers.direct.Count":0, [junit4] 2> "port":10003, [junit4] 2> "heapUsage":123450000, [junit4] 2> "sysLoadAvg":1.0, [junit4] 2> "metrics:solr.node:ADMIN./admin/authorization.clientErrors:count":0}} [junit4] 2> 2874897 INFO (TEST-TestComputePlanAction.testNodeLost-seed#[EE28ED6983405874]) [ ] o.a.s.c.a.s.TestComputePlanAction * Live nodes: [127.0.0.1:10001_solr] [junit4] 2> 2874897 INFO (TEST-TestComputePlanAction.testNodeLost-seed#[EE28ED6983405874]) [ ] o.a.s.c.a.s.TestComputePlanAction * Collection .system state: DocCollection(.system//clusterstate.json/10)={ [junit4] 2> "replicationFactor":"1", [junit4] 2> "pullReplicas":"0", [junit4] 2> "router":{"name":"compositeId"}, [junit4] 2> "maxShardsPerNode":"1", [junit4] 2> "autoAddReplicas":"false", [junit4] 2> "nrtReplicas":"1", [junit4] 2> "tlogReplicas":"0", [junit4] 2> "autoCreated":"true", [junit4] 2> "shards":{"shard1":{ [junit4] 2> "replicas":{"core_node1":{ [junit4] 2> "core":".system_shard1_replica_n1", [junit4] 2> "SEARCHER.searcher.maxDoc":1, [junit4] 2> "SEARCHER.searcher.deletedDocs":0, [junit4] 2> "INDEX.sizeInBytes":1, [junit4] 2> "node_name":"127.0.0.1:10003_solr", [junit4] 2> "state":"down", [junit4] 2> "type":"NRT", [junit4] 2> "SEARCHER.searcher.numDocs":1}}, [junit4] 2> "range":"80000000-7fffffff", [junit4] 2> "state":"active"}}} [junit4] 2> 2874897 INFO (TEST-TestComputePlanAction.testNodeLost-seed#[EE28ED6983405874]) [ ] o.a.s.c.a.s.TestComputePlanAction * Collection testNodeLost state: DocCollection(testNodeLost//clusterstate.json/10)={ [junit4] 2> "replicationFactor":"2", [junit4] 2> "pullReplicas":"0", [junit4] 2> "router":{"name":"compositeId"}, [junit4] 2> "maxShardsPerNode":"1", [junit4] 2> "autoAddReplicas":"false", [junit4] 2> "nrtReplicas":"2", [junit4] 2> "tlogReplicas":"0", [junit4] 2> "autoCreated":"true", [junit4] 2> "shards":{"shard1":{ [junit4] 2> "replicas":{ [junit4] 2> "core_node1":{ [junit4] 2> "core":"testNodeLost_shard1_replica_n1", [junit4] 2> "SEARCHER.searcher.maxDoc":0, [junit4] 2> "SEARCHER.searcher.deletedDocs":0, [junit4] 2> "INDEX.sizeInBytes":1, [junit4] 2> "node_name":"127.0.0.1:10002_solr", [junit4] 2> "state":"down", [junit4] 2> "type":"NRT", [junit4] 2> "SEARCHER.searcher.numDocs":0}, [junit4] 2> "core_node2":{ [junit4] 2> "core":"testNodeLost_shard1_replica_n2", [junit4] 2> "leader":"true", [junit4] 2> "SEARCHER.searcher.maxDoc":0, [junit4] 2> "SEARCHER.searcher.deletedDocs":0, [junit4] 2> "INDEX.sizeInBytes":1, [junit4] 2> "node_name":"127.0.0.1:10001_solr", [junit4] 2> "state":"active", [junit4] 2> "type":"NRT", [junit4] 2> "SEARCHER.searcher.numDocs":0}}, [junit4] 2> "range":"80000000-7fffffff", [junit4] 2> "state":"active"}}} [junit4] 2> 2874898 WARN (simCloudManagerPool-13052-thread-14) [ ] o.a.s.c.a.s.SimClusterStateProvider -- can't find any active replicas for .system / shard1 [junit4] 2> 2874899 DEBUG (AutoscalingActionExecutor-13054-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: .auto_add_replicas after 100ms [junit4] 2> 2874899 DEBUG (AutoscalingActionExecutor-13054-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: .scheduled_maintenance after 100ms [junit4] 2> 2874899 DEBUG (AutoscalingActionExecutor-13054-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: node_lost_trigger after 100ms [junit4] 2> 2874899 DEBUG (AutoscalingActionExecutor-13054-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing took 678 ms for event id=bfec807743e24T9m9xb0oetrzy4h43664fwmvb2 [junit4] 2> 2874903 INFO (TEST-TestComputePlanAction.testNodeLost-seed#[EE28ED6983405874]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ####################################### [junit4] 2> ############ CLUSTER STATE ############ [junit4] 2> ####################################### [junit4] 2> ## Live nodes: 1 [junit4] 2> ## Empty nodes: 0 [junit4] 2> ## Dead nodes: 2 [junit4] 2> ## 127.0.0.1:10002_solr [junit4] 2> ## 127.0.0.1:10003_solr [junit4] 2> ## Collections: [.system, testNodeLost] [junit4] 2> ## Max replicas per node: 1 [junit4] 2> ## Min replicas per node: 1 [junit4] 2> ## Total replicas: 1 [junit4] 2> ## * testNodeLost 1 [junit4] 2> ## - active 1 [junit4] 2> ######### Solr op counts ########## [junit4] 2> ## - CREATE 1 [junit4] 2> ## - autoscaling 3 [junit4] 2> ## - update 4 [junit4] 2> ######### Autoscaling event counts ########### [junit4] 2> ## * Trigger: node_lost_trigger [junit4] 2> ## - AFTER_ACTION 1 [junit4] 2> ## - BEFORE_ACTION 1 [junit4] 2> ## - SUCCEEDED 1 [junit4] 2> [junit4] 2> 2874913 DEBUG (TEST-TestComputePlanAction.testNodeWithMultipleReplicasLost-seed#[EE28ED6983405874]) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 6 [junit4] 2> 2874913 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 6 [junit4] 2> 2874913 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeLost markers [junit4] 2> 2874913 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers [junit4] 2> 2874913 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 6, lastZnodeVersion 6 [junit4] 2> 2874913 DEBUG (TEST-TestComputePlanAction.testNodeWithMultipleReplicasLost-seed#[EE28ED6983405874]) [ ] o.a.s.c.a.s.SimNodeStateProvider - removing dead node values: 127.0.0.1:10002_solr [junit4] 2> 2874913 DEBUG (TEST-TestComputePlanAction.testNodeWithMultipleReplicasLost-seed#[EE28ED6983405874]) [ ] o.a.s.c.a.s.SimNodeStateProvider - removing dead node values: 127.0.0.1:10003_solr [junit4] 2> 2874913 INFO (TEST-TestComputePlanAction.testNodeWithMultipleReplicasLost-seed#[EE28ED6983405874]) [ ] o.a.s.c.a.s.SimCloudManager === Restarting OverseerTriggerThread and clearing object cache... [junit4] 2> 2874914 DEBUG (TEST-TestComputePlanAction.testNodeWithMultipleReplicasLost-seed#[EE28ED6983405874]) [ ] o.a.s.c.a.ScheduledTriggers Shutting down scheduled thread pool executor now [junit4] 2> 2874914 DEBUG (TEST-TestComputePlanAction.testNodeWithMultipleReplicasLost-seed#[EE28ED6983405874]) [ ] o.a.s.c.a.ScheduledTriggers Shutting down action executor now [junit4] 2> 2874914 DEBUG (TEST-TestComputePlanAction.testNodeWithMultipleReplicasLost-seed#[EE28ED6983405874]) [ ] o.a.s.c.a.ScheduledTriggers Awaiting termination for action executor [junit4] 2> 2874914 WARN (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting. [junit4] 2> 2874914 DEBUG (TEST-TestComputePlanAction.testNodeWithMultipleReplicasLost-seed#[EE28ED6983405874]) [ ] o.a.s.c.a.ScheduledTriggers Awaiting termination for scheduled thread pool executor [junit4] 2> 2874914 DEBUG (TEST-TestComputePlanAction.testNodeWithMultipleReplicasLost-seed#[EE28ED6983405874]) [ ] o.a.s.c.a.ScheduledTriggers ScheduledTriggers closed completely [junit4] 2> 2874914 DEBUG (TEST-TestComputePlanAction.testNodeWithMultipleReplicasLost-seed#[EE28ED6983405874]) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly [junit4] 2> 2874918 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Adding .auto_add_replicas and .scheduled_maintenance triggers [junit4] 2> 2874918 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 7 [junit4] 2> 2874919 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 7, lastZnodeVersion -1 [junit4] 2> 2874919 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 7 [junit4] 2> 2874920 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger .auto_add_replicas - Initial livenodes: [127.0.0.1:10001_solr] [junit4] 2> 2874921 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers [junit4] 2> 2874921 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 7, lastZnodeVersion 7 [junit4] 2> 2874921 DEBUG (ScheduledTrigger-13056-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1 [junit4] 2> 2874941 DEBUG (ScheduledTrigger-13056-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1 [junit4] 2> 2874962 DEBUG (ScheduledTrigger-13056-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1 [junit4] 2> 2874983 DEBUG (ScheduledTrigger-13056-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1 [junit4] 2> 2875004 DEBUG (ScheduledTrigger-13056-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1 [junit4] 2> 2875016 DEBUG (simCloudManagerPool-13055-thread-1) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration [junit4] 2> 2875016 DEBUG (simCloudManagerPool-13055-thread-1) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 8 [junit4] 2> 2875017 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 8 [junit4] 2> 2875017 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers [junit4] 2> 2875017 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 8, lastZnodeVersion 8 [junit4] 2> 2875017 DEBUG (simCloudManagerPool-13055-thread-2) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration [junit4] 2> 2875018 DEBUG (simCloudManagerPool-13055-thread-2) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 9 [junit4] 2> 2875018 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 9 [junit4] 2> 2875018 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers [junit4] 2> 2875018 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 9, lastZnodeVersion 9 [junit4] 2> 2875024 DEBUG (ScheduledTrigger-13056-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1 [junit4] 2> 2875044 DEBUG (ScheduledTrigger-13056-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1 [junit4] 2> 2875064 DEBUG (ScheduledTrigger-13056-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1 [junit4] 2> 2875085 DEBUG (ScheduledTrigger-13056-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1 [junit4] 2> 2875105 DEBUG (ScheduledTrigger-13056-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1 [junit4] 2> 2875120 DEBUG (simCloudManagerPool-13055-thread-3) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration [junit4] 2> 2875120 DEBUG (simCloudManagerPool-13055-thread-3) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 10 [junit4] 2> 2875120 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 10 [junit4] 2> 2875121 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger node_lost_trigger - Initial livenodes: [127.0.0.1:10001_solr, 127.0.0.1:10004_solr, 127.0.0.1:10006_solr, 127.0.0.1:10005_solr] [junit4] 2> 2875121 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers [junit4] 2> 2875121 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 10, lastZnodeVersion 10 [junit4] 2> 2875121 DEBUG (ScheduledTrigger-13056-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 4 [junit4] 2> 2875121 DEBUG (simCloudManagerPool-13055-thread-4) [ ] o.a.s.c.o.ClusterStateMutator building a new cName: testNodeWithMultipleReplicasLost [junit4] 2> 2875125 DEBUG (ScheduledTrigger-13056-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 4 [junit4] 2> 2875135 DEBUG (simCloudManagerPool-13055-thread-4) [ ] o.a.s.c.s.c.a.PolicyHelper Creating a new session [junit4] 2> 2875135 DEBUG (simCloudManagerPool-13055-thread-4) [ ] o.a.s.c.s.c.a.PolicyHelper New session created [junit4] 2> 2875137 INFO (simCloudManagerPool-13055-thread-4) [ ] o.a.s.c.s.c.a.PolicyHelper returnSession, curr-time 3376381455 sessionWrapper.createTime 3376381344495916, this.sessionWrapper.createTime 3376381344495916 [junit4] 2> 2875137 DEBUG (simCloudManagerPool-13055-thread-4) [ ] o.a.s.c.s.c.a.PolicyHelper session set to NULL [junit4] 2> 2875141 DEBUG (ScheduledTrigger-13056-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 4 [junit4] 2> 2875149 DEBUG (ScheduledTrigger-13056-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 4 [junit4] 2> 2875162 DEBUG (ScheduledTrigger-13056-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 4 [junit4] 2> 2875170 DEBUG (ScheduledTrigger-13056-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 4 [junit4] 2> 2875172 DEBUG (simCloudManagerPool-13055-thread-11) [ ] o.a.s.c.a.s.SimClusterStateProvider -- elected new leader for testNodeWithMultipleReplicasLost / shard2: {"core_node4":{ [junit4] 2> "core":"testNodeWithMultipleReplicasLost_shard2_replica_n4", [junit4] 2> "leader":"true", [junit4] 2> "SEARCHER.searcher.maxDoc":0, [junit4] 2> "SEARCHER.searcher.deletedDocs":0, [junit4] 2> "INDEX.sizeInBytes":1, [junit4] 2> "node_name":"127.0.0.1:10001_solr", [junit4] 2> "state":"active", [junit4] 2> "type":"NRT", [junit4] 2> "SEARCHER.searcher.numDocs":0, [junit4] 2> "shard":"shard2", [junit4] 2> "collection":"testNodeWithMultipleReplicasLost"}} [junit4] 2> 2875172 DEBUG (simCloudManagerPool-13055-thread-12) [ ] o.a.s.c.a.s.SimClusterStateProvider -- elected new leader for testNodeWithMultipleReplicasLost / shard1: {"core_node1":{ [junit4] 2> "core":"testNodeWithMultipleReplicasLost_shard1_replica_n1", [junit4] 2> "leader":"true", [junit4] 2> "SEARCHER.searcher.maxDoc":0, [junit4] 2> "SEARCHER.searcher.deletedDocs":0, [junit4] 2> "INDEX.sizeInBytes":1, [junit4] 2> "node_name":"127.0.0.1:10005_solr", [junit4] 2> "state":"active", [junit4] 2> "type":"NRT", [junit4] 2> "SEARCHER.searcher.numDocs":0, [junit4] 2> "shard":"shard1", [junit4] 2> "collection":"testNodeWithMultipleReplicasLost"}} [junit4] 2> 2875183 DEBUG (ScheduledTrigger-13056-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 4 [junit4] 2> 2875191 DEBUG (ScheduledTrigger-13056-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 4 [junit4] 2> 2875202 DEBUG (TEST-TestComputePlanAction.testNodeWithMultipleReplicasLost-seed#[EE28ED6983405874]) [ ] o.a.s.c.a.s.TestComputePlanAction -- cluster state: znodeVersion: 16 [junit4] 2> live nodes:[127.0.0.1:10001_solr, 127.0.0.1:10004_solr, 127.0.0.1:10006_solr, 127.0.0.1:10005_solr] [junit4] 2> collections:{testNodeWithMultipleReplicasLost=DocCollection(testNodeWithMultipleReplicasLost//clusterstate.json/15)={ [junit4] 2> "replicationFactor":"3", [junit4] 2> "pullReplicas":"0", [junit4] 2> "router":{"name":"compositeId"}, [junit4] 2> "maxShardsPerNode":"1", [junit4] 2> "autoAddReplicas":"false", [junit4] 2> "nrtReplicas":"3", [junit4] 2> "tlogReplicas":"0", [junit4] 2> "autoCreated":"true", [junit4] 2> "shards":{ [junit4] 2> "shard2":{ [junit4] 2> "replicas":{ [junit4] 2> "core_node6":{ [junit4] 2> "core":"testNodeWithMultipleReplicasLost_shard2_replica_n6", [junit4] 2> "SEARCHER.searcher.maxDoc":0, [junit4] 2> "SEARCHER.searcher.deletedDocs":0, [junit4] 2> "INDEX.sizeInBytes":1, [junit4] 2> "node_name":"127.0.0.1:10006_solr", [junit4] 2> "state":"active", [junit4] 2> "type":"NRT", [junit4] 2> "SEARCHER.searcher.numDocs":0}, [junit4] 2> "core_node4":{ [junit4] 2> "core":"testNodeWithMultipleReplicasLost_shard2_replica_n4", [junit4] 2> "leader":"true", [junit4] 2> "SEARCHER.searcher.maxDoc":0, [junit4] 2> "SEARCHER.searcher.deletedDocs":0, [junit4] 2> "INDEX.sizeInBytes":1, [junit4] 2> "node_name":"127.0.0.1:10001_solr", [junit4] 2> "state":"active", [junit4] 2> "type":"NRT", [junit4] 2> "SEARCHER.searcher.numDocs":0}, [junit4] 2> "core_node5":{ [junit4] 2> "core":"testNodeWithMultipleReplicasLost_shard2_replica_n5", [junit4] 2> "SEARCHER.searcher.maxDoc":0, [junit4] 2> "SEARCHER.searcher.deletedDocs":0, [junit4] 2> "INDEX.sizeInBytes":1, [junit4] 2> "node_name":"127.0.0.1:10004_solr", [junit4] 2> "state":"active", [junit4] 2> "type":"NRT", [junit4] 2> "SEARCHER.searcher.numDocs":0}}, [junit4] 2> "range":"0-7fffffff", [junit4] 2> "state":"active"}, [junit4] 2> "shard1":{ [junit4] 2> "replicas":{ [junit4] 2> "core_node1":{ [junit4] 2> "core":"testNodeWithMultipleReplicasLost_shard1_replica_n1", [junit4] 2> "leader":"true", [junit4] 2> "SEARCHER.searcher.maxDoc":0, [junit4] 2> "SEARCHER.searcher.deletedDocs":0, [junit4] 2> "INDEX.sizeInBytes":1, [junit4] 2> "node_name":"127.0.0.1:10005_solr", [junit4] 2> "state":"active", [junit4] 2> "type":"NRT", [junit4] 2> "SEARCHER.searcher.numDocs":0}, [junit4] 2> "core_node2":{ [junit4] 2> "core":"testNodeWithMultipleReplicasLost_shard1_replica_n2", [junit4] 2> "SEARCHER.searcher.maxDoc":0, [junit4] 2> "SEARCHER.searcher.deletedDocs":0, [junit4] 2> "INDEX.sizeInBytes":1, [junit4] 2> "node_name":"127.0.0.1:10006_solr", [junit4] 2> "state":"active", [junit4] 2> "type":"NRT", [junit4] 2> "SEARCHER.searcher.numDocs":0}, [junit4] 2> "core_node3":{ [junit4] 2> "core":"testNodeWithMultipleReplicasLost_shard1_replica_n3", [junit4] 2> "SEARCHER.searcher.maxDoc":0, [junit4] 2> "SEARCHER.searcher.deletedDocs":0, [junit4] 2> "INDEX.sizeInBytes":1, [junit4] 2> "node_name":"127.0.0.1:10004_solr", [junit4] 2> "state":"active", [junit4] 2> "type":"NRT", [junit4] 2> "SEARCHER.searcher.numDocs":0}}, [junit4] 2> "range":"80000000-ffffffff", [junit4] 2> "state":"active"}}}} [junit4] 2> 2875203 DEBUG (ScheduledTrigger-13056-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 3 [junit4] 2> 2875203 DEBUG (ScheduledTrigger-13056-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Tracking lost node: 127.0.0.1:10004_solr [junit4] 2> 2875215 DEBUG (ScheduledTrigger-13056-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3 [junit4] 2> 2875215 DEBUG (ScheduledTrigger-13056-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Tracking lost node: 127.0.0.1:10004_solr [junit4] 2> 2875223 DEBUG (ScheduledTrigger-13056-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 3 [junit4] 2> 2875223 DEBUG (ScheduledTrigger-13056-thread-2) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger firing registered processor for lost nodes: [127.0.0.1:10004_solr] [junit4] 2> 2875223 DEBUG (ScheduledTrigger-13056-thread-2) [ ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: { [junit4] 2> "id":"bfecdd56c8b56T9m9xb0oetrzy4h43664fwmvb7", [junit4] 2> "source":"node_lost_trigger", [junit4] 2> "eventTime":3376384746228566, [junit4] 2> "eventType":"NODELOST", [junit4] 2> "properties":{ [junit4] 2> "eventTimes":[3376384746228566], [junit4] 2> "nodeNames":["127.0.0.1:10004_solr"]}} [junit4] 2> 2875224 DEBUG (ScheduledTrigger-13056-thread-2) [ ] o.a.s.c.a.ScheduledTriggers Pausing all triggers: [.auto_add_replicas, .scheduled_maintenance, node_lost_trigger] [junit4] 2> 2875225 DEBUG (simCloudManagerPool-13055-thread-15) [ ] o.a.s.c.o.ClusterStateMutator building a new cName: .system [junit4] 2> 2875237 DEBUG (simCloudManagerPool-13055-thread-15) [ ] o.a.s.c.s.c.a.PolicyHelper Creating a new session [junit4] 2> 2875237 DEBUG (simCloudManagerPool-13055-thread-15) [ ] o.a.s.c.s.c.a.PolicyHelper New session created [junit4] 2> 2875238 INFO (simCloudManagerPool-13055-thread-15) [ ] o.a.s.c.s.c.a.PolicyHelper returnSession, curr-time 3376386483 sessionWrapper.createTime 3376386454578766, this.sessionWrapper.createTime 3376386454578766 [junit4] 2> 2875238 DEBUG (simCloudManagerPool-13055-thread-15) [ ] o.a.s.c.s.c.a.PolicyHelper session set to NULL [junit4] 2> 2875250 DEBUG (AutoscalingActionExecutor-13057-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing actions for { [junit4] 2> "id":"bfecdd56c8b56T9m9xb0oetrzy4h43664fwmvb7", [junit4] 2> "source":"node_lost_trigger", [junit4] 2> "eventTime":3376384746228566, [junit4] 2> "eventType":"NODELOST", [junit4] 2> "properties":{ [junit4] 2> "eventTimes":[3376384746228566], [junit4] 2> "_enqueue_time_":3376385776439566, [junit4] 2> "nodeNames":["127.0.0.1:10004_solr"]}} [junit4] 2> 2875250 DEBUG (AutoscalingActionExecutor-13057-thread-1) [ ] o.a.s.c.a.ComputePlanAction -- processing event: { [junit4] 2> "id":"bfecdd56c8b56T9m9xb0oetrzy4h43664fwmvb7", [junit4] 2> "source":"node_lost_trigger", [junit4] 2> "eventTime":3376384746228566, [junit4] 2> "eventType":"NODELOST", [junit4] 2> "properties":{ [junit4] 2> "eventTimes":[3376384746228566], [junit4] 2> "_enqueue_time_":3376385776439566, [junit4] 2> "nodeNames":["127.0.0.1:10004_solr"]}} with context properties: {BEFORE_ACTION=[compute_plan]} [junit4] 2> 2875250 DEBUG (AutoscalingActionExecutor-13057-thread-1) [ ] o.a.s.c.s.c.a.PolicyHelper Creating a new session [junit4] 2> 2875251 DEBUG (AutoscalingActionExecutor-13057-thread-1) [ ] o.a.s.c.s.c.a.PolicyHelper New session created [junit4] 2> 2875253 INFO (AutoscalingActionExecutor-13057-thread-1) [ ] o.a.s.c.a.ComputePlanAction Computed Plan: action=MOVEREPLICA&collection=testNodeWithMultipleReplicasLost&targetNode=127.0.0.1:10005_solr&inPlaceMove=true&replica=core_node5 [junit4] 2> 2875254 INFO (AutoscalingActionExecutor-13057-thread-1) [ ] o.a.s.c.a.ComputePlanAction Computed Plan: action=MOVEREPLICA&collection=testNodeWithMultipleReplicasLost&targetNode=127.0.0.1:10001_solr&inPlaceMove=true&replica=core_node3 [junit4] 2> 2875254 INFO (AutoscalingActionExecutor-13057-thread-1) [ ] o.a.s.c.s.c.a.PolicyHelper returnSession, curr-time 3376387306 sessionWrapper.createTime 3376387171946666, this.sessionWrapper.createTime 3376387171946666 [junit4] 2> 2875254 DEBUG (AutoscalingActionExecutor-13057-thread-1) [ ] o.a.s.c.s.c.a.PolicyHelper session set to NULL [junit4] 2> 2875256 INFO (TEST-TestComputePlanAction.testNodeWithMultipleReplicasLost-seed#[EE28ED6983405874]) [ ] o.a.s.c.a.s.TestComputePlanAction action=MOVEREPLICA&collection=testNodeWithMultipleReplicasLost&targetNode=127.0.0.1:10005_solr&inPlaceMove=true&replica=core_node5 [junit4] 2> 2875256 INFO (TEST-TestComputePlanAction.testNodeWithMultipleReplicasLost-seed#[EE28ED6983405874]) [ [...truncated too long message...] [junit4] 2> NOTE: reproduce with: ant test -Dtestcase=TestComputePlanAction -Dtests.method=testNodeAdded -Dtests.seed=EE28ED6983405874 -Dtests.slow=true -Dtests.badapples=true -Dtests.locale=es-CR -Dtests.timezone=Pacific/Kwajalein -Dtests.asserts=true -Dtests.file.encoding=UTF-8 [junit4] FAILURE 0.40s J0 | TestComputePlanAction.testNodeAdded <<< [junit4] > Throwable #1: java.lang.AssertionError: ComputePlanAction should have computed exactly 1 operation, but was: [org.apache.solr.client.solrj.request.CollectionAdminRequest$MoveReplica@1cbe7949, org.apache.solr.client.solrj.request.CollectionAdminRequest$MoveReplica@2c758027] expected:<1> but was:<2> [junit4] > at __randomizedtesting.SeedInfo.seed([EE28ED6983405874:8BEBBB1E21E3F077]:0) [junit4] > at org.apache.solr.cloud.autoscaling.sim.TestComputePlanAction.testNodeAdded(TestComputePlanAction.java:313) [junit4] > at java.lang.Thread.run(Thread.java:748) [junit4] 2> 7794 DEBUG (SUITE-TestComputePlanAction-seed#[EE28ED6983405874]-worker) [ ] o.a.s.c.a.ScheduledTriggers Shutting down scheduled thread pool executor now [junit4] 2> 7794 DEBUG (SUITE-TestComputePlanAction-seed#[EE28ED6983405874]-worker) [ ] o.a.s.c.a.ScheduledTriggers Shutting down action executor now [junit4] 2> 7794 DEBUG (SUITE-TestComputePlanAction-seed#[EE28ED6983405874]-worker) [ ] o.a.s.c.a.ScheduledTriggers Awaiting termination for action executor [junit4] 2> 7795 WARN (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting. [junit4] 2> 7796 WARN (AutoscalingActionExecutor-45-thread-1) [ ] o.a.s.c.a.SystemLogListener Exception sending event to collection .system [junit4] 2> java.io.IOException: java.lang.InterruptedException [junit4] 2> at org.apache.solr.cloud.autoscaling.sim.SimCloudManager.request(SimCloudManager.java:621) ~[test/:?] [junit4] 2> at org.apache.solr.cloud.autoscaling.SystemLogListener.onEvent(SystemLogListener.java:118) ~[java/:?] [junit4] 2> at org.apache.solr.cloud.autoscaling.ScheduledTriggers$TriggerListeners.fireListeners(ScheduledTriggers.java:789) ~[java/:?] [junit4] 2> at org.apache.solr.cloud.autoscaling.ScheduledTriggers$TriggerListeners.fireListeners(ScheduledTriggers.java:765) ~[java/:?] [junit4] 2> at org.apache.solr.cloud.autoscaling.ScheduledTriggers.lambda$null$3(ScheduledTriggers.java:315) ~[java/:?] [junit4] 2> at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) ~[?:1.8.0_172] [junit4] 2> at java.util.concurrent.FutureTask.run(FutureTask.java:266) ~[?:1.8.0_172] [junit4] 2> at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:209) ~[java/:?] [junit4] 2> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_172] [junit4] 2> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_172] [junit4] 2> at java.lang.Thread.run(Thread.java:748) [?:1.8.0_172] [junit4] 2> Caused by: java.lang.InterruptedException [junit4] 2> at java.util.concurrent.FutureTask.awaitDone(FutureTask.java:404) ~[?:1.8.0_172] [junit4] 2> at java.util.concurrent.FutureTask.get(FutureTask.java:191) ~[?:1.8.0_172] [junit4] 2> at org.apache.solr.cloud.autoscaling.sim.SimCloudManager.request(SimCloudManager.java:619) ~[test/:?] [junit4] 2> ... 10 more [junit4] 2> 7796 WARN (AutoscalingActionExecutor-45-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Exception executing actions [junit4] 2> org.apache.lucene.store.AlreadyClosedException: ScheduledTrigger node_added_trigger has been closed. [junit4] 2> at org.apache.solr.cloud.autoscaling.ScheduledTriggers$TriggerWrapper.dequeue(ScheduledTriggers.java:545) ~[java/:?] [junit4] 2> at org.apache.solr.cloud.autoscaling.ScheduledTriggers.lambda$null$3(ScheduledTriggers.java:318) ~[java/:?] [junit4] 2> at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) ~[?:1.8.0_172] [junit4] 2> at java.util.concurrent.FutureTask.run(FutureTask.java:266) ~[?:1.8.0_172] [junit4] 2> at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:209) ~[java/:?] [junit4] 2> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_172] [junit4] 2> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_172] [junit4] 2> at java.lang.Thread.run(Thread.java:748) [?:1.8.0_172] [junit4] 2> 7797 DEBUG (AutoscalingActionExecutor-45-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing took 1084 ms for event id=bc8ee19a147a9T9m9xb0oetrzy4h43664fwmlvz [junit4] 2> 7798 DEBUG (SUITE-TestComputePlanAction-seed#[EE28ED6983405874]-worker) [ ] o.a.s.c.a.ScheduledTriggers Awaiting termination for scheduled thread pool executor [junit4] 2> 7798 DEBUG (SUITE-TestComputePlanAction-seed#[EE28ED6983405874]-worker) [ ] o.a.s.c.a.ScheduledTriggers ScheduledTriggers closed completely [junit4] 2> 7798 DEBUG (SUITE-TestComputePlanAction-seed#[EE28ED6983405874]-worker) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly [junit4] 2> NOTE: leaving temporary files on disk at: /export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.sim.TestComputePlanAction_EE28ED6983405874-001 [junit4] 2> NOTE: test params are: codec=Asserting(Lucene70): {}, docValues:{}, maxPointsInLeafNode=1432, maxMBSortInHeap=6.050871587955811, sim=Asserting(org.apache.lucene.search.similarities.AssertingSimilarity@161e3557), locale=es-CR, timezone=Pacific/Kwajalein [junit4] 2> NOTE: SunOS 5.11 amd64/Oracle Corporation 1.8.0_172 (64-bit)/cpus=3,threads=1,free=34941184,total=100663296 [junit4] 2> NOTE: All tests run in this JVM: [TestComputePlanAction, TestComputePlanAction, TestComputePlanAction] [junit4] Completed [6/10 (3!)] on J0 in 1.24s, 3 tests, 1 failure <<< FAILURES! [junit4] [junit4] Suite: org.apache.solr.metrics.rrd.SolrRrdBackendFactoryTest [junit4] OK 0.31s J1 | SolrRrdBackendFactoryTest.testBasic [junit4] Completed [7/10 (3!)] on J1 in 0.33s, 1 test [junit4] [junit4] Duplicate suite name used with XML reports: org.apache.solr.metrics.rrd.SolrRrdBackendFactoryTest. This may confuse tools that process XML reports. Set 'ignoreDuplicateSuites' to true to skip this message. [junit4] Suite: org.apache.solr.metrics.rrd.SolrRrdBackendFactoryTest [junit4] OK 0.29s J0 | SolrRrdBackendFactoryTest.testBasic [junit4] Completed [8/10 (3!)] on J0 in 0.30s, 1 test [junit4] [junit4] Suite: org.apache.solr.metrics.rrd.SolrRrdBackendFactoryTest [junit4] OK 0.28s J1 | SolrRrdBackendFactoryTest.testBasic [junit4] Completed [9/10 (3!)] on J1 in 0.30s, 1 test [junit4] [junit4] Suite: org.apache.solr.metrics.rrd.SolrRrdBackendFactoryTest [junit4] OK 0.27s J0 | SolrRrdBackendFactoryTest.testBasic [junit4] Completed [10/10 (3!)] on J0 in 0.28s, 1 test [junit4] [junit4] [junit4] Tests with failures [seed: EE28ED6983405874]: [junit4] - org.apache.solr.cloud.autoscaling.sim.TestComputePlanAction.testNodeAdded [junit4] - org.apache.solr.cloud.autoscaling.sim.TestComputePlanAction.testNodeAdded [junit4] - org.apache.solr.cloud.autoscaling.sim.TestComputePlanAction.testNodeAdded [junit4] [junit4] [junit4] JVM J0: 0.69 .. 9.40 = 8.72s [junit4] JVM J1: 0.69 .. 8.96 = 8.27s [junit4] Execution time total: 9.41 sec. [junit4] Tests summary: 10 suites, 20 tests, 3 failures BUILD FAILED /export/home/jenkins/workspace/Lucene-Solr-master-Solaris/lucene/common-build.xml:1568: The following error occurred while executing this line: /export/home/jenkins/workspace/Lucene-Solr-master-Solaris/lucene/common-build.xml:1092: There were test failures: 10 suites, 20 tests, 3 failures [seed: EE28ED6983405874] Total time: 11 seconds [repro] Setting last failure code to 256 [repro] Failures: [repro] 0/5 failed: org.apache.lucene.index.TestIndexWriterWithThreads [repro] 0/5 failed: org.apache.solr.metrics.rrd.SolrRrdBackendFactoryTest [repro] 3/5 failed: org.apache.solr.cloud.autoscaling.sim.TestComputePlanAction [repro] Exiting with code 256 + mv lucene/build lucene/build.repro + mv solr/build solr/build.repro + mv lucene/build.orig lucene/build + mv solr/build.orig solr/build Archiving artifacts Setting ANT_1_8_2_HOME=/export/home/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2 [WARNINGS] Parsing warnings in console log with parser Java Compiler (javac) Setting ANT_1_8_2_HOME=/export/home/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2 Setting ANT_1_8_2_HOME=/export/home/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2 <Git Blamer> Using GitBlamer to create author and commit information for all warnings. <Git Blamer> GIT_COMMIT=3dc4fa199c175ed6351f66bac5c23c73b4e3f89a, workspace=/export/home/jenkins/workspace/Lucene-Solr-master-Solaris [WARNINGS] Computing warning deltas based on reference build #1905 Recording test results Setting ANT_1_8_2_HOME=/export/home/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2 Build step 'Publish JUnit test result report' changed build result to UNSTABLE Email was triggered for: Unstable (Test Failures) Sending email for trigger: Unstable (Test Failures) Setting ANT_1_8_2_HOME=/export/home/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2 Setting ANT_1_8_2_HOME=/export/home/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2 Setting ANT_1_8_2_HOME=/export/home/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2 Setting ANT_1_8_2_HOME=/export/home/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
--------------------------------------------------------------------- To unsubscribe, e-mail: dev-unsubscr...@lucene.apache.org For additional commands, e-mail: dev-h...@lucene.apache.org