Build: https://builds.apache.org/job/Lucene-Solr-NightlyTests-5.x/660/
2 tests failed. REGRESSION: org.apache.solr.cloud.DistribDocExpirationUpdateProcessorTest.testDistribSearch Error Message: There are still nodes recoverying - waited for 30 seconds Stack Trace: java.lang.AssertionError: There are still nodes recoverying - waited for 30 seconds at __randomizedtesting.SeedInfo.seed([B5A13DAD736935A:8ABC9DC2A069F366]:0) at org.junit.Assert.fail(Assert.java:93) at org.apache.solr.cloud.AbstractDistribZkTestBase.waitForRecoveriesToFinish(AbstractDistribZkTestBase.java:178) at org.apache.solr.cloud.AbstractFullDistribZkTestBase.waitForRecoveriesToFinish(AbstractFullDistribZkTestBase.java:840) at org.apache.solr.cloud.AbstractFullDistribZkTestBase.waitForThingsToLevelOut(AbstractFullDistribZkTestBase.java:1459) at org.apache.solr.cloud.DistribDocExpirationUpdateProcessorTest.doTest(DistribDocExpirationUpdateProcessorTest.java:79) at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:869) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:606) at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1618) at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:827) at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863) at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:877) at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53) at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50) at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46) at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55) at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49) at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65) at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365) at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:798) at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:458) at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:836) at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:738) at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:772) at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:783) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53) at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46) at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42) at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55) at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39) at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39) 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:54) at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48) at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65) at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365) at java.lang.Thread.run(Thread.java:745) FAILED: org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testDistribSearch Error Message: Captured an uncaught exception in thread: Thread[id=399, name=Thread-149, state=RUNNABLE, group=TGRP-CollectionsAPIDistributedZkTest] Stack Trace: com.carrotsearch.randomizedtesting.UncaughtExceptionError: Captured an uncaught exception in thread: Thread[id=399, name=Thread-149, state=RUNNABLE, group=TGRP-CollectionsAPIDistributedZkTest] Caused by: java.lang.NullPointerException at __randomizedtesting.SeedInfo.seed([B5A13DAD736935A]:0) at org.apache.solr.cloud.CollectionsAPIDistributedZkTest$1CollectionThread.run(CollectionsAPIDistributedZkTest.java:1044) Build Log: [...truncated 11573 lines...] [junit4] Suite: org.apache.solr.cloud.CollectionsAPIDistributedZkTest [junit4] 2> Creating dataDir: /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.x/solr/build/solr-core/test/J3/temp/solr.cloud.CollectionsAPIDistributedZkTest-B5A13DAD736935A-001/init-core-data-001 [junit4] 2> 95802 T170 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (false) and clientAuth (false) [junit4] 2> 95803 T170 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /iv/dh [junit4] 2> 95810 T170 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch [junit4] 2> 95821 T170 oasc.ZkTestServer.run STARTING ZK TEST SERVER [junit4] 1> client port:0.0.0.0/0.0.0.0:0 [junit4] 2> 95830 T171 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server [junit4] 2> 96030 T170 oasc.ZkTestServer.run start zk server on port:48179 [junit4] 2> 96040 T170 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider [junit4] 2> 96283 T170 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 96341 T172 oazs.NIOServerCnxn.doIO WARN Exception causing close of session 0x0 due to java.io.IOException: ZooKeeperServer not running [junit4] 2> 98043 T176 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@53e0e375 name:ZooKeeperConnection Watcher:127.0.0.1:48179 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 98044 T170 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 98044 T170 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider [junit4] 2> 98055 T170 oascc.SolrZkClient.makePath makePath: /solr [junit4] 2> 98177 T170 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider [junit4] 2> 98178 T170 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 98180 T179 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@26f32b74 name:ZooKeeperConnection Watcher:127.0.0.1:48179/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 98181 T170 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 98181 T170 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider [junit4] 2> 98189 T170 oascc.SolrZkClient.makePath makePath: /collections/collection1 [junit4] 2> 98194 T170 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards [junit4] 2> 98198 T170 oascc.SolrZkClient.makePath makePath: /collections/control_collection [junit4] 2> 98201 T170 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards [junit4] 2> 98205 T170 oasc.AbstractZkTestCase.putConfig put /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.x/solr/core/src/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml [junit4] 2> 98206 T170 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml [junit4] 2> 98212 T170 oasc.AbstractZkTestCase.putConfig put /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.x/solr/core/src/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml [junit4] 2> 98213 T170 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml [junit4] 2> 98218 T170 oasc.AbstractZkTestCase.putConfig put /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.x/solr/core/src/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml [junit4] 2> 98219 T170 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml [junit4] 2> 98223 T170 oasc.AbstractZkTestCase.putConfig put /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.x/solr/core/src/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt [junit4] 2> 98224 T170 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt [junit4] 2> 98228 T170 oasc.AbstractZkTestCase.putConfig put /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.x/solr/core/src/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt [junit4] 2> 98228 T170 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt [junit4] 2> 98233 T170 oasc.AbstractZkTestCase.putConfig put /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.x/solr/core/src/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml [junit4] 2> 98233 T170 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml [junit4] 2> 98238 T170 oasc.AbstractZkTestCase.putConfig put /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.x/solr/core/src/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml [junit4] 2> 98238 T170 oascc.SolrZkClient.makePath makePath: /configs/conf1/enumsConfig.xml [junit4] 2> 98242 T170 oasc.AbstractZkTestCase.putConfig put /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.x/solr/core/src/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json [junit4] 2> 98243 T170 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json [junit4] 2> 98247 T170 oasc.AbstractZkTestCase.putConfig put /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.x/solr/core/src/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt [junit4] 2> 98248 T170 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt [junit4] 2> 98252 T170 oasc.AbstractZkTestCase.putConfig put /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.x/solr/core/src/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt [junit4] 2> 98253 T170 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt [junit4] 2> 98257 T170 oasc.AbstractZkTestCase.putConfig put /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.x/solr/core/src/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt [junit4] 2> 98258 T170 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt [junit4] 2> Using old style solr.xml [junit4] 2> 99465 T170 oejs.Server.doStart jetty-8.1.10.v20130312 [junit4] 2> 99469 T170 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:48183 [junit4] 2> 99470 T170 oass.SolrDispatchFilter.init SolrDispatchFilter.init() [junit4] 2> 99470 T170 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx) [junit4] 2> 99470 T170 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.x/solr/build/solr-core/test/J3/temp/solr.cloud.CollectionsAPIDistributedZkTest-B5A13DAD736935A-001/tempDir-002 [junit4] 2> 99471 T170 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.x/solr/build/solr-core/test/J3/temp/solr.cloud.CollectionsAPIDistributedZkTest-B5A13DAD736935A-001/tempDir-002/' [junit4] 2> 99501 T170 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.x/solr/build/solr-core/test/J3/temp/solr.cloud.CollectionsAPIDistributedZkTest-B5A13DAD736935A-001/tempDir-002/solr.xml [junit4] 2> 99574 T170 oasc.CoreContainer.<init> New CoreContainer 1463550078 [junit4] 2> 99574 T170 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.x/solr/build/solr-core/test/J3/temp/solr.cloud.CollectionsAPIDistributedZkTest-B5A13DAD736935A-001/tempDir-002/] [junit4] 2> 99576 T170 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000 [junit4] 2> 99576 T170 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: null [junit4] 2> 99576 T170 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000 [junit4] 2> 99577 T170 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20 [junit4] 2> 99577 T170 oashc.HttpShardHandlerFactory.getParameter Setting maxConnections to: 10000 [junit4] 2> 99577 T170 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0 [junit4] 2> 99577 T170 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647 [junit4] 2> 99578 T170 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5 [junit4] 2> 99578 T170 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1 [junit4] 2> 99578 T170 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false [junit4] 2> 99579 T170 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: socketTimeout=3400000&connTimeout=45000&retry=false [junit4] 2> 99579 T170 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory [junit4] 2> 99579 T170 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)] [junit4] 2> 99580 T170 oasc.CoreContainer.load Host Name: 127.0.0.1 [junit4] 2> 99580 T170 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:48179/solr [junit4] 2> 99605 T170 oasc.ZkController.checkChrootPath zkHost includes chroot [junit4] 2> 99605 T170 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider [junit4] 2> 99606 T170 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 99609 T190 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2ac1105f name:ZooKeeperConnection Watcher:127.0.0.1:48179 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 99609 T170 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 99610 T170 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider [junit4] 2> 99624 T170 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 99626 T192 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@688b97a9 name:ZooKeeperConnection Watcher:127.0.0.1:48179/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 99626 T170 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 99647 T170 oascc.SolrZkClient.makePath makePath: /overseer/queue [junit4] 2> 99659 T170 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work [junit4] 2> 99669 T170 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running [junit4] 2> 99674 T170 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed [junit4] 2> 99678 T170 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure [junit4] 2> 99702 T170 oascc.SolrZkClient.makePath makePath: /live_nodes [junit4] 2> 99704 T170 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:48183_iv%2Fdh [junit4] 2> 99722 T170 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:48183_iv%2Fdh [junit4] 2> 99730 T170 oascc.SolrZkClient.makePath makePath: /overseer_elect [junit4] 2> 99733 T170 oascc.SolrZkClient.makePath makePath: /overseer_elect/election [junit4] 2> 99736 T170 oasc.Overseer.close Overseer (id=null) closing [junit4] 2> 99760 T170 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:48183_iv%2Fdh [junit4] 2> 99760 T170 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader [junit4] 2> 99764 T170 oasc.Overseer.start Overseer (id=92697411967516675-127.0.0.1:48183_iv%2Fdh-n_0000000000) starting [junit4] 2> 99784 T170 oascc.SolrZkClient.makePath makePath: /overseer/queue-work [junit4] 2> 99824 T170 oasc.OverseerAutoReplicaFailoverThread.<init> Starting OverseerAutoReplicaFailoverThread autoReplicaFailoverWorkLoopDelay=10000 autoReplicaFailoverWaitAfterExpiration=30000 autoReplicaFailoverBadNodeExpiration=60000 [junit4] 2> 99847 T194 oasc.OverseerCollectionProcessor.run Process current queue of collection creations [junit4] 2> 99848 T170 oascc.SolrZkClient.makePath makePath: /clusterstate.json [junit4] 2> 99851 T170 oascc.SolrZkClient.makePath makePath: /aliases.json [junit4] 2> 99853 T170 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... [junit4] 2> 99890 T193 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue [junit4] 2> 99900 T170 oass.SolrDispatchFilter.init user.dir=/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.x/solr/build/solr-core/test/J3 [junit4] 2> 99901 T170 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done [junit4] 2> 99944 T170 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider [junit4] 2> 99945 T170 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 99947 T198 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@71d1ff7f name:ZooKeeperConnection Watcher:127.0.0.1:48179/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 99947 T170 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 99948 T170 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider [junit4] 2> 99950 T170 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... [junit4] 2> 99958 T170 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:false [junit4] 2> 99958 T170 oasc.AbstractFullDistribZkTestBase.createJettys Creating collection1 with stateFormat=2 [junit4] 2> 99959 T170 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider [junit4] 2> 99959 T170 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 99961 T200 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@638b6eec name:ZooKeeperConnection Watcher:127.0.0.1:48179/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 99962 T170 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 99962 T170 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider [junit4] 2> 99980 T201 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 100004 T193 oasc.Overseer$ClusterStateUpdater.buildCollection building a new collection: collection1 [junit4] 2> 100005 T193 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2] [junit4] 2> 100019 T193 oasc.Overseer$ClusterStateUpdater.createCollection state version collection1 2 [junit4] 2> 100031 T193 oasc.Overseer$ClusterStateUpdater.updateZkStates going to create_collection /collections/collection1/state.json [junit4] 2> 100049 T201 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 100049 T202 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 101097 T170 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 1 [junit4] 2> 101103 T170 oejs.Server.doStart jetty-8.1.10.v20130312 [junit4] 2> 101105 T170 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:48188 [junit4] 2> 101106 T170 oass.SolrDispatchFilter.init SolrDispatchFilter.init() [junit4] 2> 101106 T170 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx) [junit4] 2> 101106 T170 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../../usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.x/solr/build/solr-core/test/J3/temp/solr.cloud.CollectionsAPIDistributedZkTest-B5A13DAD736935A-001/tempDir-003 [junit4] 2> 101107 T170 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.x/solr/build/solr-core/test/J3/temp/solr.cloud.CollectionsAPIDistributedZkTest-B5A13DAD736935A-001/tempDir-003/' [junit4] 2> 101137 T170 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.x/solr/build/solr-core/test/J3/../../../../../../../../../../../usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.x/solr/build/solr-core/test/J3/temp/solr.cloud.CollectionsAPIDistributedZkTest-B5A13DAD736935A-001/tempDir-003/solr.xml [junit4] 2> 101195 T170 oasc.CoreContainer.<init> New CoreContainer 354244941 [junit4] 2> 101196 T170 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../../usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.x/solr/build/solr-core/test/J3/temp/solr.cloud.CollectionsAPIDistributedZkTest-B5A13DAD736935A-001/tempDir-003/] [junit4] 2> 101197 T170 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000 [junit4] 2> 101197 T170 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: null [junit4] 2> 101197 T170 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000 [junit4] 2> 101197 T170 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20 [junit4] 2> 101198 T170 oashc.HttpShardHandlerFactory.getParameter Setting maxConnections to: 10000 [junit4] 2> 101198 T170 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0 [junit4] 2> 101198 T170 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647 [junit4] 2> 101198 T170 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5 [junit4] 2> 101199 T170 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1 [junit4] 2> 101199 T170 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false [junit4] 2> 101200 T170 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: socketTimeout=3400000&connTimeout=45000&retry=false [junit4] 2> 101200 T170 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory [junit4] 2> 101200 T170 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)] [junit4] 2> 101200 T170 oasc.CoreContainer.load Host Name: 127.0.0.1 [junit4] 2> 101201 T170 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:48179/solr [junit4] 2> 101201 T170 oasc.ZkController.checkChrootPath zkHost includes chroot [junit4] 2> 101201 T170 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider [junit4] 2> 101202 T170 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 101204 T213 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@39d1d90f name:ZooKeeperConnection Watcher:127.0.0.1:48179 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 101205 T170 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 101205 T170 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider [junit4] 2> 101207 T170 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 101208 T215 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@d8e872 name:ZooKeeperConnection Watcher:127.0.0.1:48179/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 101209 T170 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 101217 T170 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... [junit4] 2> 102225 T170 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:48188_iv%2Fdh [junit4] 2> 102227 T170 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:48188_iv%2Fdh [junit4] 2> 102233 T170 oasc.Overseer.close Overseer (id=null) closing [junit4] 2> 102246 T170 oass.SolrDispatchFilter.init user.dir=/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.x/solr/build/solr-core/test/J3 [junit4] 2> 102246 T170 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done [junit4] 2> 103459 T170 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 2 [junit4] 2> 103460 T170 oejs.Server.doStart jetty-8.1.10.v20130312 [junit4] 2> 103462 T170 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:48191 [junit4] 2> 103463 T170 oass.SolrDispatchFilter.init SolrDispatchFilter.init() [junit4] 2> 103463 T170 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx) [junit4] 2> 103463 T170 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.x/solr/build/solr-core/test/J3/temp/solr.cloud.CollectionsAPIDistributedZkTest-B5A13DAD736935A-001/tempDir-004 [junit4] 2> 103464 T170 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.x/solr/build/solr-core/test/J3/temp/solr.cloud.CollectionsAPIDistributedZkTest-B5A13DAD736935A-001/tempDir-004/' [junit4] 2> 103494 T170 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.x/solr/build/solr-core/test/J3/temp/solr.cloud.CollectionsAPIDistributedZkTest-B5A13DAD736935A-001/tempDir-004/solr.xml [junit4] 2> 103550 T170 oasc.CoreContainer.<init> New CoreContainer 2044751973 [junit4] 2> 103551 T170 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.x/solr/build/solr-core/test/J3/temp/solr.cloud.CollectionsAPIDistributedZkTest-B5A13DAD736935A-001/tempDir-004/] [junit4] 2> 103552 T170 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000 [junit4] 2> 103552 T170 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: null [junit4] 2> 103552 T170 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000 [junit4] 2> 103552 T170 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20 [junit4] 2> 103553 T170 oashc.HttpShardHandlerFactory.getParameter Setting maxConnections to: 10000 [junit4] 2> 103553 T170 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0 [junit4] 2> 103553 T170 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647 [junit4] 2> 103554 T170 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5 [junit4] 2> 103554 T170 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1 [junit4] 2> 103554 T170 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false [junit4] 2> 103555 T170 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: socketTimeout=3400000&connTimeout=45000&retry=false [junit4] 2> 103555 T170 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory [junit4] 2> 103555 T170 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)] [junit4] 2> 103555 T170 oasc.CoreContainer.load Host Name: 127.0.0.1 [junit4] 2> 103556 T170 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:48179/solr [junit4] 2> 103556 T170 oasc.ZkController.checkChrootPath zkHost includes chroot [junit4] 2> 103556 T170 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider [junit4] 2> 103557 T170 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 103559 T228 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7df33565 name:ZooKeeperConnection Watcher:127.0.0.1:48179 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 103560 T170 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 103560 T170 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider [junit4] 2> 103562 T170 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 103564 T230 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7a9c0d0a name:ZooKeeperConnection Watcher:127.0.0.1:48179/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 103564 T170 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 103573 T170 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... [junit4] 2> 104581 T170 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:48191_iv%2Fdh [junit4] 2> 104583 T170 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:48191_iv%2Fdh [junit4] 2> 104589 T170 oasc.Overseer.close Overseer (id=null) closing [junit4] 2> 104596 T170 oass.SolrDispatchFilter.init user.dir=/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.x/solr/build/solr-core/test/J3 [junit4] 2> 104596 T170 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done [junit4] 2> 105850 T170 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 3 [junit4] 2> 105850 T170 oejs.Server.doStart jetty-8.1.10.v20130312 [junit4] 2> 105853 T170 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:48194 [junit4] 2> 105853 T170 oass.SolrDispatchFilter.init SolrDispatchFilter.init() [junit4] 2> 105854 T170 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx) [junit4] 2> 105854 T170 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../../usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.x/solr/build/solr-core/test/J3/temp/solr.cloud.CollectionsAPIDistributedZkTest-B5A13DAD736935A-001/tempDir-005 [junit4] 2> 105854 T170 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.x/solr/build/solr-core/test/J3/temp/solr.cloud.CollectionsAPIDistributedZkTest-B5A13DAD736935A-001/tempDir-005/' [junit4] 2> 105884 T170 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.x/solr/build/solr-core/test/J3/../../../../../../../../../../../usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.x/solr/build/solr-core/test/J3/temp/solr.cloud.CollectionsAPIDistributedZkTest-B5A13DAD736935A-001/tempDir-005/solr.xml [junit4] 2> 105941 T170 oasc.CoreContainer.<init> New CoreContainer 46096765 [junit4] 2> 105941 T170 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../../usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.x/solr/build/solr-core/test/J3/temp/solr.cloud.CollectionsAPIDistributedZkTest-B5A13DAD736935A-001/tempDir-005/] [junit4] 2> 105942 T170 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000 [junit4] 2> 105942 T170 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: null [junit4] 2> 105943 T170 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000 [junit4] 2> 105943 T170 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20 [junit4] 2> 105943 T170 oashc.HttpShardHandlerFactory.getParameter Setting maxConnections to: 10000 [junit4] 2> 105943 T170 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0 [junit4] 2> 105944 T170 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647 [junit4] 2> 105944 T170 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5 [junit4] 2> 105944 T170 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1 [junit4] 2> 105944 T170 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false [junit4] 2> 105945 T170 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: socketTimeout=3400000&connTimeout=45000&retry=false [junit4] 2> 105945 T170 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory [junit4] 2> 105946 T170 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)] [junit4] 2> 105946 T170 oasc.CoreContainer.load Host Name: 127.0.0.1 [junit4] 2> 105946 T170 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:48179/solr [junit4] 2> 105946 T170 oasc.ZkController.checkChrootPath zkHost includes chroot [junit4] 2> 105947 T170 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider [junit4] 2> 105947 T170 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 105950 T243 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@629956f3 name:ZooKeeperConnection Watcher:127.0.0.1:48179 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 105950 T170 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 105950 T170 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider [junit4] 2> 105953 T170 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 105955 T245 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2435968a name:ZooKeeperConnection Watcher:127.0.0.1:48179/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 105955 T170 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 105965 T170 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... [junit4] 2> 106974 T170 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:48194_iv%2Fdh [junit4] 2> 106976 T170 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:48194_iv%2Fdh [junit4] 2> 106982 T170 oasc.Overseer.close Overseer (id=null) closing [junit4] 2> 106990 T170 oass.SolrDispatchFilter.init user.dir=/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.x/solr/build/solr-core/test/J3 [junit4] 2> 106990 T170 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done [junit4] 2> 108242 T170 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 4 [junit4] 2> 108243 T170 oejs.Server.doStart jetty-8.1.10.v20130312 [junit4] 2> 108245 T170 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:48197 [junit4] 2> 108246 T170 oass.SolrDispatchFilter.init SolrDispatchFilter.init() [junit4] 2> 108246 T170 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx) [junit4] 2> 108246 T170 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../../usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.x/solr/build/solr-core/test/J3/temp/solr.cloud.CollectionsAPIDistributedZkTest-B5A13DAD736935A-001/tempDir-006 [junit4] 2> 108247 T170 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.x/solr/build/solr-core/test/J3/temp/solr.cloud.CollectionsAPIDistributedZkTest-B5A13DAD736935A-001/tempDir-006/' [junit4] 2> 108276 T170 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.x/solr/build/solr-core/test/J3/../../../../../../../../../../../usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.x/solr/build/solr-core/test/J3/temp/solr.cloud.CollectionsAPIDistributedZkTest-B5A13DAD736935A-001/tempDir-006/solr.xml [junit4] 2> 108384 T170 oasc.CoreContainer.<init> New CoreContainer 1031298825 [junit4] 2> 108385 T170 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../../usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.x/solr/build/solr-core/test/J3/temp/solr.cloud.CollectionsAPIDistributedZkTest-B5A13DAD736935A-001/tempDir-006/] [junit4] 2> 108386 T170 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000 [junit4] 2> 108387 T170 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: null [junit4] 2> 108387 T170 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000 [junit4] 2> 108388 T170 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20 [junit4] 2> 108388 T170 oashc.HttpShardHandlerFactory.getParameter Setting maxConnections to: 10000 [junit4] 2> 108388 T170 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0 [junit4] 2> 108389 T170 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647 [junit4] 2> 108389 T170 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5 [junit4] 2> 108390 T170 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1 [junit4] 2> 108390 T170 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false [junit4] 2> 108391 T170 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: socketTimeout=3400000&connTimeout=45000&retry=false [junit4] 2> 108391 T170 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory [junit4] 2> 108392 T170 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)] [junit4] 2> 108392 T170 oasc.CoreContainer.load Host Name: 127.0.0.1 [junit4] 2> 108393 T170 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:48179/solr [junit4] 2> 108393 T170 oasc.ZkController.checkChrootPath zkHost includes chroot [junit4] 2> 108393 T170 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider [junit4] 2> 108395 T170 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 108397 T258 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@29a76766 name:ZooKeeperConnection Watcher:127.0.0.1:48179 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 108398 T170 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 108398 T170 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider [junit4] 2> 108401 T170 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 108403 T260 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7b7ca312 name:ZooKeeperConnection Watcher:127.0.0.1:48179/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 108403 T170 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 108412 T170 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... [junit4] 2> 109421 T170 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:48197_iv%2Fdh [junit4] 2> 109423 T170 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:48197_iv%2Fdh [junit4] 2> 109429 T170 oasc.Overseer.close Overseer (id=null) closing [junit4] 2> 109437 T170 oass.SolrDispatchFilter.init user.dir=/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.x/solr/build/solr-core/test/J3 [junit4] 2> 109437 T170 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done [junit4] 2> 109452 T205 oasha.CollectionsHandler.handleCreateAction Creating Collection : name=solrj_collection&wt=javabin&replicationFactor=2&version=2&collection.configName=conf1&action=CREATE&numShards=2&router.field=myOwnField [junit4] 2> 109454 T201 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/collection-queue-work state: SyncConnected type NodeChildrenChanged [junit4] 2> 109456 T194 oasc.OverseerCollectionProcessor.run Overseer Collection Processor: Get the message id:/overseer/collection-queue-work/qn-0000000000 message:{ [junit4] 2> "operation":"create", [junit4] 2> "fromApi":"true", [junit4] 2> "name":"solrj_collection", [junit4] 2> "replicationFactor":"2", [junit4] 2> "collection.configName":"conf1", [junit4] 2> "numShards":"2", [junit4] 2> "router.field":"myOwnField"} [junit4] 2> 109463 T263 oasc.OverseerCollectionProcessor.processMessage WARN OverseerCollectionProcessor.processMessage : create , { [junit4] 2> "operation":"create", [junit4] 2> "fromApi":"true", [junit4] 2> "name":"solrj_collection", [junit4] 2> "replicationFactor":"2", [junit4] 2> "collection.configName":"conf1", [junit4] 2> "numShards":"2", [junit4] 2> "router.field":"myOwnField"} [junit4] 2> 109470 T263 oasc.OverseerCollectionProcessor.createConfNode creating collections conf node /collections/solrj_collection [junit4] 2> 109471 T263 oascc.SolrZkClient.makePath makePath: /collections/solrj_collection [junit4] 2> 109477 T201 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 109483 T193 oasc.Overseer$ClusterStateUpdater.buildCollection building a new collection: solrj_collection [junit4] 2> 109484 T193 oasc.Overseer$ClusterStateUpdater.createCollection Create collection solrj_collection with shards [shard1, shard2] [junit4] 2> 109484 T193 oasc.Overseer$ClusterStateUpdater.createCollection state version solrj_collection 1 [junit4] 2> 109489 T216 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5) [junit4] 2> 109490 T231 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5) [junit4] 2> 109490 T246 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5) [junit4] 2> 109489 T261 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5) [junit4] 2> 109489 T202 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5) [junit4] 2> 109489 T201 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5) [junit4] 2> 109578 T263 oasc.OverseerCollectionProcessor.createCollection Creating SolrCores for new collection solrj_collection, shardNames [shard1, shard2] , replicationFactor : 2 [junit4] 2> 109579 T263 oasc.OverseerCollectionProcessor.createCollection Creating shard solrj_collection_shard1_replica1 as part of slice shard1 of collection solrj_collection on 127.0.0.1:48197_iv%2Fdh [junit4] 2> 109580 T263 oasc.OverseerCollectionProcessor.createCollection Creating shard solrj_collection_shard1_replica2 as part of slice shard1 of collection solrj_collection on 127.0.0.1:48188_iv%2Fdh [junit4] 2> 109582 T263 oasc.OverseerCollectionProcessor.createCollection Creating shard solrj_collection_shard2_replica1 as part of slice shard2 of collection solrj_collection on 127.0.0.1:48183_iv%2Fdh [junit4] 2> 109583 T263 oasc.OverseerCollectionProcessor.createCollection Creating shard solrj_collection_shard2_replica2 as part of slice shard2 of collection solrj_collection on 127.0.0.1:48194_iv%2Fdh [junit4] 2> 109585 T207 oasha.CoreAdminHandler.handleCreateAction core create command name=solrj_collection_shard1_replica2&wt=javabin&shard=shard1&collection=solrj_collection&version=2&collection.configName=conf1&action=CREATE&qt=/admin/cores&numShards=2 [junit4] 2> 109585 T250 oasha.CoreAdminHandler.handleCreateAction core create command name=solrj_collection_shard1_replica1&wt=javabin&shard=shard1&collection=solrj_collection&version=2&collection.configName=conf1&action=CREATE&qt=/admin/cores&numShards=2 [junit4] 2> 109587 T182 oasha.CoreAdminHandler.handleCreateAction core create command name=solrj_collection_shard2_replica1&wt=javabin&shard=shard2&collection=solrj_collection&version=2&collection.configName=conf1&action=CREATE&qt=/admin/cores&numShards=2 [junit4] 2> 109588 T235 oasha.CoreAdminHandler.handleCreateAction core create command name=solrj_collection_shard2_replica2&wt=javabin&shard=shard2&collection=solrj_collection&version=2&collection.configName=conf1&action=CREATE&qt=/admin/cores&numShards=2 [junit4] 2> 109604 T250 oasc.ZkController.publish publishing core=solrj_collection_shard1_replica1 state=down collection=solrj_collection [junit4] 2> 109604 T182 oasc.ZkController.publish publishing core=solrj_collection_shard2_replica1 state=down collection=solrj_collection [junit4] 2> 109604 T235 oasc.ZkController.publish publishing core=solrj_collection_shard2_replica2 state=down collection=solrj_collection [junit4] 2> 109604 T207 oasc.ZkController.publish publishing core=solrj_collection_shard1_replica2 state=down collection=solrj_collection [junit4] 2> 109613 T201 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 109613 T250 oasc.ZkController.waitForCoreNodeName look for our core node name [junit4] 2> 109613 T235 oasc.ZkController.waitForCoreNodeName look for our core node name [junit4] 2> 109613 T207 oasc.ZkController.waitForCoreNodeName look for our core node name [junit4] 2> 109614 T182 oasc.ZkController.waitForCoreNodeName look for our core node name [junit4] 2> 109625 T193 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={ [junit4] 2> "node_name":"127.0.0.1:48197_iv%2Fdh", [junit4] 2> "roles":null, [junit4] 2> "shard":"shard1", [junit4] 2> "core":"solrj_collection_shard1_replica1", [junit4] 2> "collection":"solrj_collection", [junit4] 2> "state":"down", [junit4] 2> "base_url":"http://127.0.0.1:48197/iv/dh", [junit4] 2> "numShards":"2", [junit4] 2> "operation":"state"} [junit4] 2> 109637 T193 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={ [junit4] 2> "node_name":"127.0.0.1:48188_iv%2Fdh", [junit4] 2> "roles":null, [junit4] 2> "shard":"shard1", [junit4] 2> "core":"solrj_collection_shard1_replica2", [junit4] 2> "collection":"solrj_collection", [junit4] 2> "state":"down", [junit4] 2> "base_url":"http://127.0.0.1:48188/iv/dh", [junit4] 2> "numShards":"2", [junit4] 2> "operation":"state"} [junit4] 2> 109641 T201 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 109643 T193 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={ [junit4] 2> "node_name":"127.0.0.1:48194_iv%2Fdh", [junit4] 2> "roles":null, [junit4] 2> "shard":"shard2", [junit4] 2> "core":"solrj_collection_shard2_replica2", [junit4] 2> "collection":"solrj_collection", [junit4] 2> "state":"down", [junit4] 2> "base_url":"http://127.0.0.1:48194/iv/dh", [junit4] 2> "numShards":"2", [junit4] 2> "operation":"state"} [junit4] 2> 109648 T193 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={ [junit4] 2> "node_name":"127.0.0.1:48183_iv%2Fdh", [junit4] 2> "roles":null, [junit4] 2> "shard":"shard2", [junit4] 2> "core":"solrj_collection_shard2_replica1", [junit4] 2> "collection":"solrj_collection", [junit4] 2> "state":"down", [junit4] 2> "base_url":"http://127.0.0.1:48183/iv/dh", [junit4] 2> "numShards":"2", [junit4] 2> "operation":"state"} [junit4] 2> 109652 T201 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 109655 T261 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5) [junit4] 2> 109655 T231 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5) [junit4] 2> 109655 T201 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5) [junit4] 2> 109655 T202 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5) [junit4] 2> 109655 T246 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5) [junit4] 2> 109655 T216 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5) [junit4] 2> 110615 T207 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for solrj_collection_shard1_replica2 [junit4] 2> 110615 T250 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for solrj_collection_shard1_replica1 [junit4] 2> 110615 T235 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for solrj_collection_shard2_replica2 [junit4] 2> 110616 T250 oasc.ZkController.createCollectionZkNode Check for collection zkNode:solrj_collection [junit4] 2> 110615 T182 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for solrj_collection_shard2_replica1 [junit4] 2> 110615 T207 oasc.ZkController.createCollectionZkNode Check for collection zkNode:solrj_collection [junit4] 2> 110617 T250 oasc.ZkController.createCollectionZkNode Collection zkNode exists [junit4] 2> 110617 T182 oasc.ZkController.createCollectionZkNode Check for collection zkNode:solrj_collection [junit4] 2> 110616 T235 oasc.ZkController.createCollectionZkNode Check for collection zkNode:solrj_collection [junit4] 2> 110618 T207 oasc.ZkController.createCollectionZkNode Collection zkNode exists [junit4] 2> 110619 T207 oascc.ZkStateReader.readConfigName Load collection config from:/collections/solrj_collection [junit4] 2> 110618 T250 oascc.ZkStateReader.readConfigName Load collection config from:/collections/solrj_collection [junit4] 2> 110619 T235 oasc.ZkController.createCollectionZkNode Collection zkNode exists [junit4] 2> 110619 T182 oasc.ZkController.createCollectionZkNode Collection zkNode exists [junit4] 2> 110620 T207 oascc.ZkStateReader.readConfigName path=/collections/solrj_collection configName=conf1 specified config exists in ZooKeeper [junit4] 2> 110620 T235 oascc.ZkStateReader.readConfigName Load collection config from:/collections/solrj_collection [junit4] 2> 110620 T250 oascc.ZkStateReader.readConfigName path=/collections/solrj_collection configName=conf1 specified config exists in ZooKeeper [junit4] 2> 110620 T182 oascc.ZkStateReader.readConfigName Load collection config from:/collections/solrj_collection [junit4] 2> 110622 T250 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.x/solr/build/solr-core/test/J3/temp/solr.cloud.CollectionsAPIDistributedZkTest-B5A13DAD736935A-001/tempDir-006/solrj_collection_shard1_replica1/' [junit4] 2> 110621 T207 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.x/solr/build/solr-core/test/J3/temp/solr.cloud.CollectionsAPIDistributedZkTest-B5A13DAD736935A-001/tempDir-003/solrj_collection_shard1_replica2/' [junit4] 2> 110623 T182 oascc.ZkStateReader.readConfigName path=/collections/solrj_collection configName=conf1 specified config exists in ZooKeeper [junit4] 2> 110622 T235 oascc.ZkStateReader.readConfigName path=/collections/solrj_collection configName=conf1 specified config exists in ZooKeeper [junit4] 2> 110623 T182 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.x/solr/build/solr-core/test/J3/temp/solr.cloud.CollectionsAPIDistributedZkTest-B5A13DAD736935A-001/tempDir-002/solrj_collection_shard2_replica1/' [junit4] 2> 110624 T235 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.x/solr/build/solr-core/test/J3/temp/solr.cloud.CollectionsAPIDistributedZkTest-B5A13DAD736935A-001/tempDir-005/solrj_collection_shard2_replica2/' [junit4] 2> 110689 T250 oasc.SolrConfig.<init> Using Lucene MatchVersion: 5.0.0 [junit4] 2> 110695 T235 oasc.SolrConfig.<init> Using Lucene MatchVersion: 5.0.0 [junit4] 2> 110699 T182 oasc.SolrConfig.<init> Using Lucene MatchVersion: 5.0.0 [junit4] 2> 110714 T207 oasc.SolrConfig.<init> Using Lucene MatchVersion: 5.0.0 [junit4] 2> 110766 T250 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml [junit4] 2> 110768 T250 oass.IndexSchema.readSchema Reading Solr Schema from /configs/conf1/schema.xml [junit4] 2> 110775 T182 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml [junit4] 2> 110776 T182 oass.IndexSchema.readSchema Reading Solr Schema from /configs/conf1/schema.xml [junit4] 2> 110777 T235 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml [junit4] 2> 110779 T235 oass.IndexSchema.readSchema Reading Solr Schema from /configs/conf1/schema.xml [junit4] 2> 110785 T250 oass.IndexSchema.readSchema [solrj_collection_shard1_replica1] Schema name=test [junit4] 2> 110786 T207 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml [junit4] 2> 110788 T207 oass.IndexSchema.readSchema Reading Solr Schema from /configs/conf1/schema.xml [junit4] 2> 110792 T182 oass.IndexSchema.readSchema [solrj_collection_shard2_replica1] Schema name=test [junit4] 2> 110796 T235 oass.IndexSchema.readSchema [solrj_collection_shard2_replica2] Schema name=test [junit4] 2> 110802 T207 oass.IndexSchema.readSchema [solrj_collection_shard1_replica2] Schema name=test [junit4] 2> 111275 T182 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440. [junit4] 2> 111279 T235 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440. [junit4] 2> 111283 T207 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440. [junit4] 2> 111289 T182 oass.IndexSchema.readSchema default search field in schema is text [junit4] 2> 111290 T235 oass.IndexSchema.readSchema default search field in schema is text [junit4] 2> 111292 T250 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440. [junit4] 2> 111293 T182 oass.IndexSchema.readSchema unique key field: id [junit4] 2> 111293 T235 oass.IndexSchema.readSchema unique key field: id [junit4] 2> 111295 T207 oass.IndexSchema.readSchema default search field in schema is text [junit4] 2> 111298 T207 oass.IndexSchema.readSchema unique key field: id [junit4] 2> 111302 T250 oass.IndexSchema.readSchema default search field in schema is text [junit4] 2> 111306 T250 oass.IndexSchema.readSchema unique key field: id [junit4] 2> 111324 T235 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml [junit4] 2> 111325 T182 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml [junit4] 2> 111329 T207 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml [junit4] 2> 111330 T235 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml [junit4] 2> 111333 T250 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml [junit4] 2> 111334 T182 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml [junit4] 2> 111335 T207 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml [junit4] 2> 111336 T235 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json [junit4] 2> 111337 T235 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE [junit4] 2> 111340 T235 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING [junit4] 2> 111340 T250 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml [junit4] 2> 111340 T235 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json [junit4] 2> 111342 T235 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE [junit4] 2> 111342 T235 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING [junit4] 2> 111342 T182 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json [junit4] 2> 111343 T235 oasc.CoreContainer.create Creating SolrCore 'solrj_collection_shard2_replica2' using configuration from collection solrj_collection [junit4] 2> 111343 T207 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json [junit4] 2> 111344 T235 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory [junit4] 2> 111344 T182 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE [junit4] 2> 111345 T235 oasc.SolrCore.<init> [solrj_collection_shard2_replica2] Opening new SolrCore at ../../../../../../../../../../../usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.x/solr/build/solr-core/test/J3/temp/solr.cloud.CollectionsAPIDistributedZkTest-B5A13DAD736935A-001/tempDir-005/solrj_collection_shard2_replica2/, dataDir=/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.x/solr/build/solr-core/test/J3/../../../../../../../../../../../usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.x/solr/build/solr-core/test/J3/temp/solr.cloud.CollectionsAPIDistributedZkTest-B5A13DAD736935A-001/tempDir-005/solrj_collection_shard2_replica2/data/ [junit4] 2> 111346 T207 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE [junit4] 2> 111346 T182 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING [junit4] 2> 111347 T250 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json [junit4] 2> 111347 T207 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING [junit4] 2> 111347 T235 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@d7b3d24 [junit4] 2> 111348 T207 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json [junit4] 2> 111347 T182 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json [junit4] 2> 111349 T250 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE [junit4] 2> 111350 T250 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING [junit4] 2> 111350 T207 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE [junit4] 2> 111350 T250 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json [junit4] 2> 111350 T182 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE [junit4] 2> 111351 T207 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING [junit4] 2> 111352 T250 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE [junit4] 2> 111352 T182 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING [junit4] 2> 111353 T250 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING [junit4] 2> 111352 T207 oasc.CoreContainer.create Creating SolrCore 'solrj_collection_shard1_replica2' using configuration from collection solrj_collection [junit4] 2> 111354 T250 oasc.CoreContainer.create Creating SolrCore 'solrj_collection_shard1_replica1' using configuration from collection solrj_collection [junit4] 2> 111353 T182 oasc.CoreContainer.create Creating SolrCore 'solrj_collection_shard2_replica1' using configuration from collection solrj_collection [junit4] 2> 111354 T250 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory [junit4] 2> 111354 T207 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory [junit4] 2> 111355 T250 oasc.SolrCore.<init> [solrj_collection_shard1_replica1] Opening new SolrCore at ../../../../../../../../../../../usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.x/solr/build/solr-core/test/J3/temp/solr.cloud.CollectionsAPIDistributedZkTest-B5A13DAD736935A-001/tempDir-006/solrj_collection_shard1_replica1/, dataDir=/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.x/solr/build/solr-core/test/J3/../../../../../../../../../../../usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.x/solr/build/solr-core/test/J3/temp/solr.cloud.CollectionsAPIDistributedZkTest-B5A13DAD736935A-001/tempDir-006/solrj_collection_shard1_replica1/data/ [junit4] 2> 111355 T182 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory [junit4] 2> 111357 T207 oasc.SolrCore.<init> [solrj_collection_shard1_replica2] Opening new SolrCore at ../../../../../../../../../../../usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.x/solr/build/solr-core/test/J3/temp/solr.cloud.CollectionsAPIDistributedZkTest-B5A13DAD736935A-001/tempDir-003/solrj_collection_shard1_replica2/, dataDir=/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.x/solr/build/solr-core/test/J3/../../../../../../../../../../../usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.x/solr/build/solr-core/test/J3/temp/solr.cloud.CollectionsAPIDistributedZkTest-B5A13DAD736935A-001/tempDir-003/solrj_collection_shard1_replica2/data/ [junit4] 2> 111357 T250 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@d7b3d24 [junit4] 2> 111358 T207 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@d7b3d24 [junit4] 2> 111358 T235 oasc.CachingDirectoryFactory.get return new directory for /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.x/solr/build/solr-core/test/J3/../../../../../../../../../../../usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.x/solr/build/solr-core/test/J3/temp/solr.cloud.CollectionsAPIDistributedZkTest-B5A13DAD736935A-001/tempDir-005/solrj_collection_shard2_replica2/data [junit4] 2> 111357 T182 oasc.SolrCore.<init> [solrj_collection_shard2_replica1] Opening new SolrCore at /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.x/solr/build/solr-core/test/J3/temp/solr.cloud.CollectionsAPIDistributedZkTest-B5A13DAD736935A-001/tempDir-002/solrj_collection_shard2_replica1/, dataDir=/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.x/solr/build/solr-core/test/J3/temp/solr.cloud.CollectionsAPIDistributedZkTest-B5A13DAD736935A-001/tempDir-002/solrj_collection_shard2_replica1/data/ [junit4] 2> 111360 T235 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.x/solr/build/solr-core/test/J3/../../../../../../../../../../../usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.x/solr/build/solr-core/test/J3/temp/solr.cloud.CollectionsAPIDistributedZkTest-B5A13DAD736935A-001/tempDir-005/solrj_collection_shard2_replica2/data/index/ [junit4] 2> 111359 T250 oasc.CachingDirectoryFactory.get return new directory for /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.x/solr/build/solr-core/test/J3/../../../../../../../../../../../usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.x/solr/build/solr-core/test/J3/temp/solr.cloud.CollectionsAPIDistributedZkTest-B5A13DAD736935A-001/tempDir-006/solrj_collection_shard1_replica1/data [junit4] 2> 111360 T235 oasc.SolrCore.initIndex WARN [solrj_collection_shard2_replica2] Solr index directory '/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.x/solr/build/solr-core/test/J3/../../../../../../../../../../../usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.x/solr/build/solr-core/test/J3/temp/solr.cloud.CollectionsAPIDistributedZkTest-B5A13DAD736935A-001/tempDir-005/solrj_collection_shard2_replica2/data/index' doesn't exist. Creating new index... [junit4] 2> 111360 T207 oasc.CachingDirectoryFactory.get return new directory for /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.x/solr/build/solr-core/test/J3/../../../../../../../../../../../usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.x/solr/build/solr-core/test/J3/temp/solr.cloud.CollectionsAPIDistributedZkTest-B5A13DAD736935A-001/tempDir-003/solrj_collection_shard1_replica2/data [junit4] 2> 111360 T182 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@d7b3d24 [junit4] 2> 111362 T207 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.x/solr/build/solr-core/test/J3/../../../../../../../../../../../usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.x/solr/build/solr-core/test/J3/temp/solr.cloud.CollectionsAPIDistributedZkTest-B5A13DAD736935A-001/tempDir-003/solrj_collection_shard1_replica2/data/index/ [junit4] 2> 111362 T235 oasc.CachingDirectoryFactory.get return new directory for /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.x/solr/build/solr-core/test/J3/../../../../../../../../../../../usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.x/solr/build/solr-core/test/J3/temp/solr.cloud.CollectionsAPIDistributedZkTest-B5A13DAD736935A-001/tempDir-005/solrj_collection_shard2_replica2/data/index [junit4] 2> 111365 T182 oasc.CachingDirectoryFactory.get return new directory for /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.x/solr/build/solr-core/test/J3/temp/solr.cloud.CollectionsAPIDistributedZkTest-B5A13DAD736935A-001/tempDir-002/solrj_collection_shard2_replica1/data [junit4] 2> 111361 T250 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.x/solr/build/solr-core/test/J3/../../../../../../../../../../../usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.x/solr/build/solr-core/test/J3/temp/solr.cloud.CollectionsAPIDistributedZkTest-B5A13DAD736935A-001/tempDir-006/solrj_collection_shard1_replica1/data/index/ [junit4] 2> 111365 T182 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.x/solr/build/solr-core/test/J3/temp/solr.cloud.CollectionsAPIDistributedZkTest-B5A13DAD736935A-001/tempDir-002/solrj_collection_shard2_replica1/data/index/ [junit4] 2> 111365 T235 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=41, maxMergeAtOnceExplicit=19, maxMergedSegmentMB=93.4365234375, floorSegmentMB=1.7080078125, forceMergeDeletesPctAllowed=0.895545927665925, segmentsPerTier=7.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.19072077976595292 [junit4] 2> 111363 T207 oasc.SolrCore.initIndex WARN [solrj_collection_shard1_replica2] Solr index directory '/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.x/solr/build/solr-core/test/J3/../../../../../../../../../../../usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.x/solr/build/solr-core/test/J3/temp/solr.cloud.CollectionsAPIDistributedZkTest-B5A13DAD736935A-001/tempDir-003/solrj_collection_shard1_replica2/data/index' doesn't exist. Creating new index... [junit4] 2> 111366 T182 oasc.SolrCore.initIndex WARN [solrj_collection_shard2_replica1] Solr index directory '/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.x/solr/build/solr-core/test/J3/temp/solr.cloud.CollectionsAPIDistributedZkTest-B5A13DAD736935A-001/tempDir-002/solrj_collection_shard2_replica1/data/index' doesn't exist. Creating new index... [junit4] 2> 111366 T250 oasc.SolrCore.initIndex WARN [solrj_collection_shard1_replica1] Solr index directory '/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.x/solr/build/solr-core/test/J3/../../../../../../../../../../../usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.x/solr/build/solr-core/test/J3/temp/solr.cloud.CollectionsAPIDistributedZkTest-B5A13DAD736935A-001/tempDir-006/solrj_collection_shard1_replica1/data/index' doesn't exist. Creating new index... [junit4] 2> 111368 T182 oasc.CachingDirectoryFactory.get return new directory for /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.x/solr/build/solr-core/test/J3/temp/solr.cloud.CollectionsAPIDistributedZkTest-B5A13DAD736935A-001/tempDir-002/solrj_collection_shard2_replica1/data/index [junit4] 2> 111367 T207 oasc.CachingDirectoryFactory.get return new directory for /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.x/solr/build/solr-core/test/J3/../../../../../../../../../../../usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.x/solr/build/solr-core/test/J3/temp/solr.cloud.CollectionsAPIDistributedZkTest-B5A13DAD736935A-001/tempDir-003/solrj_collection_shard1_replica2/data/index [junit4] 2> 111367 T235 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1 [junit4] 2> commit{dir=BaseDirectoryWrapper(RAMDirectory(id=lucene-67dc87d9)),segFN=segments_1,generation=1} [junit4] 2> 111369 T207 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=41, maxMergeAtOnceExplicit=19, maxMergedSegmentMB=93.4365234375, floorSegmentMB=1.7080078125, forceMergeDeletesPctAllowed=0.895545927665925, segmentsPerTier=7.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.19072077976595292 [junit4] 2> 111369 T182 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=41, maxMergeAtOnceExplicit=19, maxMergedSegmentMB=93.4365234375, floorSegmentMB=1.7080078125, forceMergeDeletesPctAllowed=0.895545927665925, segmentsPerTier=7.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.19072077976595292 [junit4] 2> 111371 T207 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1 [junit4] 2> commit{dir=BaseDirectoryWrapper(RAMDirectory(id=lucene-378cd5fb)),segFN=segments_1,generation=1} [junit4] 2> 111368 T250 oasc.CachingDirectoryFactory.get return new directory for /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.x/solr/build/solr-core/test/J3/../../../../../../../../../../../usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.x/solr/build/solr-core/test/J3/temp/solr.cloud.CollectionsAPIDistributedZkTest-B5A13DAD736935A-001/tempDir-006/solrj_collection_shard1_replica1/data/index [junit4] 2> 111371 T182 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1 [junit4] 2> commit{dir=BaseDirectoryWrapper(RAMDirectory(id=lucene-768c5c9c)),segFN=segments_1,generation=1} [junit4] 2> 111371 T207 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1 [junit4] 2> 111370 T235 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1 [junit4] 2> 111372 T182 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1 [junit4] 2> 111372 T250 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=41, maxMergeAtOnceExplicit=19, maxMergedSegmentMB=93.4365234375, floorSegmentMB=1.7080078125, forceMergeDeletesPctAllowed=0.895545927665925, segmentsPerTier=7.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.19072077976595292 [junit4] 2> 111376 T250 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1 [junit4] 2> commit{dir=BaseDirectoryWrapper(RAMDirectory(id=lucene-584ab273)),segFN=segments_1,generation=1} [junit4] 2> 111376 T250 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1 [junit4] 2> 111395 T235 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib" [junit4] 2> 111396 T182 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib" [junit4] 2> 111395 T207 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib" [junit4] 2> 111398 T250 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib" [junit4] 2> 111470 T235 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe" [junit4] 2> 111470 T182 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe" [junit4] 2> 111470 T207 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe" [junit4] 2> 111470 T250 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe" [junit4] 2> 111472 T207 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe" [junit4] 2> 111471 T182 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe" [junit4] 2> 111471 T235 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe" [junit4] 2> 111473 T182 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig" [junit4] 2> 111472 T207 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig" [junit4] 2> 111472 T250 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe" [junit4] 2> 111474 T207 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig" [junit4] 2> 111474 T182 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig" [junit4] 2> 111473 T235 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig" [junit4] 2> 111475 T182 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit" [junit4] 2> 111475 T207 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit" [junit4] 2> 111476 T182 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit" [junit4] 2> 111477 T207 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit" [junit4] 2> 111474 T250 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig" [junit4] 2> 111477 T207 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit" [junit4] 2> 111477 T182 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit" [junit4] 2> 111475 T235 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig" [junit4] 2> 111478 T182 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default [junit4] 2> 111478 T207 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default [junit4] 2> 111478 T250 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig" [junit4] 2> 111479 T235 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit" [junit4] 2> 111481 T182 oasc.RequestHandlers.initHandlersFromConfig created /update/json: org.apache.solr.handler.UpdateRequestHandler [junit4] 2> 111480 T250 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit" [junit4] 2> 111481 T235 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit" [junit4] 2> 111481 T207 oasc.RequestHandlers.initHandlersFromConfig created /update/json: org.apache.solr.handler.UpdateRequestHandler [junit4] 2> 111482 T250 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit" [junit4] 2> 111482 T235 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit" [junit4] 2> 111482 T182 oasc.RequestHandlers.initHandlersFromConfig created /update/json/docs: org.apache.solr.handler.UpdateRequestHandler [junit4] 2> 111483 T207 oasc.RequestHandlers.initHandlersFromConfig created /update/json/docs: org.apache.solr.handler.UpdateRequestHandler [junit4] 2> 111483 T235 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default [junit4] 2> 111483 T250 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit" [junit4] 2> 111485 T182 oasc.RequestHandlers.initHandlersFromConfig created /update/csv: org.apache.solr.handler.UpdateRequestHandler [junit4] 2> 111485 T207 oasc.RequestHandlers.initHandlersFromConfig created /update/csv: org.apache.solr.handler.UpdateRequestHandler [junit4] 2> 111485 T250 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default [junit4] 2> 111485 T235 oasc.RequestHandlers.initHandlersFromConfig created /update/json: org.apache.solr.handler.UpdateRequestHandler [junit4] 2> 111486 T182 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler [junit4] 2> 111487 T207 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler [junit4] 2> 111487 T250 oasc.RequestHandlers.initHandlersFromConfig created /update/json: org.apache.solr.handler.UpdateRequestHandler [junit4] 2> 111487 T235 oasc.RequestHandlers.initHandlersFromConfig created /update/json/docs: org.apache.solr.handler.UpdateRequestHandler [junit4] 2> 111488 T207 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler [junit4] 2> 111488 T207 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler [junit4] 2> 111488 T182 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler [junit4] 2> 111489 T207 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler [junit4] 2> 111489 T235 oasc.RequestHandlers.initHandlersFromConfig created /update/csv: org.apache.solr.handler.UpdateRequestHandler [junit4] 2> 111489 T250 oasc.RequestHandlers.initHandlersFromConfig created /update/json/docs: org.apache.solr.handler.UpdateRequestHandler [junit4] 2> 111489 T182 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler [junit4] 2> 111490 T207 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler [junit4] 2> 111491 T182 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler [junit4] 2> 111491 T235 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler [junit4] 2> 111492 T207 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers [junit4] 2> 111491 T250 oasc.RequestHandlers.initHandlersFromConfig created /update/csv: org.apache.solr.handler.UpdateRequestHandler [junit4] 2> 111492 T182 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler [junit4] 2> 111493 T207 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler [junit4] 2> 111494 T250 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler [junit4] 2> 111494 T182 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers [junit4] 2> 111494 T235 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler [junit4] 2> 111495 T207 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler [junit4] 2> 111495 T250 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler [junit4] 2> 111496 T250 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler [junit4] 2> 111495 T235 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler [junit4] 2> 111497 T250 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler [junit4] 2> 111496 T182 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler [junit4] 2> 111497 T235 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler [junit4] 2> 111498 T250 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler [junit4] 2> 111498 T182 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler [junit4] 2> 111499 T235 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler [junit4] 2> 111499 T250 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers [junit4] 2> 111500 T235 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers [junit4] 2> 111501 T250 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler [junit4] 2> 111501 T235 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler [junit4] 2> 111503 T250 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler [junit4] 2> 111503 T235 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler [junit4] 2> 111528 T207 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60 [junit4] 2> 111528 T235 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60 [junit4] 2> 111528 T250 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60 [junit4] 2> 111528 T182 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60 [junit4] 2> 111531 T207 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60 [junit4] 2> 111531 T235 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60 [junit4] 2> 111532 T182 oashl.XMLLoader.init x [...truncated too long message...] sr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.x/solr/build/solr-core/test/J3/temp/solr.cloud.DistribDocExpirationUpdateProcessorTest-B5A13DAD736935A-001/tempDir-001/jetty4/index [CachedDir<<refCount=0;path=/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.x/solr/build/solr-core/test/J3/temp/solr.cloud.DistribDocExpirationUpdateProcessorTest-B5A13DAD736935A-001/tempDir-001/jetty4/index;done=true>>] [junit4] 2> 3145634 T4250 oascc.ZkStateReader$7.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json, has occurred - updating... [junit4] 2> 3145634 T3323 oasc.CachingDirectoryFactory.close Closing directory: /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.x/solr/build/solr-core/test/J3/temp/solr.cloud.DistribDocExpirationUpdateProcessorTest-B5A13DAD736935A-001/tempDir-001/jetty4/index [junit4] 2> 3145634 T3179 oasc.Overseer.close Overseer (id=92697604223991822-127.0.0.1:46372_u%2Fp-n_0000000004) closing [junit4] 2> 3145635 T3323 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 1 directories currently being tracked [junit4] 2> 3145637 T4250 oascc.ZkStateReader.updateWatchedCollection Updating data for collection1 to ver 53 [junit4] 2> 3145637 T3323 oasc.CachingDirectoryFactory.closeCacheValue looking to close /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.x/solr/build/solr-core/test/J3/temp/solr.cloud.DistribDocExpirationUpdateProcessorTest-B5A13DAD736935A-001/tempDir-001/jetty4 [CachedDir<<refCount=0;path=/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.x/solr/build/solr-core/test/J3/temp/solr.cloud.DistribDocExpirationUpdateProcessorTest-B5A13DAD736935A-001/tempDir-001/jetty4;done=false>>] [junit4] 2> 3145635 T4257 oasc.Overseer$ClusterStateUpdater.amILeader According to ZK I (id=92697604223991822-127.0.0.1:46372_u%2Fp-n_0000000004) am no longer a leader. [junit4] 2> 3145638 T3323 oasc.CachingDirectoryFactory.close Closing directory: /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.x/solr/build/solr-core/test/J3/temp/solr.cloud.DistribDocExpirationUpdateProcessorTest-B5A13DAD736935A-001/tempDir-001/jetty4 [junit4] 2> 3145638 T4250 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK [junit4] 2> 3145639 T3323 oasc.LeaderElector$ElectionWatcher.process WARN org.apache.solr.common.SolrException: Fatal Error, SolrCore not found:collection1 in [] [junit4] 2> at org.apache.solr.cloud.ShardLeaderElectionContext.runLeaderProcess(ElectionContext.java:222) [junit4] 2> at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:162) [junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:124) [junit4] 2> at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:313) [junit4] 2> at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:220) [junit4] 2> at org.apache.solr.cloud.ShardLeaderElectionContext.rejoinLeaderElection(ElectionContext.java:466) [junit4] 2> at org.apache.solr.cloud.ShardLeaderElectionContext.runLeaderProcess(ElectionContext.java:229) [junit4] 2> at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:162) [junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:124) [junit4] 2> at org.apache.solr.cloud.LeaderElector.access$200(LeaderElector.java:55) [junit4] 2> at org.apache.solr.cloud.LeaderElector$ElectionWatcher.process(LeaderElector.java:357) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$3$1.run(SolrZkClient.java:266) [junit4] 2> at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471) [junit4] 2> at java.util.concurrent.FutureTask.run(FutureTask.java:262) [junit4] 2> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) [junit4] 2> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) [junit4] 2> at java.lang.Thread.run(Thread.java:745) [junit4] 2> [junit4] 2> 3145638 T4257 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:46372_u%2Fp [junit4] 2> 3145640 T3179 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/u/p,null} [junit4] 2> 3150395 T3179 oas.SolrTestCaseJ4.tearDown ###Ending testDistribSearch [junit4] 2> 3150398 T3179 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:20444 20444 [junit4] 2> 3150691 T3180 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:20444 20444 [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=DistribDocExpirationUpdateProcessorTest -Dtests.method=testDistribSearch -Dtests.seed=B5A13DAD736935A -Dtests.multiplier=2 -Dtests.nightly=true -Dtests.slow=true -Dtests.linedocsfile=/home/jenkins/lucene-data/enwiki.random.lines.txt -Dtests.locale=it -Dtests.timezone=Atlantic/Faeroe -Dtests.asserts=true -Dtests.file.encoding=UTF-8 [junit4] FAILURE 121s J3 | DistribDocExpirationUpdateProcessorTest.testDistribSearch <<< [junit4] > Throwable #1: java.lang.AssertionError: There are still nodes recoverying - waited for 30 seconds [junit4] > at __randomizedtesting.SeedInfo.seed([B5A13DAD736935A:8ABC9DC2A069F366]:0) [junit4] > at org.apache.solr.cloud.AbstractDistribZkTestBase.waitForRecoveriesToFinish(AbstractDistribZkTestBase.java:178) [junit4] > at org.apache.solr.cloud.AbstractFullDistribZkTestBase.waitForRecoveriesToFinish(AbstractFullDistribZkTestBase.java:840) [junit4] > at org.apache.solr.cloud.AbstractFullDistribZkTestBase.waitForThingsToLevelOut(AbstractFullDistribZkTestBase.java:1459) [junit4] > at org.apache.solr.cloud.DistribDocExpirationUpdateProcessorTest.doTest(DistribDocExpirationUpdateProcessorTest.java:79) [junit4] > at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:869) [junit4] > at java.lang.Thread.run(Thread.java:745) [junit4] 2> 3150701 T3179 oas.SolrTestCaseJ4.deleteCore ###deleteCore [junit4] 2> NOTE: leaving temporary files on disk at: /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.x/solr/build/solr-core/test/J3/temp/solr.cloud.DistribDocExpirationUpdateProcessorTest-B5A13DAD736935A-001 [junit4] 2> 120968 T3178 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 1 leaked thread(s). [junit4] 2> NOTE: test params are: codec=Asserting(Lucene50): {id=PostingsFormat(name=LuceneVarGapFixedInterval), _version_=FST50}, docValues:{}, sim=RandomSimilarityProvider(queryNorm=false,coord=yes): {}, locale=it, timezone=Atlantic/Faeroe [junit4] 2> NOTE: FreeBSD 9.1-RELEASE-p3 amd64/Oracle Corporation 1.7.0_65 (64-bit)/cpus=16,threads=1,free=131202928,total=337641472 [junit4] 2> NOTE: All tests run in this JVM: [EchoParamsTest, TestOverriddenPrefixQueryForCustomFieldType, SolrIndexSplitterTest, TestSearchPerf, TestInfoStreamLogging, ModifyConfFileTest, DistributedFacetPivotLongTailTest, SolrInfoMBeanTest, TestNonNRTOpen, TermVectorComponentTest, TimeZoneUtilsTest, StandardRequestHandlerTest, CollectionsAPIDistributedZkTest, SuggesterTest, TestHighlightDedupGrouping, ShardSplitTest, FieldMutatingUpdateProcessorTest, TestFieldTypeResource, TestMergePolicyConfig, CollectionsAPIAsyncDistributedZkTest, SOLR749Test, OverseerRolesTest, ReplicationFactorTest, DocExpirationUpdateProcessorFactoryTest, FileBasedSpellCheckerTest, TestAnalyzeInfixSuggestions, DocValuesMultiTest, ResponseLogComponentTest, RemoteQueryErrorTest, SimpleFacetsTest, TestConfigSets, HdfsWriteToMultipleCollectionsTest, BadIndexSchemaTest, TestImplicitCoreProperties, TestShortCircuitedRequests, TestJoin, TestReplicaProperties, HdfsUnloadDistributedZkTest, OutputWriterTest, TestMiniSolrCloudCluster, UUIDFieldTest, TestDistributedMissingSort, SolrPluginUtilsTest, DistribDocExpirationUpdateProcessorTest] [junit4] Completed on J3 in 121.78s, 1 test, 1 failure <<< FAILURES! [...truncated 671 lines...] BUILD FAILED /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.x/build.xml:532: The following error occurred while executing this line: /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.x/build.xml:473: The following error occurred while executing this line: /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.x/build.xml:61: The following error occurred while executing this line: /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.x/extra-targets.xml:39: The following error occurred while executing this line: /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.x/solr/build.xml:189: The following error occurred while executing this line: /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.x/solr/common-build.xml:496: The following error occurred while executing this line: /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.x/lucene/common-build.xml:1359: The following error occurred while executing this line: /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.x/lucene/common-build.xml:966: There were test failures: 438 suites, 1800 tests, 1 error, 1 failure, 54 ignored (9 assumptions) Total time: 243 minutes 54 seconds Build step 'Invoke Ant' marked build as failure Archiving artifacts Sending artifact delta relative to Lucene-Solr-NightlyTests-5.x #654 Archived 5 artifacts Archive block size is 32768 Received 0 blocks and 491344509 bytes Compression is 0.0% Took 1 min 24 sec Recording test results Email was triggered for: Failure Sending email for trigger: Failure
--------------------------------------------------------------------- To unsubscribe, e-mail: dev-unsubscr...@lucene.apache.org For additional commands, e-mail: dev-h...@lucene.apache.org