You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Apache Jenkins Server <je...@builds.apache.org> on 2017/03/07 04:02:46 UTC
[JENKINS] Lucene-Solr-NightlyTests-6.x - Build # 302 - Still
Unstable
Build: https://builds.apache.org/job/Lucene-Solr-NightlyTests-6.x/302/
2 tests failed.
FAILED: org.apache.solr.cloud.CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap
Error Message:
Document mismatch on target after sync expected:<10000> but was:<0>
Stack Trace:
java.lang.AssertionError: Document mismatch on target after sync expected:<10000> but was:<0>
at __randomizedtesting.SeedInfo.seed([B003351AF67433AA:67D41A6D422BABED]: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.CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap(CdcrBootstrapTest.java:134)
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:1713)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:907)
at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:943)
at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:957)
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:916)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:802)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:852)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
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:745)
FAILED: junit.framework.TestSuite.org.apache.solr.cloud.hdfs.HdfsRecoveryZkTest
Error Message:
ObjectTracker found 1 object(s) that were not released!!! [HdfsTransactionLog] org.apache.solr.common.util.ObjectReleaseTracker$ObjectTrackerException: org.apache.solr.update.HdfsTransactionLog at org.apache.solr.common.util.ObjectReleaseTracker.track(ObjectReleaseTracker.java:42) at org.apache.solr.update.HdfsTransactionLog.<init>(HdfsTransactionLog.java:130) at org.apache.solr.update.HdfsUpdateLog.init(HdfsUpdateLog.java:203) at org.apache.solr.update.UpdateHandler.<init>(UpdateHandler.java:137) at org.apache.solr.update.UpdateHandler.<init>(UpdateHandler.java:94) at org.apache.solr.update.DirectUpdateHandler2.<init>(DirectUpdateHandler2.java:109) at sun.reflect.GeneratedConstructorAccessor172.newInstance(Unknown Source) at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45) at java.lang.reflect.Constructor.newInstance(Constructor.java:423) at org.apache.solr.core.SolrCore.createInstance(SolrCore.java:741) at org.apache.solr.core.SolrCore.createUpdateHandler(SolrCore.java:803) at org.apache.solr.core.SolrCore.initUpdateHandler(SolrCore.java:1053) at org.apache.solr.core.SolrCore.<init>(SolrCore.java:918) at org.apache.solr.core.SolrCore.<init>(SolrCore.java:811) at org.apache.solr.core.CoreContainer.create(CoreContainer.java:917) at org.apache.solr.core.CoreContainer.lambda$load$3(CoreContainer.java:552) at com.codahale.metrics.InstrumentedExecutorService$InstrumentedCallable.call(InstrumentedExecutorService.java:197) at java.util.concurrent.FutureTask.run(FutureTask.java:266) at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:229) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) at java.lang.Thread.run(Thread.java:745)
Stack Trace:
java.lang.AssertionError: ObjectTracker found 1 object(s) that were not released!!! [HdfsTransactionLog]
org.apache.solr.common.util.ObjectReleaseTracker$ObjectTrackerException: org.apache.solr.update.HdfsTransactionLog
at org.apache.solr.common.util.ObjectReleaseTracker.track(ObjectReleaseTracker.java:42)
at org.apache.solr.update.HdfsTransactionLog.<init>(HdfsTransactionLog.java:130)
at org.apache.solr.update.HdfsUpdateLog.init(HdfsUpdateLog.java:203)
at org.apache.solr.update.UpdateHandler.<init>(UpdateHandler.java:137)
at org.apache.solr.update.UpdateHandler.<init>(UpdateHandler.java:94)
at org.apache.solr.update.DirectUpdateHandler2.<init>(DirectUpdateHandler2.java:109)
at sun.reflect.GeneratedConstructorAccessor172.newInstance(Unknown Source)
at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
at org.apache.solr.core.SolrCore.createInstance(SolrCore.java:741)
at org.apache.solr.core.SolrCore.createUpdateHandler(SolrCore.java:803)
at org.apache.solr.core.SolrCore.initUpdateHandler(SolrCore.java:1053)
at org.apache.solr.core.SolrCore.<init>(SolrCore.java:918)
at org.apache.solr.core.SolrCore.<init>(SolrCore.java:811)
at org.apache.solr.core.CoreContainer.create(CoreContainer.java:917)
at org.apache.solr.core.CoreContainer.lambda$load$3(CoreContainer.java:552)
at com.codahale.metrics.InstrumentedExecutorService$InstrumentedCallable.call(InstrumentedExecutorService.java:197)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:229)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
at __randomizedtesting.SeedInfo.seed([B003351AF67433AA]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.junit.Assert.assertTrue(Assert.java:43)
at org.junit.Assert.assertNull(Assert.java:551)
at org.apache.solr.SolrTestCaseJ4.teardownTestCases(SolrTestCaseJ4.java:302)
at sun.reflect.GeneratedMethodAccessor89.invoke(Unknown Source)
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:1713)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:870)
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:745)
Build Log:
[...truncated 11990 lines...]
[junit4] Suite: org.apache.solr.cloud.CdcrBootstrapTest
[junit4] 2> Creating dataDir: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.CdcrBootstrapTest_B003351AF67433AA-001/init-core-data-001
[junit4] 2> 838255 INFO (SUITE-CdcrBootstrapTest-seed#[B003351AF67433AA]-worker) [ ] o.a.s.SolrTestCaseJ4 Using TrieFields
[junit4] 2> 838256 INFO (SUITE-CdcrBootstrapTest-seed#[B003351AF67433AA]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (true) via: @org.apache.solr.util.RandomizeSSL(reason=, ssl=NaN, value=NaN, clientAuth=NaN)
[junit4] 2> 838264 INFO (TEST-CdcrBootstrapTest.testBootstrapWithContinousIndexingOnSourceCluster-seed#[B003351AF67433AA]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testBootstrapWithContinousIndexingOnSourceCluster
[junit4] 2> 838264 INFO (TEST-CdcrBootstrapTest.testBootstrapWithContinousIndexingOnSourceCluster-seed#[B003351AF67433AA]) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 1 servers in /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.CdcrBootstrapTest_B003351AF67433AA-001/cdcr-target-001
[junit4] 2> 838264 INFO (TEST-CdcrBootstrapTest.testBootstrapWithContinousIndexingOnSourceCluster-seed#[B003351AF67433AA]) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 838269 INFO (Thread-34606) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 838270 INFO (Thread-34606) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 838369 INFO (TEST-CdcrBootstrapTest.testBootstrapWithContinousIndexingOnSourceCluster-seed#[B003351AF67433AA]) [ ] o.a.s.c.ZkTestServer start zk server on port:38021
[junit4] 2> 838403 INFO (jetty-launcher-292-thread-1) [ ] o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 838404 INFO (jetty-launcher-292-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@6d06e2e2{/solr,null,AVAILABLE}
[junit4] 2> 838411 INFO (jetty-launcher-292-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@2f4e1645{HTTP/1.1,[http/1.1]}{127.0.0.1:34168}
[junit4] 2> 838411 INFO (jetty-launcher-292-thread-1) [ ] o.e.j.s.Server Started @841454ms
[junit4] 2> 838411 INFO (jetty-launcher-292-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=34168}
[junit4] 2> 838411 ERROR (jetty-launcher-292-thread-1) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 838411 INFO (jetty-launcher-292-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 6.5.0
[junit4] 2> 838411 INFO (jetty-launcher-292-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 838411 INFO (jetty-launcher-292-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 838411 INFO (jetty-launcher-292-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-03-07T02:40:18.561Z
[junit4] 2> 838438 INFO (jetty-launcher-292-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 838453 INFO (jetty-launcher-292-thread-1) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 838462 INFO (jetty-launcher-292-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:38021/solr
[junit4] 2> 838552 INFO (jetty-launcher-292-thread-1) [n:127.0.0.1:34168_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 838554 INFO (jetty-launcher-292-thread-1) [n:127.0.0.1:34168_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:34168_solr
[junit4] 2> 838561 INFO (jetty-launcher-292-thread-1) [n:127.0.0.1:34168_solr ] o.a.s.c.Overseer Overseer (id=97573563171340291-127.0.0.1:34168_solr-n_0000000000) starting
[junit4] 2> 838606 INFO (jetty-launcher-292-thread-1) [n:127.0.0.1:34168_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:34168_solr
[junit4] 2> 838609 INFO (zkCallback-299-thread-1-processing-n:127.0.0.1:34168_solr) [n:127.0.0.1:34168_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 838845 INFO (jetty-launcher-292-thread-1) [n:127.0.0.1:34168_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.CdcrBootstrapTest_B003351AF67433AA-001/cdcr-target-001/node1/.
[junit4] 1> Target zkHost = 127.0.0.1:38021/solr
[junit4] 2> 838918 INFO (TEST-CdcrBootstrapTest.testBootstrapWithContinousIndexingOnSourceCluster-seed#[B003351AF67433AA]) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 1 servers in /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.CdcrBootstrapTest_B003351AF67433AA-001/cdcr-source-001
[junit4] 2> 838918 INFO (TEST-CdcrBootstrapTest.testBootstrapWithContinousIndexingOnSourceCluster-seed#[B003351AF67433AA]) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 838918 INFO (Thread-34616) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 838918 INFO (Thread-34616) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 838923 WARN (Thread-34616) [ ] o.a.z.j.MBeanRegistry Failed to register MBean StandaloneServer_port-1
[junit4] 2> 838923 WARN (Thread-34616) [ ] o.a.z.s.ZooKeeperServer Failed to register with JMX
[junit4] 2> javax.management.InstanceAlreadyExistsException: org.apache.ZooKeeperService:name0=StandaloneServer_port-1
[junit4] 2> at com.sun.jmx.mbeanserver.Repository.addMBean(Repository.java:437)
[junit4] 2> at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerWithRepository(DefaultMBeanServerInterceptor.java:1898)
[junit4] 2> at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerDynamicMBean(DefaultMBeanServerInterceptor.java:966)
[junit4] 2> at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerObject(DefaultMBeanServerInterceptor.java:900)
[junit4] 2> at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerMBean(DefaultMBeanServerInterceptor.java:324)
[junit4] 2> at com.sun.jmx.mbeanserver.JmxMBeanServer.registerMBean(JmxMBeanServer.java:522)
[junit4] 2> at org.apache.zookeeper.jmx.MBeanRegistry.register(MBeanRegistry.java:96)
[junit4] 2> at org.apache.zookeeper.server.ZooKeeperServer.registerJMX(ZooKeeperServer.java:377)
[junit4] 2> at org.apache.zookeeper.server.ZooKeeperServer.startup(ZooKeeperServer.java:410)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.startup(NIOServerCnxnFactory.java:123)
[junit4] 2> at org.apache.solr.cloud.ZkTestServer$ZKServerMain.runFromConfig(ZkTestServer.java:308)
[junit4] 2> at org.apache.solr.cloud.ZkTestServer$2.run(ZkTestServer.java:490)
[junit4] 2> 839018 INFO (TEST-CdcrBootstrapTest.testBootstrapWithContinousIndexingOnSourceCluster-seed#[B003351AF67433AA]) [ ] o.a.s.c.ZkTestServer start zk server on port:50896
[junit4] 2> 839037 INFO (jetty-launcher-304-thread-1) [ ] o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 839038 INFO (jetty-launcher-304-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@186e7ff3{/solr,null,AVAILABLE}
[junit4] 2> 839038 INFO (jetty-launcher-304-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@f61d64b{HTTP/1.1,[http/1.1]}{127.0.0.1:41758}
[junit4] 2> 839039 INFO (jetty-launcher-304-thread-1) [ ] o.e.j.s.Server Started @842082ms
[junit4] 2> 839039 INFO (jetty-launcher-304-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=41758}
[junit4] 2> 839039 ERROR (jetty-launcher-304-thread-1) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 839040 INFO (jetty-launcher-304-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 6.5.0
[junit4] 2> 839040 INFO (jetty-launcher-304-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 839040 INFO (jetty-launcher-304-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 839040 INFO (jetty-launcher-304-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-03-07T02:40:19.190Z
[junit4] 2> 839255 INFO (jetty-launcher-304-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 839267 INFO (jetty-launcher-304-thread-1) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 839268 INFO (jetty-launcher-304-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:50896/solr
[junit4] 2> 839307 INFO (jetty-launcher-304-thread-1) [n:127.0.0.1:41758_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 839308 INFO (jetty-launcher-304-thread-1) [n:127.0.0.1:41758_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:41758_solr
[junit4] 2> 839309 INFO (jetty-launcher-304-thread-1) [n:127.0.0.1:41758_solr ] o.a.s.c.Overseer Overseer (id=97573563208302595-127.0.0.1:41758_solr-n_0000000000) starting
[junit4] 2> 839316 INFO (jetty-launcher-304-thread-1) [n:127.0.0.1:41758_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:41758_solr
[junit4] 2> 839324 INFO (zkCallback-311-thread-1-processing-n:127.0.0.1:41758_solr) [n:127.0.0.1:41758_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 839391 INFO (jetty-launcher-304-thread-1) [n:127.0.0.1:41758_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.CdcrBootstrapTest_B003351AF67433AA-001/cdcr-source-001/node1/.
[junit4] 2> 839478 INFO (TEST-CdcrBootstrapTest.testBootstrapWithContinousIndexingOnSourceCluster-seed#[B003351AF67433AA]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 839480 INFO (TEST-CdcrBootstrapTest.testBootstrapWithContinousIndexingOnSourceCluster-seed#[B003351AF67433AA]) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:50896/solr ready
[junit4] 2> 839485 INFO (qtp2129483089-36624) [n:127.0.0.1:41758_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params replicationFactor=1&collection.configName=cdcr-source&name=cdcr-source&action=CREATE&numShards=1&property.solr.directoryFactory=solr.StandardDirectoryFactory&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 839492 INFO (OverseerThreadFactory-1077-thread-1-processing-n:127.0.0.1:41758_solr) [n:127.0.0.1:41758_solr ] o.a.s.c.CreateCollectionCmd Create collection cdcr-source
[junit4] 2> 839639 INFO (qtp2129483089-36622) [n:127.0.0.1:41758_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=cdcr-source&newCollection=true&name=cdcr-source_shard1_replica1&action=CREATE&numShards=1&collection=cdcr-source&shard=shard1&property.solr.directoryFactory=solr.StandardDirectoryFactory&wt=javabin&version=2
[junit4] 2> 839753 INFO (zkCallback-311-thread-3-processing-n:127.0.0.1:41758_solr) [n:127.0.0.1:41758_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/cdcr-source/state.json] for collection [cdcr-source] has occurred - updating... (live nodes size: [1])
[junit4] 2> 840671 INFO (qtp2129483089-36622) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 x:cdcr-source_shard1_replica1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.5.0
[junit4] 2> 840676 INFO (qtp2129483089-36622) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 x:cdcr-source_shard1_replica1] o.a.s.s.ManagedIndexSchemaFactory The schema is configured as managed, but managed schema resource managed-schema not found - loading non-managed schema schema.xml instead
[junit4] 2> 840679 INFO (qtp2129483089-36622) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 x:cdcr-source_shard1_replica1] o.a.s.s.IndexSchema [cdcr-source_shard1_replica1] Schema name=minimal
[junit4] 2> 840687 INFO (qtp2129483089-36622) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 x:cdcr-source_shard1_replica1] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 840688 INFO (qtp2129483089-36622) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 x:cdcr-source_shard1_replica1] o.a.s.s.ManagedIndexSchema Created and persisted managed schema znode at /configs/cdcr-source/managed-schema
[junit4] 2> 840690 INFO (qtp2129483089-36622) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 x:cdcr-source_shard1_replica1] o.a.s.s.ManagedIndexSchemaFactory After upgrading to managed schema in ZooKeeper, renamed the non-managed schema /configs/cdcr-source/schema.xml to /configs/cdcr-source/schema.xml.bak
[junit4] 2> 840691 INFO (qtp2129483089-36622) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 x:cdcr-source_shard1_replica1] o.a.s.c.CoreContainer Creating SolrCore 'cdcr-source_shard1_replica1' using configuration from collection cdcr-source
[junit4] 2> 840707 INFO (qtp2129483089-36622) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 x:cdcr-source_shard1_replica1] o.a.s.c.SolrCore [[cdcr-source_shard1_replica1] ] Opening new SolrCore at [/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.CdcrBootstrapTest_B003351AF67433AA-001/cdcr-source-001/node1/cdcr-source_shard1_replica1], dataDir=[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.CdcrBootstrapTest_B003351AF67433AA-001/cdcr-source-001/node1/./cdcr-source_shard1_replica1/data/]
[junit4] 2> 840788 INFO (qtp2129483089-36622) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 x:cdcr-source_shard1_replica1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.CdcrUpdateLog
[junit4] 2> 840788 INFO (qtp2129483089-36622) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 x:cdcr-source_shard1_replica1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 840789 INFO (qtp2129483089-36622) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 x:cdcr-source_shard1_replica1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 840789 INFO (qtp2129483089-36622) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 x:cdcr-source_shard1_replica1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 840790 INFO (qtp2129483089-36622) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 x:cdcr-source_shard1_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@638769aa[cdcr-source_shard1_replica1] main]
[junit4] 2> 840791 INFO (qtp2129483089-36622) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 x:cdcr-source_shard1_replica1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/cdcr-source
[junit4] 2> 840792 INFO (qtp2129483089-36622) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 x:cdcr-source_shard1_replica1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/cdcr-source
[junit4] 2> 840792 INFO (qtp2129483089-36622) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 x:cdcr-source_shard1_replica1] o.a.s.s.ZkIndexSchemaReader Creating ZooKeeper watch for the managed schema at /configs/cdcr-source/managed-schema
[junit4] 2> 840792 INFO (qtp2129483089-36622) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 x:cdcr-source_shard1_replica1] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 840792 INFO (qtp2129483089-36622) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 x:cdcr-source_shard1_replica1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 840798 INFO (qtp2129483089-36622) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 x:cdcr-source_shard1_replica1] o.a.s.h.CdcrBufferStateManager Created znode /collections/cdcr-source/cdcr/state/buffer
[junit4] 2> 840806 INFO (qtp2129483089-36622) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 x:cdcr-source_shard1_replica1] o.a.s.h.CdcrProcessStateManager Created znode /collections/cdcr-source/cdcr/state/process
[junit4] 2> 840829 INFO (searcherExecutor-1080-thread-1-processing-n:127.0.0.1:41758_solr x:cdcr-source_shard1_replica1 s:shard1 c:cdcr-source) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 x:cdcr-source_shard1_replica1] o.a.s.c.SolrCore [cdcr-source_shard1_replica1] Registered new searcher Searcher@638769aa[cdcr-source_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 840830 INFO (qtp2129483089-36622) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 x:cdcr-source_shard1_replica1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1561177013333524480
[junit4] 2> 840849 INFO (qtp2129483089-36622) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 x:cdcr-source_shard1_replica1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 840852 INFO (qtp2129483089-36622) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 x:cdcr-source_shard1_replica1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 840852 INFO (qtp2129483089-36622) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 x:cdcr-source_shard1_replica1] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:41758/solr/cdcr-source_shard1_replica1/
[junit4] 2> 840852 INFO (qtp2129483089-36622) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 x:cdcr-source_shard1_replica1] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 840852 INFO (qtp2129483089-36622) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 x:cdcr-source_shard1_replica1] o.a.s.c.SyncStrategy http://127.0.0.1:41758/solr/cdcr-source_shard1_replica1/ has no replicas
[junit4] 2> 840852 INFO (qtp2129483089-36622) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 x:cdcr-source_shard1_replica1] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR
[junit4] 2> 840860 INFO (qtp2129483089-36622) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 x:cdcr-source_shard1_replica1] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:41758/solr/cdcr-source_shard1_replica1/ shard1
[junit4] 2> 840860 INFO (zkCallback-311-thread-1-processing-n:127.0.0.1:41758_solr) [n:127.0.0.1:41758_solr ] o.a.s.h.CdcrLeaderStateManager Received new leader state @ cdcr-source:shard1
[junit4] 2> 840973 INFO (zkCallback-311-thread-4-processing-n:127.0.0.1:41758_solr) [n:127.0.0.1:41758_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/cdcr-source/state.json] for collection [cdcr-source] has occurred - updating... (live nodes size: [1])
[junit4] 2> 841021 INFO (qtp2129483089-36622) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 x:cdcr-source_shard1_replica1] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 841030 INFO (qtp2129483089-36622) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 x:cdcr-source_shard1_replica1] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=cdcr-source&newCollection=true&name=cdcr-source_shard1_replica1&action=CREATE&numShards=1&collection=cdcr-source&shard=shard1&property.solr.directoryFactory=solr.StandardDirectoryFactory&wt=javabin&version=2} status=0 QTime=1391
[junit4] 2> 841048 INFO (qtp2129483089-36624) [n:127.0.0.1:41758_solr ] o.a.s.h.a.CollectionsHandler Wait for new collection to be active for at most 30 seconds. Check all shard replicas
[junit4] 2> 841137 INFO (zkCallback-311-thread-1-processing-n:127.0.0.1:41758_solr) [n:127.0.0.1:41758_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/cdcr-source/state.json] for collection [cdcr-source] has occurred - updating... (live nodes size: [1])
[junit4] 2> 841494 INFO (OverseerCollectionConfigSetProcessor-97573563208302595-127.0.0.1:41758_solr-n_0000000000) [n:127.0.0.1:41758_solr ] o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-work/qnr-0000000000 doesn't exist. Requestor may have disconnected from ZooKeeper
[junit4] 2> 842048 INFO (qtp2129483089-36624) [n:127.0.0.1:41758_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={replicationFactor=1&collection.configName=cdcr-source&name=cdcr-source&action=CREATE&numShards=1&property.solr.directoryFactory=solr.StandardDirectoryFactory&wt=javabin&version=2} status=0 QTime=2562
[junit4] 1> Adding 100 docs with commit=true, numDocs=100
[junit4] 2> 842088 INFO (qtp2129483089-36625) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.c.S.Request [cdcr-source_shard1_replica1] webapp=/solr path=/update params={_stateVer_=cdcr-source:3&wt=javabin&version=2} status=0 QTime=23
[junit4] 2> 842090 INFO (qtp2129483089-36621) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 842090 INFO (qtp2129483089-36621) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@45dc5ae
[junit4] 2> 842118 INFO (qtp2129483089-36621) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@3f435c50[cdcr-source_shard1_replica1] main]
[junit4] 2> 842118 INFO (searcherExecutor-1080-thread-1-processing-n:127.0.0.1:41758_solr x:cdcr-source_shard1_replica1 s:shard1 c:cdcr-source r:core_node1) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.c.SolrCore [cdcr-source_shard1_replica1] Registered new searcher Searcher@3f435c50[cdcr-source_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.5.0):C100)))}
[junit4] 2> 842119 INFO (qtp2129483089-36621) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 842119 INFO (qtp2129483089-36621) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.c.S.Request [cdcr-source_shard1_replica1] webapp=/solr path=/update params={_stateVer_=cdcr-source:3&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2} status=0 QTime=28
[junit4] 1> Adding 100 docs with commit=true, numDocs=200
[junit4] 2> 842125 INFO (qtp2129483089-36626) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.c.S.Request [cdcr-source_shard1_replica1] webapp=/solr path=/update params={_stateVer_=cdcr-source:3&wt=javabin&version=2} status=0 QTime=4
[junit4] 2> 842127 INFO (qtp2129483089-36622) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 842128 INFO (qtp2129483089-36622) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@45dc5ae
[junit4] 2> 842153 INFO (qtp2129483089-36622) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@64205cae[cdcr-source_shard1_replica1] main]
[junit4] 2> 842153 INFO (searcherExecutor-1080-thread-1-processing-n:127.0.0.1:41758_solr x:cdcr-source_shard1_replica1 s:shard1 c:cdcr-source r:core_node1) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.c.SolrCore [cdcr-source_shard1_replica1] Registered new searcher Searcher@64205cae[cdcr-source_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.5.0):C100) Uninverting(_1(6.5.0):C100)))}
[junit4] 2> 842153 INFO (qtp2129483089-36622) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 842153 INFO (qtp2129483089-36622) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.c.S.Request [cdcr-source_shard1_replica1] webapp=/solr path=/update params={_stateVer_=cdcr-source:3&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2} status=0 QTime=26
[junit4] 1> Adding 100 docs with commit=true, numDocs=300
[junit4] 2> 842159 INFO (qtp2129483089-36624) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.c.S.Request [cdcr-source_shard1_replica1] webapp=/solr path=/update params={_stateVer_=cdcr-source:3&wt=javabin&version=2} status=0 QTime=3
[junit4] 2> 842160 INFO (qtp2129483089-36628) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 842160 INFO (qtp2129483089-36628) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@45dc5ae
[junit4] 2> 842184 INFO (qtp2129483089-36628) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@7339b776[cdcr-source_shard1_replica1] main]
[junit4] 2> 842184 INFO (searcherExecutor-1080-thread-1-processing-n:127.0.0.1:41758_solr x:cdcr-source_shard1_replica1 s:shard1 c:cdcr-source r:core_node1) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.c.SolrCore [cdcr-source_shard1_replica1] Registered new searcher Searcher@7339b776[cdcr-source_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.5.0):C100) Uninverting(_1(6.5.0):C100) Uninverting(_2(6.5.0):C100)))}
[junit4] 2> 842184 INFO (qtp2129483089-36628) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 842184 INFO (qtp2129483089-36628) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.c.S.Request [cdcr-source_shard1_replica1] webapp=/solr path=/update params={_stateVer_=cdcr-source:3&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2} status=0 QTime=24
[junit4] 1> Adding 100 docs with commit=true, numDocs=400
[junit4] 2> 842189 INFO (qtp2129483089-36625) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.c.S.Request [cdcr-source_shard1_replica1] webapp=/solr path=/update params={_stateVer_=cdcr-source:3&wt=javabin&version=2} status=0 QTime=2
[junit4] 2> 842191 INFO (qtp2129483089-36625) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 842191 INFO (qtp2129483089-36625) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@45dc5ae
[junit4] 2> 842221 INFO (qtp2129483089-36625) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@24536924[cdcr-source_shard1_replica1] main]
[junit4] 2> 842222 INFO (searcherExecutor-1080-thread-1-processing-n:127.0.0.1:41758_solr x:cdcr-source_shard1_replica1 s:shard1 c:cdcr-source r:core_node1) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.c.SolrCore [cdcr-source_shard1_replica1] Registered new searcher Searcher@24536924[cdcr-source_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.5.0):C100) Uninverting(_1(6.5.0):C100) Uninverting(_2(6.5.0):C100) Uninverting(_3(6.5.0):C100)))}
[junit4] 2> 842222 INFO (qtp2129483089-36625) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 842222 INFO (qtp2129483089-36625) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.c.S.Request [cdcr-source_shard1_replica1] webapp=/solr path=/update params={_stateVer_=cdcr-source:3&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2} status=0 QTime=31
[junit4] 1> Adding 100 docs with commit=true, numDocs=500
[junit4] 2> 842228 INFO (qtp2129483089-36626) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.c.S.Request [cdcr-source_shard1_replica1] webapp=/solr path=/update params={_stateVer_=cdcr-source:3&wt=javabin&version=2} status=0 QTime=2
[junit4] 2> 842230 INFO (qtp2129483089-36626) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 842230 INFO (qtp2129483089-36626) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@45dc5ae
[junit4] 2> 842270 INFO (qtp2129483089-36626) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@39a160fb[cdcr-source_shard1_replica1] main]
[junit4] 2> 842270 INFO (searcherExecutor-1080-thread-1-processing-n:127.0.0.1:41758_solr x:cdcr-source_shard1_replica1 s:shard1 c:cdcr-source r:core_node1) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.c.SolrCore [cdcr-source_shard1_replica1] Registered new searcher Searcher@39a160fb[cdcr-source_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.5.0):C100) Uninverting(_1(6.5.0):C100) Uninverting(_2(6.5.0):C100) Uninverting(_3(6.5.0):C100) Uninverting(_4(6.5.0):C100)))}
[junit4] 2> 842270 INFO (qtp2129483089-36626) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 842270 INFO (qtp2129483089-36626) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.c.S.Request [cdcr-source_shard1_replica1] webapp=/solr path=/update params={_stateVer_=cdcr-source:3&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2} status=0 QTime=40
[junit4] 1> Adding 100 docs with commit=true, numDocs=600
[junit4] 2> 842278 INFO (qtp2129483089-36624) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.c.S.Request [cdcr-source_shard1_replica1] webapp=/solr path=/update params={_stateVer_=cdcr-source:3&wt=javabin&version=2} status=0 QTime=4
[junit4] 2> 842287 INFO (qtp2129483089-36628) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 842287 INFO (qtp2129483089-36628) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@45dc5ae
[junit4] 2> 842328 INFO (qtp2129483089-36628) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@31536a5[cdcr-source_shard1_replica1] main]
[junit4] 2> 842328 INFO (searcherExecutor-1080-thread-1-processing-n:127.0.0.1:41758_solr x:cdcr-source_shard1_replica1 s:shard1 c:cdcr-source r:core_node1) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.c.SolrCore [cdcr-source_shard1_replica1] Registered new searcher Searcher@31536a5[cdcr-source_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.5.0):C100) Uninverting(_1(6.5.0):C100) Uninverting(_2(6.5.0):C100) Uninverting(_3(6.5.0):C100) Uninverting(_4(6.5.0):C100) Uninverting(_5(6.5.0):C100)))}
[junit4] 2> 842328 INFO (qtp2129483089-36628) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 842328 INFO (qtp2129483089-36628) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.c.S.Request [cdcr-source_shard1_replica1] webapp=/solr path=/update params={_stateVer_=cdcr-source:3&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2} status=0 QTime=41
[junit4] 1> Adding 100 docs with commit=true, numDocs=700
[junit4] 2> 842336 INFO (qtp2129483089-36621) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.c.S.Request [cdcr-source_shard1_replica1] webapp=/solr path=/update params={_stateVer_=cdcr-source:3&wt=javabin&version=2} status=0 QTime=5
[junit4] 2> 842338 INFO (qtp2129483089-36625) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 842338 INFO (qtp2129483089-36625) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@45dc5ae
[junit4] 2> 842373 INFO (qtp2129483089-36625) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@52028cc2[cdcr-source_shard1_replica1] main]
[junit4] 2> 842373 INFO (searcherExecutor-1080-thread-1-processing-n:127.0.0.1:41758_solr x:cdcr-source_shard1_replica1 s:shard1 c:cdcr-source r:core_node1) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.c.SolrCore [cdcr-source_shard1_replica1] Registered new searcher Searcher@52028cc2[cdcr-source_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.5.0):C100) Uninverting(_1(6.5.0):C100) Uninverting(_2(6.5.0):C100) Uninverting(_3(6.5.0):C100) Uninverting(_4(6.5.0):C100) Uninverting(_5(6.5.0):C100) Uninverting(_6(6.5.0):C100)))}
[junit4] 2> 842373 INFO (qtp2129483089-36625) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 842374 INFO (qtp2129483089-36625) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.c.S.Request [cdcr-source_shard1_replica1] webapp=/solr path=/update params={_stateVer_=cdcr-source:3&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2} status=0 QTime=35
[junit4] 1> Adding 100 docs with commit=true, numDocs=800
[junit4] 2> 842381 INFO (qtp2129483089-36622) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.c.S.Request [cdcr-source_shard1_replica1] webapp=/solr path=/update params={_stateVer_=cdcr-source:3&wt=javabin&version=2} status=0 QTime=4
[junit4] 2> 842389 INFO (qtp2129483089-36626) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 842389 INFO (qtp2129483089-36626) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@45dc5ae
[junit4] 2> 842423 INFO (qtp2129483089-36626) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@243488f5[cdcr-source_shard1_replica1] main]
[junit4] 2> 842423 INFO (searcherExecutor-1080-thread-1-processing-n:127.0.0.1:41758_solr x:cdcr-source_shard1_replica1 s:shard1 c:cdcr-source r:core_node1) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.c.SolrCore [cdcr-source_shard1_replica1] Registered new searcher Searcher@243488f5[cdcr-source_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.5.0):C100) Uninverting(_1(6.5.0):C100) Uninverting(_2(6.5.0):C100) Uninverting(_3(6.5.0):C100) Uninverting(_4(6.5.0):C100) Uninverting(_5(6.5.0):C100) Uninverting(_6(6.5.0):C100) Uninverting(_7(6.5.0):C100)))}
[junit4] 2> 842423 INFO (qtp2129483089-36626) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 842424 INFO (qtp2129483089-36626) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.c.S.Request [cdcr-source_shard1_replica1] webapp=/solr path=/update params={_stateVer_=cdcr-source:3&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2} status=0 QTime=34
[junit4] 1> Adding 100 docs with commit=true, numDocs=900
[junit4] 2> 842430 INFO (qtp2129483089-36624) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.c.S.Request [cdcr-source_shard1_replica1] webapp=/solr path=/update params={_stateVer_=cdcr-source:3&wt=javabin&version=2} status=0 QTime=4
[junit4] 2> 842432 INFO (qtp2129483089-36628) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 842433 INFO (qtp2129483089-36628) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@45dc5ae
[junit4] 2> 842475 INFO (qtp2129483089-36628) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@693dff0d[cdcr-source_shard1_replica1] main]
[junit4] 2> 842475 INFO (searcherExecutor-1080-thread-1-processing-n:127.0.0.1:41758_solr x:cdcr-source_shard1_replica1 s:shard1 c:cdcr-source r:core_node1) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.c.SolrCore [cdcr-source_shard1_replica1] Registered new searcher Searcher@693dff0d[cdcr-source_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.5.0):C100) Uninverting(_1(6.5.0):C100) Uninverting(_2(6.5.0):C100) Uninverting(_3(6.5.0):C100) Uninverting(_4(6.5.0):C100) Uninverting(_5(6.5.0):C100) Uninverting(_6(6.5.0):C100) Uninverting(_7(6.5.0):C100) Uninverting(_8(6.5.0):C100)))}
[junit4] 2> 842475 INFO (qtp2129483089-36628) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 842475 INFO (qtp2129483089-36628) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.c.S.Request [cdcr-source_shard1_replica1] webapp=/solr path=/update params={_stateVer_=cdcr-source:3&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2} status=0 QTime=43
[junit4] 1> Adding 100 docs with commit=true, numDocs=1000
[junit4] 2> 842482 INFO (qtp2129483089-36628) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.c.S.Request [cdcr-source_shard1_replica1] webapp=/solr path=/update params={_stateVer_=cdcr-source:3&wt=javabin&version=2} status=0 QTime=3
[junit4] 2> 842494 INFO (qtp2129483089-36628) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 842494 INFO (qtp2129483089-36628) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@45dc5ae
[junit4] 2> 842550 INFO (qtp2129483089-36628) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@11f9d7bc[cdcr-source_shard1_replica1] main]
[junit4] 2> 842550 INFO (searcherExecutor-1080-thread-1-processing-n:127.0.0.1:41758_solr x:cdcr-source_shard1_replica1 s:shard1 c:cdcr-source r:core_node1) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.c.SolrCore [cdcr-source_shard1_replica1] Registered new searcher Searcher@11f9d7bc[cdcr-source_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.5.0):C100) Uninverting(_1(6.5.0):C100) Uninverting(_2(6.5.0):C100) Uninverting(_3(6.5.0):C100) Uninverting(_4(6.5.0):C100) Uninverting(_5(6.5.0):C100) Uninverting(_6(6.5.0):C100) Uninverting(_7(6.5.0):C100) Uninverting(_8(6.5.0):C100) Uninverting(_9(6.5.0):C100)))}
[junit4] 2> 842550 INFO (qtp2129483089-36628) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 842552 INFO (qtp2129483089-36628) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.c.S.Request [cdcr-source_shard1_replica1] webapp=/solr path=/update params={_stateVer_=cdcr-source:3&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2} status=0 QTime=57
[junit4] 1> Adding 100 docs with commit=true, numDocs=1100
[junit4] 2> 842563 INFO (qtp2129483089-36621) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.c.S.Request [cdcr-source_shard1_replica1] webapp=/solr path=/update params={_stateVer_=cdcr-source:3&wt=javabin&version=2} status=0 QTime=4
[junit4] 2> 842566 INFO (qtp2129483089-36625) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 842566 INFO (qtp2129483089-36625) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@45dc5ae
[junit4] 2> 842606 INFO (qtp2129483089-36625) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@347d9e0f[cdcr-source_shard1_replica1] main]
[junit4] 2> 842606 INFO (searcherExecutor-1080-thread-1-processing-n:127.0.0.1:41758_solr x:cdcr-source_shard1_replica1 s:shard1 c:cdcr-source r:core_node1) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.c.SolrCore [cdcr-source_shard1_replica1] Registered new searcher Searcher@347d9e0f[cdcr-source_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.5.0):C100) Uninverting(_1(6.5.0):C100) Uninverting(_2(6.5.0):C100) Uninverting(_3(6.5.0):C100) Uninverting(_4(6.5.0):C100) Uninverting(_5(6.5.0):C100) Uninverting(_6(6.5.0):C100) Uninverting(_7(6.5.0):C100) Uninverting(_8(6.5.0):C100) Uninverting(_9(6.5.0):C100) Uninverting(_b(6.5.0):C100)))}
[junit4] 2> 842606 INFO (qtp2129483089-36625) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 842607 INFO (qtp2129483089-36625) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.c.S.Request [cdcr-source_shard1_replica1] webapp=/solr path=/update params={_stateVer_=cdcr-source:3&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2} status=0 QTime=41
[junit4] 1> Adding 100 docs with commit=true, numDocs=1200
[junit4] 2> 842617 INFO (qtp2129483089-36625) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.c.S.Request [cdcr-source_shard1_replica1] webapp=/solr path=/update params={_stateVer_=cdcr-source:3&wt=javabin&version=2} status=0 QTime=5
[junit4] 2> 842619 INFO (qtp2129483089-36622) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 842620 INFO (qtp2129483089-36622) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@45dc5ae
[junit4] 2> 842659 INFO (qtp2129483089-36622) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@3164b8d4[cdcr-source_shard1_replica1] main]
[junit4] 2> 842660 INFO (searcherExecutor-1080-thread-1-processing-n:127.0.0.1:41758_solr x:cdcr-source_shard1_replica1 s:shard1 c:cdcr-source r:core_node1) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.c.SolrCore [cdcr-source_shard1_replica1] Registered new searcher Searcher@3164b8d4[cdcr-source_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_a(6.5.0):C1000) Uninverting(_b(6.5.0):C100) Uninverting(_c(6.5.0):C100)))}
[junit4] 2> 842660 INFO (qtp2129483089-36622) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 842668 INFO (qtp2129483089-36622) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.c.S.Request [cdcr-source_shard1_replica1] webapp=/solr path=/update params={_stateVer_=cdcr-source:3&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2} status=0 QTime=48
[junit4] 1> Adding 100 docs with commit=true, numDocs=1300
[junit4] 2> 842675 INFO (qtp2129483089-36626) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.c.S.Request [cdcr-source_shard1_replica1] webapp=/solr path=/update params={_stateVer_=cdcr-source:3&wt=javabin&version=2} status=0 QTime=4
[junit4] 2> 842678 INFO (qtp2129483089-36624) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 842679 INFO (qtp2129483089-36624) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@45dc5ae
[junit4] 2> 842707 INFO (qtp2129483089-36624) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@1556d15c[cdcr-source_shard1_replica1] main]
[junit4] 2> 842707 INFO (searcherExecutor-1080-thread-1-processing-n:127.0.0.1:41758_solr x:cdcr-source_shard1_replica1 s:shard1 c:cdcr-source r:core_node1) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.c.SolrCore [cdcr-source_shard1_replica1] Registered new searcher Searcher@1556d15c[cdcr-source_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_a(6.5.0):C1000) Uninverting(_b(6.5.0):C100) Uninverting(_c(6.5.0):C100) Uninverting(_d(6.5.0):C100)))}
[junit4] 2> 842707 INFO (qtp2129483089-36624) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 842707 INFO (qtp2129483089-36624) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.c.S.Request [cdcr-source_shard1_replica1] webapp=/solr path=/update params={_stateVer_=cdcr-source:3&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2} status=0 QTime=28
[junit4] 1> Adding 100 docs with commit=true, numDocs=1400
[junit4] 2> 842714 INFO (qtp2129483089-36628) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.c.S.Request [cdcr-source_shard1_replica1] webapp=/solr path=/update params={_stateVer_=cdcr-source:3&wt=javabin&version=2} status=0 QTime=4
[junit4] 2> 842717 INFO (qtp2129483089-36621) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 842717 INFO (qtp2129483089-36621) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@45dc5ae
[junit4] 2> 842745 INFO (qtp2129483089-36621) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@70f65571[cdcr-source_shard1_replica1] main]
[junit4] 2> 842745 INFO (searcherExecutor-1080-thread-1-processing-n:127.0.0.1:41758_solr x:cdcr-source_shard1_replica1 s:shard1 c:cdcr-source r:core_node1) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.c.SolrCore [cdcr-source_shard1_replica1] Registered new searcher Searcher@70f65571[cdcr-source_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_a(6.5.0):C1000) Uninverting(_b(6.5.0):C100) Uninverting(_c(6.5.0):C100) Uninverting(_d(6.5.0):C100) Uninverting(_e(6.5.0):C100)))}
[junit4] 2> 842745 INFO (qtp2129483089-36621) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 842745 INFO (qtp2129483089-36621) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.c.S.Request [cdcr-source_shard1_replica1] webapp=/solr path=/update params={_stateVer_=cdcr-source:3&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2} status=0 QTime=28
[junit4] 1> Adding 100 docs with commit=true, numDocs=1500
[junit4] 2> 842754 INFO (qtp2129483089-36625) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.c.S.Request [cdcr-source_shard1_replica1] webapp=/solr path=/update params={_stateVer_=cdcr-source:3&wt=javabin&version=2} status=0 QTime=6
[junit4] 2> 842757 INFO (qtp2129483089-36622) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 842757 INFO (qtp2129483089-36622) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@45dc5ae
[junit4] 2> 842787 INFO (qtp2129483089-36622) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@3b19556b[cdcr-source_shard1_replica1] main]
[junit4] 2> 842787 INFO (searcherExecutor-1080-thread-1-processing-n:127.0.0.1:41758_solr x:cdcr-source_shard1_replica1 s:shard1 c:cdcr-source r:core_node1) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.c.SolrCore [cdcr-source_shard1_replica1] Registered new searcher Searcher@3b19556b[cdcr-source_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_a(6.5.0):C1000) Uninverting(_b(6.5.0):C100) Uninverting(_c(6.5.0):C100) Uninverting(_d(6.5.0):C100) Uninverting(_e(6.5.0):C100) Uninverting(_f(6.5.0):C100)))}
[junit4] 2> 842787 INFO (qtp2129483089-36622) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 842787 INFO (qtp2129483089-36622) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.c.S.Request [cdcr-source_shard1_replica1] webapp=/solr path=/update params={_stateVer_=cdcr-source:3&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2} status=0 QTime=30
[junit4] 1> Adding 100 docs with commit=true, numDocs=1600
[junit4] 2> 842794 INFO (qtp2129483089-36626) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.c.S.Request [cdcr-source_shard1_replica1] webapp=/solr path=/update params={_stateVer_=cdcr-source:3&wt=javabin&version=2} status=0 QTime=4
[junit4] 2> 842797 INFO (qtp2129483089-36626) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 842797 INFO (qtp2129483089-36626) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@45dc5ae
[junit4] 2> 842826 INFO (qtp2129483089-36626) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@7faff261[cdcr-source_shard1_replica1] main]
[junit4] 2> 842827 INFO (searcherExecutor-1080-thread-1-processing-n:127.0.0.1:41758_solr x:cdcr-source_shard1_replica1 s:shard1 c:cdcr-source r:core_node1) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.c.SolrCore [cdcr-source_shard1_replica1] Registered new searcher Searcher@7faff261[cdcr-source_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_a(6.5.0):C1000) Uninverting(_b(6.5.0):C100) Uninverting(_c(6.5.0):C100) Uninverting(_d(6.5.0):C100) Uninverting(_e(6.5.0):C100) Uninverting(_f(6.5.0):C100) Uninverting(_g(6.5.0):C100)))}
[junit4] 2> 842827 INFO (qtp2129483089-36626) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 842827 INFO (qtp2129483089-36626) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.c.S.Request [cdcr-source_shard1_replica1] webapp=/solr path=/update params={_stateVer_=cdcr-source:3&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2} status=0 QTime=30
[junit4] 1> Adding 100 docs with commit=true, numDocs=1700
[junit4] 2> 842833 INFO (qtp2129483089-36624) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.c.S.Request [cdcr-source_shard1_replica1] webapp=/solr path=/update params={_stateVer_=cdcr-source:3&wt=javabin&version=2} status=0 QTime=4
[junit4] 2> 842835 INFO (qtp2129483089-36628) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 842835 INFO (qtp2129483089-36628) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@45dc5ae
[junit4] 2> 842863 INFO (qtp2129483089-36628) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@241d689b[cdcr-source_shard1_replica1] main]
[junit4] 2> 842863 INFO (searcherExecutor-1080-thread-1-processing-n:127.0.0.1:41758_solr x:cdcr-source_shard1_replica1 s:shard1 c:cdcr-source r:core_node1) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.c.SolrCore [cdcr-source_shard1_replica1] Registered new searcher Searcher@241d689b[cdcr-source_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_a(6.5.0):C1000) Uninverting(_b(6.5.0):C100) Uninverting(_c(6.5.0):C100) Uninverting(_d(6.5.0):C100) Uninverting(_e(6.5.0):C100) Uninverting(_f(6.5.0):C100) Uninverting(_g(6.5.0):C100) Uninverting(_h(6.5.0):C100)))}
[junit4] 2> 842863 INFO (qtp2129483089-36628) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 842864 INFO (qtp2129483089-36628) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.c.S.Request [cdcr-source_shard1_replica1] webapp=/solr path=/update params={_stateVer_=cdcr-source:3&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2} status=0 QTime=28
[junit4] 1> Adding 100 docs with commit=true, numDocs=1800
[junit4] 2> 842870 INFO (qtp2129483089-36621) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.c.S.Request [cdcr-source_shard1_replica1] webapp=/solr path=/update params={_stateVer_=cdcr-source:3&wt=javabin&version=2} status=0 QTime=3
[junit4] 2> 842872 INFO (qtp2129483089-36625) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 842872 INFO (qtp2129483089-36625) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@45dc5ae
[junit4] 2> 842903 INFO (qtp2129483089-36625) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@783ba924[cdcr-source_shard1_replica1] main]
[junit4] 2> 842904 INFO (searcherExecutor-1080-thread-1-processing-n:127.0.0.1:41758_solr x:cdcr-source_shard1_replica1 s:shard1 c:cdcr-source r:core_node1) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.c.SolrCore [cdcr-source_shard1_replica1] Registered new searcher Searcher@783ba924[cdcr-source_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_a(6.5.0):C1000) Uninverting(_b(6.5.0):C100) Uninverting(_c(6.5.0):C100) Uninverting(_d(6.5.0):C100) Uninverting(_e(6.5.0):C100) Uninverting(_f(6.5.0):C100) Uninverting(_g(6.5.0):C100) Uninverting(_h(6.5.0):C100) Uninverting(_i(6.5.0):C100)))}
[junit4] 2> 842904 INFO (qtp2129483089-36625) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 842904 INFO (qtp2129483089-36625) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.c.S.Request [cdcr-source_shard1_replica1] webapp=/solr path=/update params={_stateVer_=cdcr-source:3&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2} status=0 QTime=32
[junit4] 1> Adding 100 docs with commit=true, numDocs=1900
[junit4] 2> 842912 INFO (qtp2129483089-36622) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.c.S.Request [cdcr-source_shard1_replica1] webapp=/solr path=/update params={_stateVer_=cdcr-source:3&wt=javabin&version=2} status=0 QTime=6
[junit4] 2> 842914 INFO (qtp2129483089-36626) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 842914 INFO (qtp2129483089-36626) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@45dc5ae
[junit4] 2> 842954 INFO (qtp2129483089-36626) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@54d64cd4[cdcr-source_shard1_replica1] main]
[junit4] 2> 842954 INFO (searcherExecutor-1080-thread-1-processing-n:127.0.0.1:41758_solr x:cdcr-source_shard1_replica1 s:shard1 c:cdcr-source r:core_node1) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.c.SolrCore [cdcr-source_shard1_replica1] Registered new searcher Searcher@54d64cd4[cdcr-source_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_a(6.5.0):C1000) Uninverting(_b(6.5.0):C100) Uninverting(_c(6.5.0):C100) Uninverting(_d(6.5.0):C100) Uninverting(_e(6.5.0):C100) Uninverting(_f(6.5.0):C100) Uninverting(_g(6.5.0):C100) Uninverting(_h(6.5.0):C100) Uninverting(_i(6.5.0):C100) Uninverting(_j(6.5.0):C100)))}
[junit4] 2> 842954 INFO (qtp2129483089-36626) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 842965 INFO (qtp2129483089-36626) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.c.S.Request [cdcr-source_shard1_replica1] webapp=/solr path=/update params={_stateVer_=cdcr-source:3&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2} status=0 QTime=51
[junit4] 1> Adding 100 docs with commit=true, numDocs=2000
[junit4] 2> 842971 INFO (qtp2129483089-36624) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.c.S.Request [cdcr-source_shard1_replica1] webapp=/solr path=/update params={_stateVer_=cdcr-source:3&wt=javabin&version=2} status=0 QTime=3
[junit4] 2> 842973 INFO (qtp2129483089-36624) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 842973 INFO (qtp2129483089-36624) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@45dc5ae
[junit4] 2> 843009 INFO (qtp2129483089-36624) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@30153ba3[cdcr-source_shard1_replica1] main]
[junit4] 2> 843009 INFO (searcherExecutor-1080-thread-1-processing-n:127.0.0.1:41758_solr x:cdcr-source_shard1_replica1 s:shard1 c:cdcr-source r:core_node1) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.c.SolrCore [cdcr-source_shard1_replica1] Registered new searcher Searcher@30153ba3[cdcr-source_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_k(6.5.0):C1900) Uninverting(_l(6.5.0):C100)))}
[junit4] 2> 843009 INFO (qtp2129483089-36624) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 843010 INFO (qtp2129483089-36624) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.c.S.Request [cdcr-source_shard1_replica1] webapp=/solr path=/update params={_stateVer_=cdcr-source:3&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2} status=0 QTime=37
[junit4] 1> Adding 100 docs with commit=true, numDocs=2100
[junit4] 2> 843015 INFO (qtp2129483089-36621) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.c.S.Request [cdcr-source_shard1_replica1] webapp=/solr path=/update params={_stateVer_=cdcr-source:3&wt=javabin&version=2} status=0 QTime=2
[junit4] 2> 843017 INFO (qtp2129483089-36625) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 843017 INFO (qtp2129483089-36625) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@45dc5ae
[junit4] 2> 843066 INFO (qtp2129483089-36625) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@5573e7d3[cdcr-source_shard1_replica1] main]
[junit4] 2> 843066 INFO (searcherExecutor-1080-thread-1-processing-n:127.0.0.1:41758_solr x:cdcr-source_shard1_replica1 s:shard1 c:cdcr-source r:core_node1) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.c.SolrCore [cdcr-source_shard1_replica1] Registered new searcher Searcher@5573e7d3[cdcr-source_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_k(6.5.0):C1900) Uninverting(_l(6.5.0):C100) Uninverting(_m(6.5.0):C100)))}
[junit4] 2> 843066 INFO (qtp2129483089-36625) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 843066 INFO (qtp2129483089-36625) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.c.S.Request [cdcr-source_shard1_replica1] webapp=/solr path=/update params={_stateVer_=cdcr-source:3&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2} status=0 QTime=49
[junit4] 1> Adding 100 docs with commit=true, numDocs=2200
[junit4] 2> 843071 INFO (qtp2129483089-36622) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.c.S.Request [cdcr-source_shard1_replica1] webapp=/solr path=/update params={_stateVer_=cdcr-source:3&wt=javabin&version=2} status=0 QTime=2
[junit4] 2> 843073 INFO (qtp2129483089-36626) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 843073 INFO (qtp2129483089-36626) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@45dc5ae
[junit4] 2> 843130 INFO (qtp2129483089-36626) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@11e83a4e[cdcr-source_shard1_replica1] main]
[junit4] 2> 843130 INFO (qtp2129483089-36626) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 843133 INFO (searcherExecutor-1080-thread-1-processing-n:127.0.0.1:41758_solr x:cdcr-source_shard1_replica1 s:shard1 c:cdcr-source r:core_node1) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.c.SolrCore [cdcr-source_shard1_replica1] Registered new searcher Searcher@11e83a4e[cdcr-source_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_k(6.5.0):C1900) Uninverting(_l(6.5.0):C100) Uninverting(_m(6.5.0):C100) Uninverting(_n(6.5.0):C100)))}
[junit4] 2> 843134 INFO (qtp2129483089-36626) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.c.S.Request [cdcr-source_shard1_replica1] webapp=/solr path=/update params={_stateVer_=cdcr-source:3&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2} status=0 QTime=60
[junit4] 1> Adding 100 docs with commit=true, numDocs=2300
[junit4] 2> 843139 INFO (qtp2129483089-36628) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.c.S.Request [cdcr-source_shard1_replica1] webapp=/solr path=/update params={_stateVer_=cdcr-source:3&wt=javabin&version=2} status=0 QTime=2
[junit4] 2> 843141 INFO (qtp2129483089-36624) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 843141 INFO (qtp2129483089-36624) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@45dc5ae
[junit4] 2> 843166 INFO (qtp2129483089-36624) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@59567db1[cdcr-source_shard1_replica1] main]
[junit4] 2> 843167 INFO (searcherExecutor-1080-thread-1-processing-n:127.0.0.1:41758_solr x:cdcr-source_shard1_replica1 s:shard1 c:cdcr-source r:core_node1) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.c.SolrCore [cdcr-source_shard1_replica1] Registered new searcher Searcher@59567db1[cdcr-source_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_k(6.5.0):C1900) Uninverting(_l(6.5.0):C100) Uninverting(_m(6.5.0):C100) Uninverting(_n(6.5.0):C100) Uninverting(_o(6.5.0):C100)))}
[junit4] 2> 843167 INFO (qtp2129483089-36624) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 843167 INFO (qtp2129483089-36624) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.c.S.Request [cdcr-source_shard1_replica1] webapp=/solr path=/update params={_stateVer_=cdcr-source:3&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2} status=0 QTime=26
[junit4] 1> Adding 100 docs with commit=true, numDocs=2400
[junit4] 2> 843173 INFO (qtp2129483089-36621) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.c.S.Request [cdcr-source_shard1_replica1] webapp=/solr path=/update params={_stateVer_=cdcr-source:3&wt=javabin&version=2} status=0 QTime=3
[junit4] 2> 843174 INFO (qtp2129483089-36625) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 843174 INFO (qtp2129483089-36625) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@45dc5ae
[junit4] 2> 843198 INFO (qtp2129483089-36625) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@422c0fd7[cdcr-source_shard1_replica1] main]
[junit4] 2> 843198 INFO (searcherExecutor-1080-thread-1-processing-n:127.0.0.1:41758_solr x:cdcr-source_shard1_replica1 s:shard1 c:cdcr-source r:core_node1) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.c.SolrCore [cdcr-source_shard1_replica1] Registered new searcher Searcher@422c0fd7[cdcr-source_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_k(6.5.0):C1900) Uninverting(_l(6.5.0):C100) Uninverting(_m(6.5.0):C100) Uninverting(_n(6.5.0):C100) Uninverting(_o(6.5.0):C100) Uninverting(_p(6.5.0):C100)))}
[junit4] 2> 843198 INFO (qtp2129483089-36625) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 843198 INFO (qtp2129483089-36625) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.c.S.Request [cdcr-source_shard1_replica1] webapp=/solr path=/update params={_stateVer_=cdcr-source:3&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2} status=0 QTime=23
[junit4] 1> Adding 100 docs with commit=true, numDocs=2500
[junit4] 2> 843204 INFO (qtp2129483089-36622) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.c.S.Request [cdcr-source_shard1_replica1] webapp=/solr path=/update params={_stateVer_=cdcr-source:3&wt=javabin&version=2} status=0 QTime=3
[junit4] 2> 843205 INFO (qtp2129483089-36626) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 843205 INFO (qtp2129483089-36626) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@45dc5ae
[junit4] 2> 843232 INFO (qtp2129483089-36626) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@417edb32[cdcr-source_shard1_replica1] main]
[junit4] 2> 843232 INFO (searcherExecutor-1080-thread-1-processing-n:127.0.0.1:41758_solr x:cdcr-source_shard1_replica1 s:shard1 c:cdcr-source r:core_node1) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.c.SolrCore [cdcr-source_shard1_replica1] Registered new searcher Searcher@417edb32[cdcr-source_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_k(6.5.0):C1900) Uninverting(_l(6.5.0):C100) Uninverting(_m(6.5.0):C100) Uninverting(_n(6.5.0):C100) Uninverting(_o(6.5.0):C100) Uninverting(_p(6.5.0):C100) Uninverting(_q(6.5.0):C100)))}
[junit4] 2> 843232 INFO (qtp2129483089-36626) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 843232 INFO (qtp2129483089-36626) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.c.S.Request [cdcr-source_shard1_replica1] webapp=/solr path=/update params={_stateVer_=cdcr-source:3&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2} status=0 QTime=27
[junit4] 1> Adding 100 docs with commit=true, numDocs=2600
[junit4] 2> 843256 INFO (qtp2129483089-36628) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.c.S.Request [cdcr-source_shard1_replica1] webapp=/solr path=/update params={_stateVer_=cdcr-source:3&wt=javabin&version=2} status=0 QTime=21
[junit4] 2> 843258 INFO (qtp2129483089-36624) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 843258 INFO (qtp2129483089-36624) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@45dc5ae
[junit4] 2> 843287 INFO (qtp2129483089-36624) [n:127.0.0.1:41758_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@346c8092[cdcr-source_shard1_replica1] main]
[junit4] 2> 843287 INFO (searcherExecutor-1080-thread-1-pro
[...truncated too long message...]
[junit4] 2> java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:164)
[junit4] 2> java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:209)
[junit4] 2>
[junit4] 2> JUnit4-serializer-daemon:
[junit4] 2> java.lang.Thread.sleep(Native Method)
[junit4] 2> com.carrotsearch.ant.tasks.junit4.events.Serializer$1.run(Serializer.java:50)
[junit4] 2>
[junit4] 2> main:
[junit4] 2> java.lang.Object.wait(Native Method)
[junit4] 2> java.lang.Thread.join(Thread.java:1249)
[junit4] 2> java.lang.Thread.join(Thread.java:1323)
[junit4] 2> [...com.carrotsearch.randomizedtesting.*]
[junit4] 2> com.carrotsearch.ant.tasks.junit4.slave.SlaveMain.execute(SlaveMain.java:244)
[junit4] 2> com.carrotsearch.ant.tasks.junit4.slave.SlaveMain.main(SlaveMain.java:355)
[junit4] 2> com.carrotsearch.ant.tasks.junit4.slave.SlaveMainSafe.main(SlaveMainSafe.java:13)
[junit4] 2>
[junit4] 2> Thread-40765:
[junit4] 2> java.lang.Thread.sleep(Native Method)
[junit4] 2> org.apache.zookeeper.Login$1.run(Login.java:183)
[junit4] 2> java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> org.apache.hadoop.hdfs.PeerCache@5802bfcb:
[junit4] 2> java.lang.Thread.sleep(Native Method)
[junit4] 2> org.apache.hadoop.hdfs.PeerCache.run(PeerCache.java:255)
[junit4] 2> org.apache.hadoop.hdfs.PeerCache.access$000(PeerCache.java:46)
[junit4] 2> org.apache.hadoop.hdfs.PeerCache$1.run(PeerCache.java:124)
[junit4] 2> java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> Reference Handler:
[junit4] 2> java.lang.Object.wait(Native Method)
[junit4] 2> java.lang.Object.wait(Object.java:502)
[junit4] 2> java.lang.ref.Reference.tryHandlePending(Reference.java:191)
[junit4] 2> java.lang.ref.Reference$ReferenceHandler.run(Reference.java:153)
[junit4] 2>
[junit4] 2> Signal Dispatcher:
[junit4] 2>
[junit4] 2> 3801012 INFO (SUITE-HdfsRecoveryZkTest-seed#[B003351AF67433AA]-worker) [ ] o.a.s.SolrTestCaseJ4 ------------------------------------------------------- Done waiting for tracked resources to be released
[junit4] 2> NOTE: test params are: codec=CheapBastard, sim=RandomSimilarity(queryNorm=false,coord=no): {}, locale=id, timezone=Brazil/West
[junit4] 2> NOTE: Linux 3.13.0-85-generic amd64/Oracle Corporation 1.8.0_121 (64-bit)/cpus=4,threads=1,free=131127760,total=527433728
[junit4] 2> NOTE: All tests run in this JVM: [DirectoryFactoryTest, CollectionStateFormat2Test, TestLockTree, JsonLoaderTest, MultiThreadedOCPTest, TestFuzzyAnalyzedSuggestions, BitVectorTest, DistribCursorPagingTest, BooleanFieldTest, TestCSVResponseWriter, TestFieldCollectionResource, TestCloudPivotFacet, TestUnifiedSolrHighlighter, TestRTimerTree, IndexSchemaTest, TestLRUCache, WordBreakSolrSpellCheckerTest, TestNumericTerms64, TestCoreContainer, HdfsBasicDistributedZkTest, ZkSolrClientTest, TestManagedStopFilterFactory, TestStressUserVersions, TestDefaultSearchFieldResource, TestRandomCollapseQParserPlugin, PreAnalyzedUpdateProcessorTest, TestExceedMaxTermLength, CdcrBootstrapTest, SimpleMLTQParserTest, TestSchemalessBufferedUpdates, TestFiltering, TestFastOutputStream, TestLMDirichletSimilarityFactory, InfixSuggestersTest, TestScoreJoinQPScore, TestImplicitCoreProperties, TestFileDictionaryLookup, TestSchemaSimilarityResource, MergeStrategyTest, CollectionsAPISolrJTest, SolrMetricsIntegrationTest, BJQParserTest, TestFieldCache, TestFieldCacheSort, TestTolerantUpdateProcessorCloud, TestFieldTypeResource, TestSQLHandler, InfoHandlerTest, RuleEngineTest, TestCharFilters, TestFilteredDocIdSet, DocValuesMissingTest, PeerSyncWithIndexFingerprintCachingTest, TestElisionMultitermQuery, TestUpdate, TestSolrCloudSnapshots, TestConfigSetsAPIExclusivity, IndexBasedSpellCheckerTest, TestNonDefinedSimilarityFactory, DirectSolrConnectionTest, ClassificationUpdateProcessorIntegrationTest, SharedFSAutoReplicaFailoverTest, TestWordDelimiterFilterFactory, DeleteInactiveReplicaTest, TestMinMaxOnMultiValuedField, TestSurroundQueryParser, SolrJmxReporterTest, TestSystemIdResolver, TestDeleteCollectionOnDownNodes, AddSchemaFieldsUpdateProcessorFactoryTest, SuggesterFSTTest, TestTrie, ZkCLITest, DistributedFacetPivotLargeTest, MoreLikeThisHandlerTest, TestJavabinTupleStreamParser, UtilsToolTest, TestRTGBase, HLLSerializationTest, TestSolrCloudWithHadoopAuthPlugin, DistanceUnitsTest, TestXmlQParserPlugin, SolrInfoMBeanTest, TestMacroExpander, ShardRoutingCustomTest, BasicFunctionalityTest, IndexSchemaRuntimeFieldTest, TestAddFieldRealTimeGet, TestMiniSolrCloudClusterSSL, CheckHdfsIndexTest, SpatialFilterTest, SliceStateTest, TestLuceneMatchVersion, HdfsThreadLeakTest, LeaderFailoverAfterPartitionTest, TestLeaderElectionZkExpiry, DistributedFacetPivotSmallTest, DocumentBuilderTest, SpellCheckComponentTest, LoggingHandlerTest, TestQueryTypes, AnalysisErrorHandlingTest, SearchHandlerTest, TestReplicationHandlerBackup, TestQueryUtils, ZkControllerTest, TestCloudManagedSchema, SpatialHeatmapFacetsTest, ChaosMonkeySafeLeaderTest, CollectionsAPIDistributedZkTest, URLClassifyProcessorTest, TestManagedResource, TestNamedUpdateProcessors, TestPartialUpdateDeduplication, TestBulkSchemaAPI, OverseerTest, LeaderElectionIntegrationTest, ShardRoutingTest, RecoveryZkTest, TestReplicationHandler, TestCrossCoreJoin, TestCursorMarkWithoutUniqueKey, TestDistributedMissingSort, TestHighlightDedupGrouping, TestSimpleTrackingShardHandler, TestTolerantSearch, TestEmbeddedSolrServerConstructors, ConnectionReuseTest, ActionThrottleTest, AliasIntegrationTest, AssignTest, BaseCdcrDistributedZkTest, CdcrReplicationDistributedZkTest, CdcrRequestHandlerTest, ConnectionManagerTest, CreateCollectionCleanupTest, DeleteLastCustomShardedReplicaTest, DeleteNodeTest, DeleteReplicaTest, DocValuesNotIndexedTest, ForceLeaderTest, LeaderInitiatedRecoveryOnCommitTest, OverseerCollectionConfigSetProcessorTest, OverseerModifyCollectionTest, OverseerRolesTest, OverseerStatusTest, RemoteQueryErrorTest, ReplaceNodeTest, SSLMigrationTest, SaslZkACLProviderTest, SolrCLIZkUtilsTest, SolrXmlInZkTest, TestAuthenticationFramework, TestCloudDeleteByQuery, TestCloudInspectUtil, TestCloudPseudoReturnFields, TestCloudRecovery, TestClusterProperties, TestConfigSetsAPI, TestConfigSetsAPIZkFailure, TestExclusionRuleCollectionAccess, TestLocalFSCloudBackupRestore, TestMiniSolrCloudCluster, TestOnReconnectListenerSupport, TestRandomRequestDistribution, TestRebalanceLeaders, TestReplicaProperties, TestRequestForwarding, TestRequestStatusCollectionAPI, TestSSLRandomization, TestSegmentSorting, TestStressCloudBlindAtomicUpdates, TestTolerantUpdateProcessorRandomCloud, VMParamsZkACLAndCredentialsProvidersTest, HdfsBasicDistributedZk2Test, HdfsRecoverLeaseTest, HdfsRecoveryZkTest]
[junit4] 2> NOTE: download the large Jenkins line-docs file by running 'ant get-jenkins-line-docs' in the lucene directory.
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=HdfsRecoveryZkTest -Dtests.seed=B003351AF67433AA -Dtests.multiplier=2 -Dtests.nightly=true -Dtests.slow=true -Dtests.linedocsfile=/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/test-data/enwiki.random.lines.txt -Dtests.locale=id -Dtests.timezone=Brazil/West -Dtests.asserts=true -Dtests.file.encoding=ISO-8859-1
[junit4] ERROR 0.00s J1 | HdfsRecoveryZkTest (suite) <<<
[junit4] > Throwable #1: java.lang.AssertionError: ObjectTracker found 1 object(s) that were not released!!! [HdfsTransactionLog]
[junit4] > org.apache.solr.common.util.ObjectReleaseTracker$ObjectTrackerException: org.apache.solr.update.HdfsTransactionLog
[junit4] > at org.apache.solr.common.util.ObjectReleaseTracker.track(ObjectReleaseTracker.java:42)
[junit4] > at org.apache.solr.update.HdfsTransactionLog.<init>(HdfsTransactionLog.java:130)
[junit4] > at org.apache.solr.update.HdfsUpdateLog.init(HdfsUpdateLog.java:203)
[junit4] > at org.apache.solr.update.UpdateHandler.<init>(UpdateHandler.java:137)
[junit4] > at org.apache.solr.update.UpdateHandler.<init>(UpdateHandler.java:94)
[junit4] > at org.apache.solr.update.DirectUpdateHandler2.<init>(DirectUpdateHandler2.java:109)
[junit4] > at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
[junit4] > at org.apache.solr.core.SolrCore.createInstance(SolrCore.java:741)
[junit4] > at org.apache.solr.core.SolrCore.createUpdateHandler(SolrCore.java:803)
[junit4] > at org.apache.solr.core.SolrCore.initUpdateHandler(SolrCore.java:1053)
[junit4] > at org.apache.solr.core.SolrCore.<init>(SolrCore.java:918)
[junit4] > at org.apache.solr.core.SolrCore.<init>(SolrCore.java:811)
[junit4] > at org.apache.solr.core.CoreContainer.create(CoreContainer.java:917)
[junit4] > at org.apache.solr.core.CoreContainer.lambda$load$3(CoreContainer.java:552)
[junit4] > at com.codahale.metrics.InstrumentedExecutorService$InstrumentedCallable.call(InstrumentedExecutorService.java:197)
[junit4] > at java.util.concurrent.FutureTask.run(FutureTask.java:266)
[junit4] > at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:229)
[junit4] > at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
[junit4] > at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
[junit4] > at java.lang.Thread.run(Thread.java:745)
[junit4] > at __randomizedtesting.SeedInfo.seed([B003351AF67433AA]:0)
[junit4] > at org.apache.solr.SolrTestCaseJ4.teardownTestCases(SolrTestCaseJ4.java:302)
[junit4] > at java.lang.Thread.run(Thread.java:745)
[junit4] Completed [568/697 (2!)] on J1 in 141.51s, 1 test, 1 failure <<< FAILURES!
[...truncated 63051 lines...]
Re: [JENKINS] Lucene-Solr-NightlyTests-6.x - Build # 303 - Still Unstable
Posted by Uwe Schindler <uw...@thetaphi.de>.
Thanks Robert for reminding me. Because there was a similar discussion about this in the Jenkins Mac Slave. In fact the issue was not caused by this limit as Jenkins Slave already started with 2048 limit.
Please don't raise the hardcoded test limit. It will likely break on Jenkins anyways. Better have a hard and low limit in test framework instead of hard to reproduce failures in Jenkins.
Uwe
Am 8. März 2017 17:50:04 MEZ schrieb Robert Muir <rc...@gmail.com>:
>If you don't like the limit for your specific test: use
>@SuppressFileSystems annotation to suppress it.
>
>But it is really insane for a unit test to use so many index files,
>and it is important to reproduce such bugs when they do happen.
>
>On Wed, Mar 8, 2017 at 11:46 AM, Chris Hostetter
><ho...@fucit.org> wrote:
>>
>> The exception is being thrown by
>org.apache.lucene.mockfile.HandleLimitFS,
>> so the OS level utlimit isn't relevant (as long as it's greter then
>2048,
>> hardcoded in TestRuleTemporaryFilesCleanup)
>>
>> With the test creating 2 diff indexes, that means each index index
>gets an
>> effective max open files limit of ~1024 files ... and with
>> RandomSimilarity it might be leaving a lot of small segments on
>"disk" for
>> both of those indexes -- which will have at least 100,000 docs in
>each
>> because this is a nightly run....
>>
>> I haven't tested this (my co is currently dirty and i'm in the middle
>of
>> something) but i suspect the seed will reproduce anywhere.
>>
>> See also SOLR-10234 where i recently pointed out similar concerns
>about
>> TestRuleTemporaryFilesCleanup's fixed limit of 2048 for the entire
>JVM,
>> even when the JVM itself is trying to simulate multiple diff indexes
>(or
>> completley distint nodes in the solr cloud test case).
>>
>>
>>
>> : Date: Wed, 8 Mar 2017 11:29:45 -0500
>> : From: Steve Rowe <sa...@gmail.com>
>> : Reply-To: dev@lucene.apache.org
>> : To: dev@lucene.apache.org
>> : Subject: Re: [JENKINS] Lucene-Solr-NightlyTests-6.x - Build # 303 -
>Still
>> : Unstable
>> :
>> :
>> : > On Mar 8, 2017, at 8:38 AM, Apache Jenkins Server
><je...@builds.apache.org> wrote:
>> : >
>> : > Build:
>https://builds.apache.org/job/Lucene-Solr-NightlyTests-6.x/303/
>> : >
>> : > 2 tests failed.
>> : > FAILED: org.apache.lucene.index.TestIndexSorting.testRandom3
>> : >
>> : > Error Message:
>> : >
>/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/lucene/build/core/test/J2/temp/lucene.index.TestIndexSorting_4609011308FB57E6-001/tempDir-004/_e4_Lucene50_0.tim:
>Too many open files
>> : >
>> : > Stack Trace:
>> : > java.nio.file.FileSystemException:
>/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/lucene/build/core/test/J2/temp/lucene.index.TestIndexSorting_4609011308FB57E6-001/tempDir-004/_e4_Lucene50_0.tim:
>Too many open files
>> :
>> : I logged in as the jenkins user on lucene1-us-west.apache.org (the
>‘lucene' jenkins slave), and ‘ulimit -aHS’ says (in part):
>> :
>> : open files (-n) 1048576
>> :
>> : I think this is the maximum value.
>> :
>> : Not sure what can be done here?
>> :
>> : --
>> : Steve
>> : www.lucidworks.com
>> :
>> :
>> :
>---------------------------------------------------------------------
>> : To unsubscribe, e-mail: dev-unsubscribe@lucene.apache.org
>> : For additional commands, e-mail: dev-help@lucene.apache.org
>> :
>> :
>>
>> -Hoss
>> http://www.lucidworks.com/
>>
>>
>> ---------------------------------------------------------------------
>> To unsubscribe, e-mail: dev-unsubscribe@lucene.apache.org
>> For additional commands, e-mail: dev-help@lucene.apache.org
>
>---------------------------------------------------------------------
>To unsubscribe, e-mail: dev-unsubscribe@lucene.apache.org
>For additional commands, e-mail: dev-help@lucene.apache.org
--
Uwe Schindler
Achterdiek 19, 28357 Bremen
https://www.thetaphi.de
Re: [JENKINS] Lucene-Solr-NightlyTests-6.x - Build # 303 - Still Unstable
Posted by Robert Muir <rc...@gmail.com>.
On Wed, Mar 8, 2017 at 12:04 PM, Chris Hostetter
<ho...@fucit.org> wrote:
>
> : If you don't like the limit for your specific test: use
> : @SuppressFileSystems annotation to suppress it.
> :
> : But it is really insane for a unit test to use so many index files,
> : and it is important to reproduce such bugs when they do happen.
>
> i'm not disagreeing with the value of HandleLimitFS.
>
> I'm saying that in tests like TestIndexSorting.testRandom3 -- where the
> point is to create 2 distinct indexes and compare some things about them
> -- having a single limit for the entire JVM isn't as useful as if there
> was an easy way to just limit the number of open files per index (or for
> the test to declare "treat these indexes as if they were on distinct
> filesystems").
This isn't how operating systems work though. They don't care about
how many indexes or filesystems you have, its a file handle limit for
the process (entire JVM). So this simply reflects that.
2048 is already far too much: on my mac the default limit is only 256.
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@lucene.apache.org
For additional commands, e-mail: dev-help@lucene.apache.org
Re: [JENKINS] Lucene-Solr-NightlyTests-6.x - Build # 303 - Still
Unstable
Posted by Chris Hostetter <ho...@fucit.org>.
: If you don't like the limit for your specific test: use
: @SuppressFileSystems annotation to suppress it.
:
: But it is really insane for a unit test to use so many index files,
: and it is important to reproduce such bugs when they do happen.
i'm not disagreeing with the value of HandleLimitFS.
I'm saying that in tests like TestIndexSorting.testRandom3 -- where the
point is to create 2 distinct indexes and compare some things about them
-- having a single limit for the entire JVM isn't as useful as if there
was an easy way to just limit the number of open files per index (or for
the test to declare "treat these indexes as if they were on distinct
filesystems").
a knob/hook like this would also be useful in distributed Solr tests, to
say "we want this simulated solr nodeA to act as if it has it's own
filesystem independent from nodeB's filesystem" -- that way we can still
have the benefit of sanity checks that code isn't using too many files
(per *NODE*) and we wouldn't need to use a sledghammer of completely
supressing HandleLimitFS in tests.
Perhaps, in an ideal world, when tests call
LuceneTestCase.createTempDir(...) they could (optionally) pass in some
identifier for what (conceptual/virtual) filesystem they want to use -- so
they default is to assume all temp dirs created in a test come from the
same (mock) filesystem using HandleLimitFS with a (shared) max ... but
tests like TestIndexSorting.testRandom3 could request that the 2 distinct
indexes live ontheir own filesystems; and things like Solr's cloud test
scaffolding could request that each node get their own "virtual"
filesystems (with their own limits)
?
-Hoss
http://www.lucidworks.com/
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@lucene.apache.org
For additional commands, e-mail: dev-help@lucene.apache.org
Re: [JENKINS] Lucene-Solr-NightlyTests-6.x - Build # 303 - Still Unstable
Posted by Robert Muir <rc...@gmail.com>.
If you don't like the limit for your specific test: use
@SuppressFileSystems annotation to suppress it.
But it is really insane for a unit test to use so many index files,
and it is important to reproduce such bugs when they do happen.
On Wed, Mar 8, 2017 at 11:46 AM, Chris Hostetter
<ho...@fucit.org> wrote:
>
> The exception is being thrown by org.apache.lucene.mockfile.HandleLimitFS,
> so the OS level utlimit isn't relevant (as long as it's greter then 2048,
> hardcoded in TestRuleTemporaryFilesCleanup)
>
> With the test creating 2 diff indexes, that means each index index gets an
> effective max open files limit of ~1024 files ... and with
> RandomSimilarity it might be leaving a lot of small segments on "disk" for
> both of those indexes -- which will have at least 100,000 docs in each
> because this is a nightly run....
>
> I haven't tested this (my co is currently dirty and i'm in the middle of
> something) but i suspect the seed will reproduce anywhere.
>
> See also SOLR-10234 where i recently pointed out similar concerns about
> TestRuleTemporaryFilesCleanup's fixed limit of 2048 for the entire JVM,
> even when the JVM itself is trying to simulate multiple diff indexes (or
> completley distint nodes in the solr cloud test case).
>
>
>
> : Date: Wed, 8 Mar 2017 11:29:45 -0500
> : From: Steve Rowe <sa...@gmail.com>
> : Reply-To: dev@lucene.apache.org
> : To: dev@lucene.apache.org
> : Subject: Re: [JENKINS] Lucene-Solr-NightlyTests-6.x - Build # 303 - Still
> : Unstable
> :
> :
> : > On Mar 8, 2017, at 8:38 AM, Apache Jenkins Server <je...@builds.apache.org> wrote:
> : >
> : > Build: https://builds.apache.org/job/Lucene-Solr-NightlyTests-6.x/303/
> : >
> : > 2 tests failed.
> : > FAILED: org.apache.lucene.index.TestIndexSorting.testRandom3
> : >
> : > Error Message:
> : > /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/lucene/build/core/test/J2/temp/lucene.index.TestIndexSorting_4609011308FB57E6-001/tempDir-004/_e4_Lucene50_0.tim: Too many open files
> : >
> : > Stack Trace:
> : > java.nio.file.FileSystemException: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/lucene/build/core/test/J2/temp/lucene.index.TestIndexSorting_4609011308FB57E6-001/tempDir-004/_e4_Lucene50_0.tim: Too many open files
> :
> : I logged in as the jenkins user on lucene1-us-west.apache.org (the ‘lucene' jenkins slave), and ‘ulimit -aHS’ says (in part):
> :
> : open files (-n) 1048576
> :
> : I think this is the maximum value.
> :
> : Not sure what can be done here?
> :
> : --
> : Steve
> : www.lucidworks.com
> :
> :
> : ---------------------------------------------------------------------
> : To unsubscribe, e-mail: dev-unsubscribe@lucene.apache.org
> : For additional commands, e-mail: dev-help@lucene.apache.org
> :
> :
>
> -Hoss
> http://www.lucidworks.com/
>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: dev-unsubscribe@lucene.apache.org
> For additional commands, e-mail: dev-help@lucene.apache.org
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@lucene.apache.org
For additional commands, e-mail: dev-help@lucene.apache.org
Re: [JENKINS] Lucene-Solr-NightlyTests-6.x - Build # 303 - Still
Unstable
Posted by Chris Hostetter <ho...@fucit.org>.
The exception is being thrown by org.apache.lucene.mockfile.HandleLimitFS,
so the OS level utlimit isn't relevant (as long as it's greter then 2048,
hardcoded in TestRuleTemporaryFilesCleanup)
With the test creating 2 diff indexes, that means each index index gets an
effective max open files limit of ~1024 files ... and with
RandomSimilarity it might be leaving a lot of small segments on "disk" for
both of those indexes -- which will have at least 100,000 docs in each
because this is a nightly run....
I haven't tested this (my co is currently dirty and i'm in the middle of
something) but i suspect the seed will reproduce anywhere.
See also SOLR-10234 where i recently pointed out similar concerns about
TestRuleTemporaryFilesCleanup's fixed limit of 2048 for the entire JVM,
even when the JVM itself is trying to simulate multiple diff indexes (or
completley distint nodes in the solr cloud test case).
: Date: Wed, 8 Mar 2017 11:29:45 -0500
: From: Steve Rowe <sa...@gmail.com>
: Reply-To: dev@lucene.apache.org
: To: dev@lucene.apache.org
: Subject: Re: [JENKINS] Lucene-Solr-NightlyTests-6.x - Build # 303 - Still
: Unstable
:
:
: > On Mar 8, 2017, at 8:38 AM, Apache Jenkins Server <je...@builds.apache.org> wrote:
: >
: > Build: https://builds.apache.org/job/Lucene-Solr-NightlyTests-6.x/303/
: >
: > 2 tests failed.
: > FAILED: org.apache.lucene.index.TestIndexSorting.testRandom3
: >
: > Error Message:
: > /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/lucene/build/core/test/J2/temp/lucene.index.TestIndexSorting_4609011308FB57E6-001/tempDir-004/_e4_Lucene50_0.tim: Too many open files
: >
: > Stack Trace:
: > java.nio.file.FileSystemException: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/lucene/build/core/test/J2/temp/lucene.index.TestIndexSorting_4609011308FB57E6-001/tempDir-004/_e4_Lucene50_0.tim: Too many open files
:
: I logged in as the jenkins user on lucene1-us-west.apache.org (the lucene' jenkins slave), and ulimit -aHS says (in part):
:
: open files (-n) 1048576
:
: I think this is the maximum value.
:
: Not sure what can be done here?
:
: --
: Steve
: www.lucidworks.com
:
:
: ---------------------------------------------------------------------
: To unsubscribe, e-mail: dev-unsubscribe@lucene.apache.org
: For additional commands, e-mail: dev-help@lucene.apache.org
:
:
-Hoss
http://www.lucidworks.com/
Re: [JENKINS] Lucene-Solr-NightlyTests-6.x - Build # 303 - Still Unstable
Posted by Robert Muir <rc...@gmail.com>.
The exception is not from the operating system: it is from the test framework.
https://github.com/apache/lucene-solr/blob/master/lucene/test-framework/src/java/org/apache/lucene/mockfile/HandleLimitFS.java#L48
This is currently limited to 2048. We should not increase it: the idea
is to catch buggy/crazy tests just like this one.
https://github.com/apache/lucene-solr/blob/master/lucene/test-framework/src/java/org/apache/lucene/util/TestRuleTemporaryFilesCleanup.java#L117-L119
On Wed, Mar 8, 2017 at 11:29 AM, Steve Rowe <sa...@gmail.com> wrote:
>
>> On Mar 8, 2017, at 8:38 AM, Apache Jenkins Server <je...@builds.apache.org> wrote:
>>
>> Build: https://builds.apache.org/job/Lucene-Solr-NightlyTests-6.x/303/
>>
>> 2 tests failed.
>> FAILED: org.apache.lucene.index.TestIndexSorting.testRandom3
>>
>> Error Message:
>> /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/lucene/build/core/test/J2/temp/lucene.index.TestIndexSorting_4609011308FB57E6-001/tempDir-004/_e4_Lucene50_0.tim: Too many open files
>>
>> Stack Trace:
>> java.nio.file.FileSystemException: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/lucene/build/core/test/J2/temp/lucene.index.TestIndexSorting_4609011308FB57E6-001/tempDir-004/_e4_Lucene50_0.tim: Too many open files
>
> I logged in as the jenkins user on lucene1-us-west.apache.org (the ‘lucene' jenkins slave), and ‘ulimit -aHS’ says (in part):
>
> open files (-n) 1048576
>
> I think this is the maximum value.
>
> Not sure what can be done here?
>
> --
> Steve
> www.lucidworks.com
>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: dev-unsubscribe@lucene.apache.org
> For additional commands, e-mail: dev-help@lucene.apache.org
>
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@lucene.apache.org
For additional commands, e-mail: dev-help@lucene.apache.org
Re: [JENKINS] Lucene-Solr-NightlyTests-6.x - Build # 303 - Still
Unstable
Posted by Steve Rowe <sa...@gmail.com>.
> On Mar 8, 2017, at 8:38 AM, Apache Jenkins Server <je...@builds.apache.org> wrote:
>
> Build: https://builds.apache.org/job/Lucene-Solr-NightlyTests-6.x/303/
>
> 2 tests failed.
> FAILED: org.apache.lucene.index.TestIndexSorting.testRandom3
>
> Error Message:
> /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/lucene/build/core/test/J2/temp/lucene.index.TestIndexSorting_4609011308FB57E6-001/tempDir-004/_e4_Lucene50_0.tim: Too many open files
>
> Stack Trace:
> java.nio.file.FileSystemException: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/lucene/build/core/test/J2/temp/lucene.index.TestIndexSorting_4609011308FB57E6-001/tempDir-004/_e4_Lucene50_0.tim: Too many open files
I logged in as the jenkins user on lucene1-us-west.apache.org (the ‘lucene' jenkins slave), and ‘ulimit -aHS’ says (in part):
open files (-n) 1048576
I think this is the maximum value.
Not sure what can be done here?
--
Steve
www.lucidworks.com
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@lucene.apache.org
For additional commands, e-mail: dev-help@lucene.apache.org
[JENKINS] Lucene-Solr-NightlyTests-6.x - Build # 303 - Still
Unstable
Posted by Apache Jenkins Server <je...@builds.apache.org>.
Build: https://builds.apache.org/job/Lucene-Solr-NightlyTests-6.x/303/
2 tests failed.
FAILED: org.apache.lucene.index.TestIndexSorting.testRandom3
Error Message:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/lucene/build/core/test/J2/temp/lucene.index.TestIndexSorting_4609011308FB57E6-001/tempDir-004/_e4_Lucene50_0.tim: Too many open files
Stack Trace:
java.nio.file.FileSystemException: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/lucene/build/core/test/J2/temp/lucene.index.TestIndexSorting_4609011308FB57E6-001/tempDir-004/_e4_Lucene50_0.tim: Too many open files
at __randomizedtesting.SeedInfo.seed([4609011308FB57E6:E4D14FC96C097EE0]:0)
at org.apache.lucene.mockfile.HandleLimitFS.onOpen(HandleLimitFS.java:48)
at org.apache.lucene.mockfile.HandleTrackingFS.callOpenHook(HandleTrackingFS.java:81)
at org.apache.lucene.mockfile.HandleTrackingFS.newFileChannel(HandleTrackingFS.java:197)
at org.apache.lucene.mockfile.HandleTrackingFS.newFileChannel(HandleTrackingFS.java:166)
at org.apache.lucene.mockfile.FilterFileSystemProvider.newFileChannel(FilterFileSystemProvider.java:202)
at java.nio.channels.FileChannel.open(FileChannel.java:287)
at java.nio.channels.FileChannel.open(FileChannel.java:335)
at org.apache.lucene.store.NIOFSDirectory.openInput(NIOFSDirectory.java:81)
at org.apache.lucene.util.LuceneTestCase.slowFileExists(LuceneTestCase.java:2741)
at org.apache.lucene.store.MockDirectoryWrapper.openInput(MockDirectoryWrapper.java:749)
at org.apache.lucene.codecs.blocktree.BlockTreeTermsReader.<init>(BlockTreeTermsReader.java:153)
at org.apache.lucene.codecs.lucene50.Lucene50PostingsFormat.fieldsProducer(Lucene50PostingsFormat.java:445)
at org.apache.lucene.codecs.perfield.PerFieldPostingsFormat$FieldsReader.<init>(PerFieldPostingsFormat.java:292)
at org.apache.lucene.codecs.perfield.PerFieldPostingsFormat.fieldsProducer(PerFieldPostingsFormat.java:372)
at org.apache.lucene.index.SegmentCoreReaders.<init>(SegmentCoreReaders.java:112)
at org.apache.lucene.index.SegmentReader.<init>(SegmentReader.java:74)
at org.apache.lucene.index.ReadersAndUpdates.getReader(ReadersAndUpdates.java:145)
at org.apache.lucene.index.BufferedUpdatesStream$SegmentState.<init>(BufferedUpdatesStream.java:384)
at org.apache.lucene.index.BufferedUpdatesStream.openSegmentStates(BufferedUpdatesStream.java:416)
at org.apache.lucene.index.BufferedUpdatesStream.applyDeletesAndUpdates(BufferedUpdatesStream.java:261)
at org.apache.lucene.index.IndexWriter.applyAllDeletesAndUpdates(IndexWriter.java:3464)
at org.apache.lucene.index.IndexWriter.applyDeletesAndPurge(IndexWriter.java:4992)
at org.apache.lucene.index.DocumentsWriter$ApplyDeletesEvent.process(DocumentsWriter.java:717)
at org.apache.lucene.index.IndexWriter.processEvents(IndexWriter.java:5042)
at org.apache.lucene.index.IndexWriter.processEvents(IndexWriter.java:5033)
at org.apache.lucene.index.IndexWriter.deleteDocuments(IndexWriter.java:1509)
at org.apache.lucene.index.TestIndexSorting.testRandom3(TestIndexSorting.java:2237)
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:1713)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:907)
at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:943)
at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:957)
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:916)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:802)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:852)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
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:745)
FAILED: org.apache.solr.handler.TestReplicationHandler.doTestReplicateAfterCoreReload
Error Message:
expected:<[{indexVersion=1488977341443,generation=2,filelist=[_1hx.cfe, _1hx.cfs, _1hx.si, _1hz.cfe, _1hz.cfs, _1hz.si, _1i0.cfe, _1i0.cfs, _1i0.si, _1i1.cfe, _1i1.cfs, _1i1.si, _1i2.cfe, _1i2.cfs, _1i2.si, _1i3.cfe, _1i3.cfs, _1i3.si, _1i4.cfe, _1i4.cfs, _1i4.si, _1i5.cfe, _1i5.cfs, _1i5.si, _1i6.cfe, _1i6.cfs, _1i6.si, _1i7.cfe, _1i7.cfs, _1i7.si, _1i8.cfe, _1i8.cfs, _1i8.si, _1i9.cfe, _1i9.cfs, _1i9.si, _1ia.cfe, _1ia.cfs, _1ia.si, _1ib.cfe, _1ib.cfs, _1ib.si, _1ic.cfe, _1ic.cfs, _1ic.si, _1id.cfe, _1id.cfs, _1id.si, _1ie.cfe, _1ie.cfs, _1ie.si, _1if.cfe, _1if.cfs, _1if.si, _1ig.cfe, _1ig.cfs, _1ig.si, _1ih.cfe, _1ih.cfs, _1ih.si, _1ii.cfe, _1ii.cfs, _1ii.si, _1ij.cfe, _1ij.cfs, _1ij.si, _1ik.cfe, _1ik.cfs, _1ik.si, segments_2]}]> but was:<[{indexVersion=1488977341443,generation=2,filelist=[_1hx.cfe, _1hx.cfs, _1hx.si, _1hz.cfe, _1hz.cfs, _1hz.si, _1i0.cfe, _1i0.cfs, _1i0.si, _1i1.cfe, _1i1.cfs, _1i1.si, _1i2.cfe, _1i2.cfs, _1i2.si, _1i3.cfe, _1i3.cfs, _1i3.si, _1i4.cfe, _1i4.cfs, _1i4.si, _1i5.cfe, _1i5.cfs, _1i5.si, _1i6.cfe, _1i6.cfs, _1i6.si, _1i7.cfe, _1i7.cfs, _1i7.si, _1i8.cfe, _1i8.cfs, _1i8.si, _1i9.cfe, _1i9.cfs, _1i9.si, _1ia.cfe, _1ia.cfs, _1ia.si, _1ib.cfe, _1ib.cfs, _1ib.si, _1ic.cfe, _1ic.cfs, _1ic.si, _1id.cfe, _1id.cfs, _1id.si, _1ie.cfe, _1ie.cfs, _1ie.si, _1if.cfe, _1if.cfs, _1if.si, _1ig.cfe, _1ig.cfs, _1ig.si, _1ih.cfe, _1ih.cfs, _1ih.si, _1ii.cfe, _1ii.cfs, _1ii.si, _1ij.cfe, _1ij.cfs, _1ij.si, _1ik.cfe, _1ik.cfs, _1ik.si, segments_2]}, {indexVersion=1488977341443,generation=3,filelist=[_1hz.cfe, _1hz.cfs, _1hz.si, _1i0.cfe, _1i0.cfs, _1i0.si, _1i3.cfe, _1i3.cfs, _1i3.si, _1i5.cfe, _1i5.cfs, _1i5.si, _1i7.cfe, _1i7.cfs, _1i7.si, _1i8.cfe, _1i8.cfs, _1i8.si, _1ib.cfe, _1ib.cfs, _1ib.si, _1ic.cfe, _1ic.cfs, _1ic.si, _1ie.cfe, _1ie.cfs, _1ie.si, _1ig.cfe, _1ig.cfs, _1ig.si, _1ih.cfe, _1ih.cfs, _1ih.si, _1ii.cfe, _1ii.cfs, _1ii.si, _1il.cfe, _1il.cfs, _1il.si, segments_3]}]>
Stack Trace:
java.lang.AssertionError: expected:<[{indexVersion=1488977341443,generation=2,filelist=[_1hx.cfe, _1hx.cfs, _1hx.si, _1hz.cfe, _1hz.cfs, _1hz.si, _1i0.cfe, _1i0.cfs, _1i0.si, _1i1.cfe, _1i1.cfs, _1i1.si, _1i2.cfe, _1i2.cfs, _1i2.si, _1i3.cfe, _1i3.cfs, _1i3.si, _1i4.cfe, _1i4.cfs, _1i4.si, _1i5.cfe, _1i5.cfs, _1i5.si, _1i6.cfe, _1i6.cfs, _1i6.si, _1i7.cfe, _1i7.cfs, _1i7.si, _1i8.cfe, _1i8.cfs, _1i8.si, _1i9.cfe, _1i9.cfs, _1i9.si, _1ia.cfe, _1ia.cfs, _1ia.si, _1ib.cfe, _1ib.cfs, _1ib.si, _1ic.cfe, _1ic.cfs, _1ic.si, _1id.cfe, _1id.cfs, _1id.si, _1ie.cfe, _1ie.cfs, _1ie.si, _1if.cfe, _1if.cfs, _1if.si, _1ig.cfe, _1ig.cfs, _1ig.si, _1ih.cfe, _1ih.cfs, _1ih.si, _1ii.cfe, _1ii.cfs, _1ii.si, _1ij.cfe, _1ij.cfs, _1ij.si, _1ik.cfe, _1ik.cfs, _1ik.si, segments_2]}]> but was:<[{indexVersion=1488977341443,generation=2,filelist=[_1hx.cfe, _1hx.cfs, _1hx.si, _1hz.cfe, _1hz.cfs, _1hz.si, _1i0.cfe, _1i0.cfs, _1i0.si, _1i1.cfe, _1i1.cfs, _1i1.si, _1i2.cfe, _1i2.cfs, _1i2.si, _1i3.cfe, _1i3.cfs, _1i3.si, _1i4.cfe, _1i4.cfs, _1i4.si, _1i5.cfe, _1i5.cfs, _1i5.si, _1i6.cfe, _1i6.cfs, _1i6.si, _1i7.cfe, _1i7.cfs, _1i7.si, _1i8.cfe, _1i8.cfs, _1i8.si, _1i9.cfe, _1i9.cfs, _1i9.si, _1ia.cfe, _1ia.cfs, _1ia.si, _1ib.cfe, _1ib.cfs, _1ib.si, _1ic.cfe, _1ic.cfs, _1ic.si, _1id.cfe, _1id.cfs, _1id.si, _1ie.cfe, _1ie.cfs, _1ie.si, _1if.cfe, _1if.cfs, _1if.si, _1ig.cfe, _1ig.cfs, _1ig.si, _1ih.cfe, _1ih.cfs, _1ih.si, _1ii.cfe, _1ii.cfs, _1ii.si, _1ij.cfe, _1ij.cfs, _1ij.si, _1ik.cfe, _1ik.cfs, _1ik.si, segments_2]}, {indexVersion=1488977341443,generation=3,filelist=[_1hz.cfe, _1hz.cfs, _1hz.si, _1i0.cfe, _1i0.cfs, _1i0.si, _1i3.cfe, _1i3.cfs, _1i3.si, _1i5.cfe, _1i5.cfs, _1i5.si, _1i7.cfe, _1i7.cfs, _1i7.si, _1i8.cfe, _1i8.cfs, _1i8.si, _1ib.cfe, _1ib.cfs, _1ib.si, _1ic.cfe, _1ic.cfs, _1ic.si, _1ie.cfe, _1ie.cfs, _1ie.si, _1ig.cfe, _1ig.cfs, _1ig.si, _1ih.cfe, _1ih.cfs, _1ih.si, _1ii.cfe, _1ii.cfs, _1ii.si, _1il.cfe, _1il.cfs, _1il.si, segments_3]}]>
at __randomizedtesting.SeedInfo.seed([829C4BD9B8CDAE69:A74B50E9C885A06A]: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:147)
at org.apache.solr.handler.TestReplicationHandler.doTestReplicateAfterCoreReload(TestReplicationHandler.java:1281)
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:1713)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:907)
at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:943)
at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:957)
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:916)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:802)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:852)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
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:745)
Build Log:
[...truncated 277 lines...]
[junit4] Suite: org.apache.lucene.index.TestIndexSorting
[junit4] 2> NOTE: download the large Jenkins line-docs file by running 'ant get-jenkins-line-docs' in the lucene directory.
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=TestIndexSorting -Dtests.method=testRandom3 -Dtests.seed=4609011308FB57E6 -Dtests.multiplier=2 -Dtests.nightly=true -Dtests.slow=true -Dtests.linedocsfile=/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/test-data/enwiki.random.lines.txt -Dtests.locale=es-MX -Dtests.timezone=America/El_Salvador -Dtests.asserts=true -Dtests.file.encoding=US-ASCII
[junit4] ERROR 105s J2 | TestIndexSorting.testRandom3 <<<
[junit4] > Throwable #1: java.nio.file.FileSystemException: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/lucene/build/core/test/J2/temp/lucene.index.TestIndexSorting_4609011308FB57E6-001/tempDir-004/_e4_Lucene50_0.tim: Too many open files
[junit4] > at __randomizedtesting.SeedInfo.seed([4609011308FB57E6:E4D14FC96C097EE0]:0)
[junit4] > at org.apache.lucene.mockfile.HandleLimitFS.onOpen(HandleLimitFS.java:48)
[junit4] > at org.apache.lucene.mockfile.HandleTrackingFS.callOpenHook(HandleTrackingFS.java:81)
[junit4] > at org.apache.lucene.mockfile.HandleTrackingFS.newFileChannel(HandleTrackingFS.java:197)
[junit4] > at org.apache.lucene.mockfile.HandleTrackingFS.newFileChannel(HandleTrackingFS.java:166)
[junit4] > at org.apache.lucene.mockfile.FilterFileSystemProvider.newFileChannel(FilterFileSystemProvider.java:202)
[junit4] > at java.nio.channels.FileChannel.open(FileChannel.java:287)
[junit4] > at java.nio.channels.FileChannel.open(FileChannel.java:335)
[junit4] > at org.apache.lucene.store.NIOFSDirectory.openInput(NIOFSDirectory.java:81)
[junit4] > at org.apache.lucene.util.LuceneTestCase.slowFileExists(LuceneTestCase.java:2741)
[junit4] > at org.apache.lucene.store.MockDirectoryWrapper.openInput(MockDirectoryWrapper.java:749)
[junit4] > at org.apache.lucene.codecs.blocktree.BlockTreeTermsReader.<init>(BlockTreeTermsReader.java:153)
[junit4] > at org.apache.lucene.codecs.lucene50.Lucene50PostingsFormat.fieldsProducer(Lucene50PostingsFormat.java:445)
[junit4] > at org.apache.lucene.codecs.perfield.PerFieldPostingsFormat$FieldsReader.<init>(PerFieldPostingsFormat.java:292)
[junit4] > at org.apache.lucene.codecs.perfield.PerFieldPostingsFormat.fieldsProducer(PerFieldPostingsFormat.java:372)
[junit4] > at org.apache.lucene.index.SegmentCoreReaders.<init>(SegmentCoreReaders.java:112)
[junit4] > at org.apache.lucene.index.SegmentReader.<init>(SegmentReader.java:74)
[junit4] > at org.apache.lucene.index.ReadersAndUpdates.getReader(ReadersAndUpdates.java:145)
[junit4] > at org.apache.lucene.index.BufferedUpdatesStream$SegmentState.<init>(BufferedUpdatesStream.java:384)
[junit4] > at org.apache.lucene.index.BufferedUpdatesStream.openSegmentStates(BufferedUpdatesStream.java:416)
[junit4] > at org.apache.lucene.index.BufferedUpdatesStream.applyDeletesAndUpdates(BufferedUpdatesStream.java:261)
[junit4] > at org.apache.lucene.index.IndexWriter.applyAllDeletesAndUpdates(IndexWriter.java:3464)
[junit4] > at org.apache.lucene.index.IndexWriter.applyDeletesAndPurge(IndexWriter.java:4992)
[junit4] > at org.apache.lucene.index.DocumentsWriter$ApplyDeletesEvent.process(DocumentsWriter.java:717)
[junit4] > at org.apache.lucene.index.IndexWriter.processEvents(IndexWriter.java:5042)
[junit4] > at org.apache.lucene.index.IndexWriter.processEvents(IndexWriter.java:5033)
[junit4] > at org.apache.lucene.index.IndexWriter.deleteDocuments(IndexWriter.java:1509)
[junit4] > at org.apache.lucene.index.TestIndexSorting.testRandom3(TestIndexSorting.java:2237)
[junit4] > at java.lang.Thread.run(Thread.java:745)
[junit4] 2> NOTE: leaving temporary files on disk at: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/lucene/build/core/test/J2/temp/lucene.index.TestIndexSorting_4609011308FB57E6-001
[junit4] 2> NOTE: test params are: codec=Lucene62, sim=RandomSimilarity(queryNorm=true,coord=crazy): {positions=DFR I(n)B2, id=DFR I(F)2, term_vectors=DFR GB1}, locale=es-MX, timezone=America/El_Salvador
[junit4] 2> NOTE: Linux 3.13.0-85-generic amd64/Oracle Corporation 1.8.0_121 (64-bit)/cpus=4,threads=1,free=41132400,total=462946304
[junit4] 2> NOTE: All tests run in this JVM: [TestPackedTokenAttributeImpl, TestIndexSorting]
[junit4] Completed [20/452 (1!)] on J2 in 164.56s, 48 tests, 1 error <<< FAILURES!
[...truncated 12699 lines...]
[junit4] Suite: org.apache.solr.handler.TestReplicationHandler
[junit4] 2> Creating dataDir: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J2/temp/solr.handler.TestReplicationHandler_829C4BD9B8CDAE69-001/init-core-data-001
[junit4] 2> 1913996 INFO (SUITE-TestReplicationHandler-seed#[829C4BD9B8CDAE69]-worker) [ ] o.a.s.SolrTestCaseJ4 Using TrieFields
[junit4] 2> 1913998 INFO (SUITE-TestReplicationHandler-seed#[829C4BD9B8CDAE69]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false) via: @org.apache.solr.SolrTestCaseJ4$SuppressSSL(bugUrl=None)
[junit4] 2> 1913999 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartupWithNoActivity-seed#[829C4BD9B8CDAE69]) [ ] o.a.s.SolrTestCaseJ4 ###Starting doTestReplicateAfterStartupWithNoActivity
[junit4] 2> 1913999 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartupWithNoActivity-seed#[829C4BD9B8CDAE69]) [ ] o.a.s.SolrTestCaseJ4 Writing core.properties file to /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J2/temp/solr.handler.TestReplicationHandler_829C4BD9B8CDAE69-001/solr-instance-001/collection1
[junit4] 2> 1914002 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartupWithNoActivity-seed#[829C4BD9B8CDAE69]) [ ] o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 1914003 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartupWithNoActivity-seed#[829C4BD9B8CDAE69]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@50dc0934{/solr,null,AVAILABLE}
[junit4] 2> 1914004 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartupWithNoActivity-seed#[829C4BD9B8CDAE69]) [ ] o.e.j.s.AbstractConnector Started ServerConnector@4f3f5a93{HTTP/1.1,[http/1.1]}{127.0.0.1:45220}
[junit4] 2> 1914005 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartupWithNoActivity-seed#[829C4BD9B8CDAE69]) [ ] o.e.j.s.Server Started @1916709ms
[junit4] 2> 1914005 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartupWithNoActivity-seed#[829C4BD9B8CDAE69]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {solr.data.dir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J2/temp/solr.handler.TestReplicationHandler_829C4BD9B8CDAE69-001/solr-instance-001/collection1/data, hostContext=/solr, hostPort=45220}
[junit4] 2> 1914005 ERROR (TEST-TestReplicationHandler.doTestReplicateAfterStartupWithNoActivity-seed#[829C4BD9B8CDAE69]) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 1914005 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartupWithNoActivity-seed#[829C4BD9B8CDAE69]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 6.5.0
[junit4] 2> 1914005 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartupWithNoActivity-seed#[829C4BD9B8CDAE69]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in standalone mode on port null
[junit4] 2> 1914005 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartupWithNoActivity-seed#[829C4BD9B8CDAE69]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 1914005 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartupWithNoActivity-seed#[829C4BD9B8CDAE69]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-03-08T12:38:22.244Z
[junit4] 2> 1914005 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartupWithNoActivity-seed#[829C4BD9B8CDAE69]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J2/temp/solr.handler.TestReplicationHandler_829C4BD9B8CDAE69-001/solr-instance-001/solr.xml
[junit4] 2> 1914010 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartupWithNoActivity-seed#[829C4BD9B8CDAE69]) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 1914028 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartupWithNoActivity-seed#[829C4BD9B8CDAE69]) [ ] o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J2/temp/solr.handler.TestReplicationHandler_829C4BD9B8CDAE69-001/solr-instance-001/.
[junit4] 2> 1914028 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartupWithNoActivity-seed#[829C4BD9B8CDAE69]) [ ] o.a.s.c.CorePropertiesLocator Cores are: [collection1]
[junit4] 2> 1914036 INFO (coreLoadExecutor-5980-thread-1) [ x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.5.0
[junit4] 2> 1914041 INFO (coreLoadExecutor-5980-thread-1) [ x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=test
[junit4] 2> 1914043 INFO (coreLoadExecutor-5980-thread-1) [ x:collection1] o.a.s.s.IndexSchema Loaded schema test/1.2 with uniqueid field id
[junit4] 2> 1914044 INFO (coreLoadExecutor-5980-thread-1) [ x:collection1] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from instancedir /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J2/temp/solr.handler.TestReplicationHandler_829C4BD9B8CDAE69-001/solr-instance-001/./collection1
[junit4] 2> 1914044 INFO (coreLoadExecutor-5980-thread-1) [ x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J2/temp/solr.handler.TestReplicationHandler_829C4BD9B8CDAE69-001/solr-instance-001/collection1], dataDir=[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J2/temp/solr.handler.TestReplicationHandler_829C4BD9B8CDAE69-001/solr-instance-001/./collection1/data/]
[junit4] 2> 1914045 INFO (coreLoadExecutor-5980-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.MockRandomMergePolicy: org.apache.lucene.index.MockRandomMergePolicy@33d8b92a
[junit4] 2> 1914097 INFO (coreLoadExecutor-5980-thread-1) [ x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 1914097 INFO (coreLoadExecutor-5980-thread-1) [ x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 1914097 INFO (coreLoadExecutor-5980-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.MockRandomMergePolicy: org.apache.lucene.index.MockRandomMergePolicy@5de32b1b
[junit4] 2> 1914098 INFO (coreLoadExecutor-5980-thread-1) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@c03f260[collection1] main]
[junit4] 2> 1914098 INFO (coreLoadExecutor-5980-thread-1) [ x:collection1] o.a.s.r.ManagedResourceStorage File-based storage initialized to use dir: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J2/temp/solr.handler.TestReplicationHandler_829C4BD9B8CDAE69-001/solr-instance-001/collection1/conf
[junit4] 2> 1914098 INFO (coreLoadExecutor-5980-thread-1) [ x:collection1] o.a.s.h.ReplicationHandler Replication enabled for following config files: schema.xml,xslt/dummy.xsl
[junit4] 2> 1914098 INFO (coreLoadExecutor-5980-thread-1) [ x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 1914099 INFO (searcherExecutor-5981-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@c03f260[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 1914620 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartupWithNoActivity-seed#[829C4BD9B8CDAE69]) [ ] o.a.s.SolrTestCaseJ4 Writing core.properties file to /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J2/temp/solr.handler.TestReplicationHandler_829C4BD9B8CDAE69-001/solr-instance-002/collection1
[junit4] 2> 1914622 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartupWithNoActivity-seed#[829C4BD9B8CDAE69]) [ ] o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 1914623 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartupWithNoActivity-seed#[829C4BD9B8CDAE69]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@43362856{/solr,null,AVAILABLE}
[junit4] 2> 1914623 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartupWithNoActivity-seed#[829C4BD9B8CDAE69]) [ ] o.e.j.s.AbstractConnector Started ServerConnector@1cf3e1f9{HTTP/1.1,[http/1.1]}{127.0.0.1:51656}
[junit4] 2> 1914623 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartupWithNoActivity-seed#[829C4BD9B8CDAE69]) [ ] o.e.j.s.Server Started @1917328ms
[junit4] 2> 1914623 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartupWithNoActivity-seed#[829C4BD9B8CDAE69]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {solr.data.dir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J2/temp/solr.handler.TestReplicationHandler_829C4BD9B8CDAE69-001/solr-instance-002/collection1/data, hostContext=/solr, hostPort=51656}
[junit4] 2> 1914624 ERROR (TEST-TestReplicationHandler.doTestReplicateAfterStartupWithNoActivity-seed#[829C4BD9B8CDAE69]) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 1914624 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartupWithNoActivity-seed#[829C4BD9B8CDAE69]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 6.5.0
[junit4] 2> 1914624 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartupWithNoActivity-seed#[829C4BD9B8CDAE69]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in standalone mode on port null
[junit4] 2> 1914624 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartupWithNoActivity-seed#[829C4BD9B8CDAE69]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 1914624 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartupWithNoActivity-seed#[829C4BD9B8CDAE69]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-03-08T12:38:22.863Z
[junit4] 2> 1914624 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartupWithNoActivity-seed#[829C4BD9B8CDAE69]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J2/temp/solr.handler.TestReplicationHandler_829C4BD9B8CDAE69-001/solr-instance-002/solr.xml
[junit4] 2> 1914629 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartupWithNoActivity-seed#[829C4BD9B8CDAE69]) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 1914646 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartupWithNoActivity-seed#[829C4BD9B8CDAE69]) [ ] o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J2/temp/solr.handler.TestReplicationHandler_829C4BD9B8CDAE69-001/solr-instance-002/.
[junit4] 2> 1914646 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartupWithNoActivity-seed#[829C4BD9B8CDAE69]) [ ] o.a.s.c.CorePropertiesLocator Cores are: [collection1]
[junit4] 2> 1914653 INFO (coreLoadExecutor-5990-thread-1) [ x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.5.0
[junit4] 2> 1914659 INFO (coreLoadExecutor-5990-thread-1) [ x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=test
[junit4] 2> 1914660 INFO (coreLoadExecutor-5990-thread-1) [ x:collection1] o.a.s.s.IndexSchema Loaded schema test/1.2 with uniqueid field id
[junit4] 2> 1914661 INFO (coreLoadExecutor-5990-thread-1) [ x:collection1] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from instancedir /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J2/temp/solr.handler.TestReplicationHandler_829C4BD9B8CDAE69-001/solr-instance-002/./collection1
[junit4] 2> 1914662 INFO (coreLoadExecutor-5990-thread-1) [ x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J2/temp/solr.handler.TestReplicationHandler_829C4BD9B8CDAE69-001/solr-instance-002/collection1], dataDir=[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J2/temp/solr.handler.TestReplicationHandler_829C4BD9B8CDAE69-001/solr-instance-002/./collection1/data/]
[junit4] 2> 1914662 INFO (coreLoadExecutor-5990-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.MockRandomMergePolicy: org.apache.lucene.index.MockRandomMergePolicy@520880e8
[junit4] 2> 1914688 INFO (coreLoadExecutor-5990-thread-1) [ x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 1914688 INFO (coreLoadExecutor-5990-thread-1) [ x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 1914688 INFO (coreLoadExecutor-5990-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.MockRandomMergePolicy: org.apache.lucene.index.MockRandomMergePolicy@43ddd5a9
[junit4] 2> 1914689 INFO (coreLoadExecutor-5990-thread-1) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@7a267329[collection1] main]
[junit4] 2> 1914689 INFO (coreLoadExecutor-5990-thread-1) [ x:collection1] o.a.s.r.ManagedResourceStorage File-based storage initialized to use dir: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J2/temp/solr.handler.TestReplicationHandler_829C4BD9B8CDAE69-001/solr-instance-002/collection1/conf
[junit4] 2> 1914691 INFO (coreLoadExecutor-5990-thread-1) [ x:collection1] o.a.s.h.ReplicationHandler Poll scheduled at an interval of 1000ms
[junit4] 2> 1914691 INFO (searcherExecutor-5991-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@7a267329[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 1914845 INFO (qtp58319730-17378) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={qt=/replication&wt=javabin&version=2&command=indexversion} status=0 QTime=0
[junit4] 2> 1914845 INFO (indexFetcher-5995-thread-1) [ x:collection1] o.a.s.h.IndexFetcher Master's generation: 1
[junit4] 2> 1914845 INFO (indexFetcher-5995-thread-1) [ x:collection1] o.a.s.h.IndexFetcher Master's version: 0
[junit4] 2> 1914846 INFO (indexFetcher-5995-thread-1) [ x:collection1] o.a.s.h.IndexFetcher Slave's generation: 1
[junit4] 2> 1914846 INFO (indexFetcher-5995-thread-1) [ x:collection1] o.a.s.h.IndexFetcher Slave's version: 0
[junit4] 2> 1915167 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartupWithNoActivity-seed#[829C4BD9B8CDAE69]) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@1cf3e1f9{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
[junit4] 2> 1915167 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartupWithNoActivity-seed#[829C4BD9B8CDAE69]) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=1451848266
[junit4] 2> 1915167 INFO (coreCloseExecutor-5996-thread-1) [ x:collection1] o.a.s.c.SolrCore [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@5529075e
[junit4] 2> 1915169 INFO (coreCloseExecutor-5996-thread-1) [ x:collection1] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.collection1
[junit4] 2> 1915170 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartupWithNoActivity-seed#[829C4BD9B8CDAE69]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.node
[junit4] 2> 1915170 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartupWithNoActivity-seed#[829C4BD9B8CDAE69]) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@43362856{/solr,null,UNAVAILABLE}
[junit4] 2> 1915171 INFO (qtp58319730-17382) [ x:collection1] o.a.s.u.DirectUpdateHandler2 [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4] 2> 1915171 INFO (qtp58319730-17382) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{deleteByQuery=*:*} 0 0
[junit4] 2> 1915173 INFO (qtp58319730-17375) [ x:collection1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 1915173 INFO (qtp58319730-17375) [ x:collection1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@5a54662b
[junit4] 2> 1915174 INFO (qtp58319730-17375) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@25295475[collection1] main]
[junit4] 2> 1915174 INFO (qtp58319730-17375) [ x:collection1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 1915174 INFO (searcherExecutor-5981-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@25295475[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 1915174 INFO (qtp58319730-17375) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=} 0 1
[junit4] 2> 1915175 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartupWithNoActivity-seed#[829C4BD9B8CDAE69]) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@4f3f5a93{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
[junit4] 2> 1915175 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartupWithNoActivity-seed#[829C4BD9B8CDAE69]) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=22544708
[junit4] 2> 1915176 INFO (coreCloseExecutor-5998-thread-1) [ x:collection1] o.a.s.c.SolrCore [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@7389003
[junit4] 2> 1915177 INFO (coreCloseExecutor-5998-thread-1) [ x:collection1] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.collection1
[junit4] 2> 1915177 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartupWithNoActivity-seed#[829C4BD9B8CDAE69]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.node
[junit4] 2> 1915177 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartupWithNoActivity-seed#[829C4BD9B8CDAE69]) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@50dc0934{/solr,null,UNAVAILABLE}
[junit4] 2> 1915178 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartupWithNoActivity-seed#[829C4BD9B8CDAE69]) [ ] o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 1915179 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartupWithNoActivity-seed#[829C4BD9B8CDAE69]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@208073ba{/solr,null,AVAILABLE}
[junit4] 2> 1915179 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartupWithNoActivity-seed#[829C4BD9B8CDAE69]) [ ] o.e.j.s.AbstractConnector Started ServerConnector@545cd856{HTTP/1.1,[http/1.1]}{127.0.0.1:35478}
[junit4] 2> 1915179 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartupWithNoActivity-seed#[829C4BD9B8CDAE69]) [ ] o.e.j.s.Server Started @1917884ms
[junit4] 2> 1915179 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartupWithNoActivity-seed#[829C4BD9B8CDAE69]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {solr.data.dir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J2/temp/solr.handler.TestReplicationHandler_829C4BD9B8CDAE69-001/solr-instance-001/collection1/data, hostContext=/solr, hostPort=35478}
[junit4] 2> 1915180 ERROR (TEST-TestReplicationHandler.doTestReplicateAfterStartupWithNoActivity-seed#[829C4BD9B8CDAE69]) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 1915180 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartupWithNoActivity-seed#[829C4BD9B8CDAE69]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 6.5.0
[junit4] 2> 1915180 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartupWithNoActivity-seed#[829C4BD9B8CDAE69]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in standalone mode on port null
[junit4] 2> 1915180 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartupWithNoActivity-seed#[829C4BD9B8CDAE69]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 1915180 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartupWithNoActivity-seed#[829C4BD9B8CDAE69]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-03-08T12:38:23.419Z
[junit4] 2> 1915180 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartupWithNoActivity-seed#[829C4BD9B8CDAE69]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J2/temp/solr.handler.TestReplicationHandler_829C4BD9B8CDAE69-001/solr-instance-001/solr.xml
[junit4] 2> 1915185 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartupWithNoActivity-seed#[829C4BD9B8CDAE69]) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 1915212 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartupWithNoActivity-seed#[829C4BD9B8CDAE69]) [ ] o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J2/temp/solr.handler.TestReplicationHandler_829C4BD9B8CDAE69-001/solr-instance-001/.
[junit4] 2> 1915213 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartupWithNoActivity-seed#[829C4BD9B8CDAE69]) [ ] o.a.s.c.CorePropertiesLocator Cores are: [collection1]
[junit4] 2> 1915219 INFO (coreLoadExecutor-6005-thread-1) [ x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.5.0
[junit4] 2> 1915225 INFO (coreLoadExecutor-6005-thread-1) [ x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=test
[junit4] 2> 1915227 INFO (coreLoadExecutor-6005-thread-1) [ x:collection1] o.a.s.s.IndexSchema Loaded schema test/1.2 with uniqueid field id
[junit4] 2> 1915228 INFO (coreLoadExecutor-6005-thread-1) [ x:collection1] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from instancedir /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J2/temp/solr.handler.TestReplicationHandler_829C4BD9B8CDAE69-001/solr-instance-001/./collection1
[junit4] 2> 1915229 INFO (coreLoadExecutor-6005-thread-1) [ x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J2/temp/solr.handler.TestReplicationHandler_829C4BD9B8CDAE69-001/solr-instance-001/collection1], dataDir=[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J2/temp/solr.handler.TestReplicationHandler_829C4BD9B8CDAE69-001/solr-instance-001/./collection1/data/]
[junit4] 2> 1915230 INFO (coreLoadExecutor-6005-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=47, maxMergeAtOnceExplicit=42, maxMergedSegmentMB=1.7880859375, floorSegmentMB=1.1396484375, forceMergeDeletesPctAllowed=22.69448066501961, segmentsPerTier=14.0, maxCFSSegmentSizeMB=0.62890625, noCFSRatio=0.0
[junit4] 2> 1915260 INFO (coreLoadExecutor-6005-thread-1) [ x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 1915260 INFO (coreLoadExecutor-6005-thread-1) [ x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 1915260 INFO (coreLoadExecutor-6005-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=28, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.8693303321743608]
[junit4] 2> 1915261 INFO (coreLoadExecutor-6005-thread-1) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@5264ef7a[collection1] main]
[junit4] 2> 1915261 INFO (coreLoadExecutor-6005-thread-1) [ x:collection1] o.a.s.r.ManagedResourceStorage File-based storage initialized to use dir: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J2/temp/solr.handler.TestReplicationHandler_829C4BD9B8CDAE69-001/solr-instance-001/collection1/conf
[junit4] 2> 1915261 INFO (coreLoadExecutor-6005-thread-1) [ x:collection1] o.a.s.h.ReplicationHandler Replication enabled for following config files: schema.xml
[junit4] 2> 1915261 INFO (coreLoadExecutor-6005-thread-1) [ x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 1915261 INFO (searcherExecutor-6006-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@5264ef7a[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 1915770 INFO (qtp1421268278-17420) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[0]} 0 0
[junit4] 2> 1915771 INFO (qtp1421268278-17420) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[1]} 0 0
[junit4] 2> 1915773 INFO (qtp1421268278-17420) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[2]} 0 0
[junit4] 2> 1915774 INFO (qtp1421268278-17423) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[3]} 0 0
[junit4] 2> 1915776 INFO (qtp1421268278-17424) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[4]} 0 0
[junit4] 2> 1915777 INFO (qtp1421268278-17424) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[5]} 0 0
[junit4] 2> 1915779 INFO (qtp1421268278-17424) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[6]} 0 0
[junit4] 2> 1915780 INFO (qtp1421268278-17424) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[7]} 0 0
[junit4] 2> 1915781 INFO (qtp1421268278-17424) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[8]} 0 0
[junit4] 2> 1915783 INFO (qtp1421268278-17423) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[9]} 0 0
[junit4] 2> 1915784 INFO (qtp1421268278-17417) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[10]} 0 0
[junit4] 2> 1915786 INFO (qtp1421268278-17417) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[11]} 0 0
[junit4] 2> 1915787 INFO (qtp1421268278-17417) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[12]} 0 0
[junit4] 2> 1915789 INFO (qtp1421268278-17417) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[13]} 0 0
[junit4] 2> 1915790 INFO (qtp1421268278-17417) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[14]} 0 0
[junit4] 2> 1915792 INFO (qtp1421268278-17423) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[15]} 0 0
[junit4] 2> 1915793 INFO (qtp1421268278-17423) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[16]} 0 0
[junit4] 2> 1915795 INFO (qtp1421268278-17423) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[17]} 0 0
[junit4] 2> 1915796 INFO (qtp1421268278-17423) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[18]} 0 0
[junit4] 2> 1915798 INFO (qtp1421268278-17423) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[19]} 0 0
[junit4] 2> 1915800 INFO (qtp1421268278-17423) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[20]} 0 0
[junit4] 2> 1915801 INFO (qtp1421268278-17423) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[21]} 0 0
[junit4] 2> 1915803 INFO (qtp1421268278-17423) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[22]} 0 0
[junit4] 2> 1915804 INFO (qtp1421268278-17423) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[23]} 0 0
[junit4] 2> 1915806 INFO (qtp1421268278-17423) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[24]} 0 0
[junit4] 2> 1915807 INFO (qtp1421268278-17423) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[25]} 0 0
[junit4] 2> 1915809 INFO (qtp1421268278-17423) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[26]} 0 0
[junit4] 2> 1915810 INFO (qtp1421268278-17423) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[27]} 0 0
[junit4] 2> 1915811 INFO (qtp1421268278-17423) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[28]} 0 0
[junit4] 2> 1915813 INFO (qtp1421268278-17423) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[29]} 0 0
[junit4] 2> 1915814 INFO (qtp1421268278-17423) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[30]} 0 0
[junit4] 2> 1915816 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[31]} 0 0
[junit4] 2> 1915818 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[32]} 0 0
[junit4] 2> 1915819 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[33]} 0 0
[junit4] 2> 1915821 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[34]} 0 0
[junit4] 2> 1915822 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[35]} 0 0
[junit4] 2> 1915824 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[36]} 0 0
[junit4] 2> 1915825 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[37]} 0 0
[junit4] 2> 1915827 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[38]} 0 0
[junit4] 2> 1915828 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[39]} 0 0
[junit4] 2> 1915830 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[40]} 0 0
[junit4] 2> 1915831 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[41]} 0 0
[junit4] 2> 1915833 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[42]} 0 0
[junit4] 2> 1915834 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[43]} 0 0
[junit4] 2> 1915836 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[44]} 0 0
[junit4] 2> 1915837 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[45]} 0 0
[junit4] 2> 1915839 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[46]} 0 0
[junit4] 2> 1915841 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[47]} 0 0
[junit4] 2> 1915842 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[48]} 0 0
[junit4] 2> 1915844 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[49]} 0 0
[junit4] 2> 1915845 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[50]} 0 0
[junit4] 2> 1915847 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[51]} 0 0
[junit4] 2> 1915849 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[52]} 0 0
[junit4] 2> 1915850 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[53]} 0 0
[junit4] 2> 1915852 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[54]} 0 0
[junit4] 2> 1915853 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[55]} 0 0
[junit4] 2> 1915855 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[56]} 0 0
[junit4] 2> 1915857 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[57]} 0 0
[junit4] 2> 1915858 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[58]} 0 0
[junit4] 2> 1915860 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[59]} 0 0
[junit4] 2> 1915861 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[60]} 0 0
[junit4] 2> 1915863 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[61]} 0 0
[junit4] 2> 1915864 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[62]} 0 0
[junit4] 2> 1915866 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[63]} 0 0
[junit4] 2> 1915867 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[64]} 0 0
[junit4] 2> 1915869 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[65]} 0 0
[junit4] 2> 1915871 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[66]} 0 0
[junit4] 2> 1915872 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[67]} 0 0
[junit4] 2> 1915874 INFO (qtp1421268278-17420) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[68]} 0 0
[junit4] 2> 1915875 INFO (qtp1421268278-17424) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[69]} 0 0
[junit4] 2> 1915877 INFO (qtp1421268278-17417) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[70]} 0 0
[junit4] 2> 1915878 INFO (qtp1421268278-17423) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[71]} 0 0
[junit4] 2> 1915880 INFO (qtp1421268278-17422) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[72]} 0 0
[junit4] 2> 1915881 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[73]} 0 0
[junit4] 2> 1915882 INFO (qtp1421268278-17420) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[74]} 0 0
[junit4] 2> 1915884 INFO (qtp1421268278-17424) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[75]} 0 0
[junit4] 2> 1915885 INFO (qtp1421268278-17417) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[76]} 0 0
[junit4] 2> 1915887 INFO (qtp1421268278-17423) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[77]} 0 0
[junit4] 2> 1915888 INFO (qtp1421268278-17422) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[78]} 0 0
[junit4] 2> 1915889 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[79]} 0 0
[junit4] 2> 1915891 INFO (qtp1421268278-17420) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[80]} 0 0
[junit4] 2> 1915892 INFO (qtp1421268278-17424) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[81]} 0 0
[junit4] 2> 1915894 INFO (qtp1421268278-17417) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[82]} 0 0
[junit4] 2> 1915895 INFO (qtp1421268278-17423) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[83]} 0 0
[junit4] 2> 1915896 INFO (qtp1421268278-17422) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[84]} 0 0
[junit4] 2> 1915898 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[85]} 0 0
[junit4] 2> 1915899 INFO (qtp1421268278-17420) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[86]} 0 0
[junit4] 2> 1915900 INFO (qtp1421268278-17424) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[87]} 0 0
[junit4] 2> 1915902 INFO (qtp1421268278-17417) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[88]} 0 0
[junit4] 2> 1915903 INFO (qtp1421268278-17423) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[89]} 0 0
[junit4] 2> 1915905 INFO (qtp1421268278-17422) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[90]} 0 0
[junit4] 2> 1915906 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[91]} 0 0
[junit4] 2> 1915908 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[92]} 0 0
[junit4] 2> 1915909 INFO (qtp1421268278-17424) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[93]} 0 0
[junit4] 2> 1915910 INFO (qtp1421268278-17417) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[94]} 0 0
[junit4] 2> 1915912 INFO (qtp1421268278-17423) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[95]} 0 0
[junit4] 2> 1915913 INFO (qtp1421268278-17422) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[96]} 0 0
[junit4] 2> 1915915 INFO (qtp1421268278-17420) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[97]} 0 0
[junit4] 2> 1915916 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[98]} 0 0
[junit4] 2> 1915918 INFO (qtp1421268278-17424) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[99]} 0 0
[junit4] 2> 1915919 INFO (qtp1421268278-17417) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[100]} 0 0
[junit4] 2> 1915920 INFO (qtp1421268278-17423) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[101]} 0 0
[junit4] 2> 1915922 INFO (qtp1421268278-17422) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[102]} 0 0
[junit4] 2> 1915923 INFO (qtp1421268278-17420) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[103]} 0 0
[junit4] 2> 1915925 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[104]} 0 0
[junit4] 2> 1915926 INFO (qtp1421268278-17424) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[105]} 0 0
[junit4] 2> 1915927 INFO (qtp1421268278-17417) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[106]} 0 0
[junit4] 2> 1915929 INFO (qtp1421268278-17423) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[107]} 0 0
[junit4] 2> 1915930 INFO (qtp1421268278-17422) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[108]} 0 0
[junit4] 2> 1915932 INFO (qtp1421268278-17420) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[109]} 0 0
[junit4] 2> 1915933 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[110]} 0 0
[junit4] 2> 1915935 INFO (qtp1421268278-17424) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[111]} 0 0
[junit4] 2> 1915936 INFO (qtp1421268278-17417) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[112]} 0 0
[junit4] 2> 1915937 INFO (qtp1421268278-17423) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[113]} 0 0
[junit4] 2> 1915939 INFO (qtp1421268278-17422) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[114]} 0 0
[junit4] 2> 1915940 INFO (qtp1421268278-17420) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[115]} 0 0
[junit4] 2> 1915942 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[116]} 0 0
[junit4] 2> 1915943 INFO (qtp1421268278-17424) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[117]} 0 0
[junit4] 2> 1915945 INFO (qtp1421268278-17417) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[118]} 0 0
[junit4] 2> 1915946 INFO (qtp1421268278-17423) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[119]} 0 0
[junit4] 2> 1915948 INFO (qtp1421268278-17422) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[120]} 0 0
[junit4] 2> 1915950 INFO (qtp1421268278-17422) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[121]} 0 0
[junit4] 2> 1915951 INFO (qtp1421268278-17422) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[122]} 0 0
[junit4] 2> 1915953 INFO (qtp1421268278-17422) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[123]} 0 0
[junit4] 2> 1915955 INFO (qtp1421268278-17417) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[124]} 0 0
[junit4] 2> 1915960 INFO (qtp1421268278-17423) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[125]} 0 4
[junit4] 2> 1915962 INFO (qtp1421268278-17420) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[126]} 0 0
[junit4] 2> 1915963 INFO (qtp1421268278-17420) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[127]} 0 0
[junit4] 2> 1915965 INFO (qtp1421268278-17420) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[128]} 0 0
[junit4] 2> 1915966 INFO (qtp1421268278-17422) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[129]} 0 0
[junit4] 2> 1915968 INFO (qtp1421268278-17417) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[130]} 0 0
[junit4] 2> 1915969 INFO (qtp1421268278-17423) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[131]} 0 0
[junit4] 2> 1915971 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[132]} 0 0
[junit4] 2> 1915972 INFO (qtp1421268278-17424) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[133]} 0 0
[junit4] 2> 1915973 INFO (qtp1421268278-17420) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[134]} 0 0
[junit4] 2> 1915975 INFO (qtp1421268278-17422) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[135]} 0 0
[junit4] 2> 1915976 INFO (qtp1421268278-17417) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[136]} 0 0
[junit4] 2> 1915978 INFO (qtp1421268278-17423) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[137]} 0 0
[junit4] 2> 1915979 INFO (qtp1421268278-17423) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[138]} 0 0
[junit4] 2> 1915981 INFO (qtp1421268278-17424) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[139]} 0 0
[junit4] 2> 1915982 INFO (qtp1421268278-17420) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[140]} 0 0
[junit4] 2> 1915983 INFO (qtp1421268278-17422) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[141]} 0 0
[junit4] 2> 1915985 INFO (qtp1421268278-17417) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[142]} 0 0
[junit4] 2> 1915986 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[143]} 0 0
[junit4] 2> 1915988 INFO (qtp1421268278-17423) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[144]} 0 0
[junit4] 2> 1915989 INFO (qtp1421268278-17424) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[145]} 0 0
[junit4] 2> 1915991 INFO (qtp1421268278-17420) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[146]} 0 0
[junit4] 2> 1915992 INFO (qtp1421268278-17422) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[147]} 0 0
[junit4] 2> 1915993 INFO (qtp1421268278-17417) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[148]} 0 0
[junit4] 2> 1915995 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[149]} 0 0
[junit4] 2> 1915996 INFO (qtp1421268278-17423) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[150]} 0 0
[junit4] 2> 1915998 INFO (qtp1421268278-17424) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[151]} 0 0
[junit4] 2> 1915999 INFO (qtp1421268278-17424) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[152]} 0 0
[junit4] 2> 1916000 INFO (qtp1421268278-17422) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[153]} 0 0
[junit4] 2> 1916002 INFO (qtp1421268278-17417) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[154]} 0 0
[junit4] 2> 1916003 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[155]} 0 0
[junit4] 2> 1916005 INFO (qtp1421268278-17423) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[156]} 0 0
[junit4] 2> 1916006 INFO (qtp1421268278-17420) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[157]} 0 0
[junit4] 2> 1916008 INFO (qtp1421268278-17424) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[158]} 0 0
[junit4] 2> 1916009 INFO (qtp1421268278-17422) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[159]} 0 0
[junit4] 2> 1916010 INFO (qtp1421268278-17417) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[160]} 0 0
[junit4] 2> 1916012 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[161]} 0 0
[junit4] 2> 1916013 INFO (qtp1421268278-17423) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[162]} 0 0
[junit4] 2> 1916015 INFO (qtp1421268278-17420) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[163]} 0 0
[junit4] 2> 1916016 INFO (qtp1421268278-17424) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[164]} 0 0
[junit4] 2> 1916018 INFO (qtp1421268278-17422) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[165]} 0 0
[junit4] 2> 1916019 INFO (qtp1421268278-17417) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[166]} 0 0
[junit4] 2> 1916021 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[167]} 0 0
[junit4] 2> 1916022 INFO (qtp1421268278-17423) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[168]} 0 0
[junit4] 2> 1916024 INFO (qtp1421268278-17420) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[169]} 0 0
[junit4] 2> 1916025 INFO (qtp1421268278-17424) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[170]} 0 0
[junit4] 2> 1916027 INFO (qtp1421268278-17422) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[171]} 0 0
[junit4] 2> 1916028 INFO (qtp1421268278-17417) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[172]} 0 0
[junit4] 2> 1916032 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[173]} 0 0
[junit4] 2> 1916034 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[174]} 0 0
[junit4] 2> 1916035 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[175]} 0 0
[junit4] 2> 1916037 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[176]} 0 0
[junit4] 2> 1916038 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[177]} 0 0
[junit4] 2> 1916040 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[178]} 0 0
[junit4] 2> 1916041 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[179]} 0 0
[junit4] 2> 1916042 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[180]} 0 0
[junit4] 2> 1916044 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[181]} 0 0
[junit4] 2> 1916046 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[182]} 0 0
[junit4] 2> 1916047 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[183]} 0 0
[junit4] 2> 1916048 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[184]} 0 0
[junit4] 2> 1916050 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[185]} 0 0
[junit4] 2> 1916051 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[186]} 0 0
[junit4] 2> 1916053 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[187]} 0 0
[junit4] 2> 1916055 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[188]} 0 0
[junit4] 2> 1916056 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[189]} 0 0
[junit4] 2> 1916058 INFO (qtp1421268278-17420) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[190]} 0 0
[junit4] 2> 1916059 INFO (qtp1421268278-17424) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[191]} 0 0
[junit4] 2> 1916061 INFO (qtp1421268278-17424) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[192]} 0 0
[junit4] 2> 1916062 INFO (qtp1421268278-17424) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[193]} 0 0
[junit4] 2> 1916064 INFO (qtp1421268278-17424) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[194]} 0 0
[junit4] 2> 1916065 INFO (qtp1421268278-17424) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[195]} 0 0
[junit4] 2> 1916066 INFO (qtp1421268278-17420) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[196]} 0 0
[junit4] 2> 1916068 INFO (qtp1421268278-17422) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[197]} 0 0
[junit4] 2> 1916069 INFO (qtp1421268278-17422) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[198]} 0 0
[junit4] 2> 1916071 INFO (qtp1421268278-17422) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[199]} 0 0
[junit4] 2> 1916072 INFO (qtp1421268278-17422) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[200]} 0 0
[junit4] 2> 1916074 INFO (qtp1421268278-17422) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[201]} 0 0
[junit4] 2> 1916075 INFO (qtp1421268278-17420) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[202]} 0 0
[junit4] 2> 1916076 INFO (qtp1421268278-17417) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[203]} 0 0
[junit4] 2> 1916078 INFO (qtp1421268278-17417) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[204]} 0 0
[junit4] 2> 1916079 INFO (qtp1421268278-17417) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[205]} 0 0
[junit4] 2> 1916081 INFO (qtp1421268278-17417) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[206]} 0 0
[junit4] 2> 1916082 INFO (qtp1421268278-17417) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[207]} 0 0
[junit4] 2> 1916084 INFO (qtp1421268278-17420) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[208]} 0 0
[junit4] 2> 1916085 INFO (qtp1421268278-17423) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[209]} 0 0
[junit4] 2> 1916086 INFO (qtp1421268278-17423) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[210]} 0 0
[junit4] 2> 1916088 INFO (qtp1421268278-17423) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[211]} 0 0
[junit4] 2> 1916089 INFO (qtp1421268278-17423) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[212]} 0 0
[junit4] 2> 1916091 INFO (qtp1421268278-17423) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[213]} 0 0
[junit4] 2> 1916092 INFO (qtp1421268278-17420) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[214]} 0 0
[junit4] 2> 1916093 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[215]} 0 0
[junit4] 2> 1916095 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[216]} 0 0
[junit4] 2> 1916096 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[217]} 0 0
[junit4] 2> 1916098 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[218]} 0 0
[junit4] 2> 1916099 INFO (qtp1421268278-17421) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[219]} 0 0
[junit4] 2> 1916101 INFO (qtp1421268278-17420) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[220]} 0 0
[junit4] 2> 1916102 INFO (qtp1421268278-17424) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[221]} 0 0
[junit4] 2> 1916105 INFO (qtp1421268278-17424) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[222]} 0 0
[junit4] 2> 1916106 INFO (qtp1421268278-17424) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[223]} 0 0
[junit4] 2> 1916107 INFO (qtp1421268278-17424) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[224]} 0 0
[junit4] 2> 1916109 INFO (qtp1421268278-17424) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={
[...truncated too long message...]
path=/update params={wt=javabin&version=2}{add=[554]} 0 0
[junit4] 2> 2557424 INFO (qtp1239514442-19187) [ x:collection1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 2557424 INFO (qtp1239514442-19187) [ x:collection1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@3b566bad
[junit4] 2> 2557434 INFO (qtp1239514442-19187) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@68c4a09c[collection1] main]
[junit4] 2> 2557434 INFO (qtp1239514442-19187) [ x:collection1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 2557434 INFO (searcherExecutor-6879-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@68c4a09c[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_2(6.5.0):c1) Uninverting(_1(6.5.0):c1) Uninverting(_3(6.5.0):c1) Uninverting(_4(6.5.0):c1)))}
[junit4] 2> 2557434 INFO (qtp1239514442-19187) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=} 0 10
[junit4] 2> 2557438 INFO (qtp1239514442-19189) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[555]} 0 0
[junit4] 2> 2557439 INFO (qtp1239514442-19185) [ x:collection1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 2557439 INFO (qtp1239514442-19185) [ x:collection1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@3b566bad
[junit4] 2> 2557445 INFO (qtp1239514442-19185) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@5f390aa2[collection1] main]
[junit4] 2> 2557445 INFO (qtp1239514442-19185) [ x:collection1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 2557445 INFO (searcherExecutor-6879-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@5f390aa2[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_2(6.5.0):c1) Uninverting(_1(6.5.0):c1) Uninverting(_3(6.5.0):c1) Uninverting(_4(6.5.0):c1) Uninverting(_5(6.5.0):c1)))}
[junit4] 2> 2557445 INFO (qtp1239514442-19185) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=} 0 6
[junit4] 2> 2557447 INFO (qtp1239514442-19190) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/select params={q=id:555&sort=id+desc&wt=javabin&version=2} hits=1 status=0 QTime=0
[junit4] 2> 2557447 INFO (TEST-TestReplicationHandler.doTestReplicateAfterWrite2Slave-seed#[829C4BD9B8CDAE69]) [ ] o.a.s.h.TestReplicationHandler Waited for 0ms and found 1 docs
[junit4] 2> 2557448 INFO (qtp1021027092-19171) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={command=enablereplication} status=0 QTime=0
[junit4] 2> 2557450 INFO (qtp1239514442-19188) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={command=fetchindex} status=0 QTime=1
[junit4] 2> 2557450 INFO (TEST-TestReplicationHandler.doTestReplicateAfterWrite2Slave-seed#[829C4BD9B8CDAE69]) [ ] o.a.s.SolrTestCaseJ4 ###Ending doTestReplicateAfterWrite2Slave
[junit4] 2> 2557451 INFO (TEST-TestReplicationHandler.doTestReplicateAfterWrite2Slave-seed#[829C4BD9B8CDAE69]) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@70c399ff{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
[junit4] 2> 2557451 INFO (TEST-TestReplicationHandler.doTestReplicateAfterWrite2Slave-seed#[829C4BD9B8CDAE69]) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=1969462354
[junit4] 2> 2557451 ERROR (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Master at: http://127.0.0.1:47377/solr/collection1 is not available. Index fetch failed. Exception: Server refused connection at: http://127.0.0.1:47377/solr/collection1
[junit4] 2> 2557452 INFO (coreCloseExecutor-6884-thread-1) [ x:collection1] o.a.s.c.SolrCore [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@5eeca976
[junit4] 2> 2557453 INFO (coreCloseExecutor-6884-thread-1) [ x:collection1] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.collection1
[junit4] 2> 2557454 INFO (TEST-TestReplicationHandler.doTestReplicateAfterWrite2Slave-seed#[829C4BD9B8CDAE69]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.node
[junit4] 2> 2557454 INFO (TEST-TestReplicationHandler.doTestReplicateAfterWrite2Slave-seed#[829C4BD9B8CDAE69]) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@792e465e{/solr,null,UNAVAILABLE}
[junit4] 2> 2557455 INFO (TEST-TestReplicationHandler.doTestReplicateAfterWrite2Slave-seed#[829C4BD9B8CDAE69]) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@10522d71{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
[junit4] 2> 2557455 INFO (TEST-TestReplicationHandler.doTestReplicateAfterWrite2Slave-seed#[829C4BD9B8CDAE69]) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=1747387634
[junit4] 2> 2557455 INFO (coreCloseExecutor-6886-thread-1) [ x:collection1] o.a.s.c.SolrCore [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@108f0157
[junit4] 2> 2557458 INFO (coreCloseExecutor-6886-thread-1) [ x:collection1] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.collection1
[junit4] 2> 2557459 INFO (TEST-TestReplicationHandler.doTestReplicateAfterWrite2Slave-seed#[829C4BD9B8CDAE69]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.node
[junit4] 2> 2557459 INFO (TEST-TestReplicationHandler.doTestReplicateAfterWrite2Slave-seed#[829C4BD9B8CDAE69]) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@5f48be1b{/solr,null,UNAVAILABLE}
[junit4] 2> 2557460 INFO (SUITE-TestReplicationHandler-seed#[829C4BD9B8CDAE69]-worker) [ ] o.a.s.SolrTestCaseJ4 ###deleteCore
[junit4] 2> NOTE: leaving temporary files on disk at: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J2/temp/solr.handler.TestReplicationHandler_829C4BD9B8CDAE69-001
[junit4] 2> NOTE: test params are: codec=CheapBastard, sim=RandomSimilarity(queryNorm=false,coord=crazy): {}, locale=sq-AL, timezone=Africa/Nairobi
[junit4] 2> NOTE: Linux 3.13.0-85-generic amd64/Oracle Corporation 1.8.0_121 (64-bit)/cpus=4,threads=1,free=197212072,total=533200896
[junit4] 2> NOTE: All tests run in this JVM: [HdfsNNFailoverTest, TestDefaultStatsCache, TestConfigReload, HttpPartitionTest, SolrIndexMetricsTest, TestExtendedDismaxParser, TestCustomSort, CurrencyFieldXmlFileTest, CoreAdminRequestStatusTest, TestJsonFacetRefinement, SuggestComponentContextFilterQueryTest, EnumFieldTest, TestSolrCLIRunExample, MetricsHandlerTest, HLLUtilTest, TermVectorComponentDistributedTest, HardAutoCommitTest, TestConfig, TimeZoneUtilsTest, TestWriterPerf, PrimUtilsTest, ConcurrentDeleteAndCreateCollectionTest, BasicDistributedZk2Test, DeleteLastCustomShardedReplicaTest, CreateCollectionCleanupTest, SolrCloudExampleTest, SolrSlf4jReporterTest, FieldAnalysisRequestHandlerTest, CollectionTooManyReplicasTest, GraphQueryTest, TestSolrQueryParserResource, TestCoreDiscovery, TestSystemCollAutoCreate, TestHdfsCloudBackupRestore, DocValuesMultiTest, TestClassNameShortening, TestReversedWildcardFilterFactory, TestCollectionAPI, TestMaxScoreQueryParser, OverseerModifyCollectionTest, TestOverriddenPrefixQueryForCustomFieldType, ClassificationUpdateProcessorTest, BlockJoinFacetDistribTest, StatsReloadRaceTest, TestUtils, TestHdfsUpdateLog, BinaryUpdateRequestHandlerTest, UnloadDistributedZkTest, TestCollapseQParserPlugin, FieldMutatingUpdateProcessorTest, BlockDirectoryTest, TestJmxMonitoredMap, TestLFUCache, TestFieldCacheReopen, TestAnalyzedSuggestions, JSONWriterTest, TestLMJelinekMercerSimilarityFactory, DistribDocExpirationUpdateProcessorTest, TestExactStatsCache, TestPerFieldSimilarityClassic, TestFreeTextSuggestions, RequestHandlersTest, TestDynamicFieldCollectionResource, TestManagedResourceStorage, TestAnalyzeInfixSuggestions, LeaderElectionTest, IgnoreCommitOptimizeUpdateProcessorFactoryTest, MinimalSchemaTest, QueryParsingTest, SuggesterTSTTest, SharedFSAutoReplicaFailoverUtilsTest, TestSolrFieldCacheMBean, TestIndexingPerformance, TestSchemaNameResource, TestSort, PingRequestHandlerTest, TestMacros, TestSchemaVersionResource, DirectUpdateHandlerTest, TestConfigsApi, TestGeoJSONResponseWriter, TestManagedSchema, ShowFileRequestHandlerTest, TestOrdValues, AnalyticsQueryTest, RestartWhileUpdatingTest, DeleteShardTest, TestXIncludeConfig, CdcrUpdateLogTest, ExitableDirectoryReaderTest, HdfsTlogReplayBufferedWhileIndexingTest, DistributedFacetPivotLongTailTest, TestSolrCloudWithKerberosAlt, TestPhraseSuggestions, HdfsChaosMonkeyNothingIsSafeTest, OverseerTest, ReplicaListTransformerTest, TestPKIAuthenticationPlugin, TestSubQueryTransformerCrossCore, SaslZkACLProviderTest, HttpSolrCallGetCoreTest, ActionThrottleTest, ChangedSchemaMergeTest, TestSolrJ, CdcrVersionReplicationTest, TestStressReorder, TestLegacyFieldCache, TestRecovery, TestShortCircuitedRequests, TestFieldResource, TestReqParamsAPI, BasicDistributedZkTest, ChaosMonkeySafeLeaderTest, CollectionsAPIDistributedZkTest, TestReplicationHandler]
[junit4] Completed [503/697 (1!)] on J2 in 643.48s, 16 tests, 1 failure, 1 skipped <<< FAILURES!
[...truncated 63302 lines...]