You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2014/05/26 17:36:15 UTC
[JENKINS] Lucene-Solr-trunk-Windows (32bit/jdk1.8.0_05) - Build #
4066 - Failure!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Windows/4066/
Java: 32bit/jdk1.8.0_05 -server -XX:+UseSerialGC
1 tests failed.
REGRESSION: org.apache.solr.cloud.SyncSliceTest.testDistribSearch
Error Message:
No live SolrServers available to handle this request
Stack Trace:
org.apache.solr.client.solrj.SolrServerException: No live SolrServers available to handle this request
at __randomizedtesting.SeedInfo.seed([6D1AE3DB3CB11AFE:ECFC6DC34BEE7AC2]:0)
at org.apache.solr.client.solrj.impl.LBHttpSolrServer.request(LBHttpSolrServer.java:317)
at org.apache.solr.client.solrj.impl.CloudSolrServer.request(CloudSolrServer.java:650)
at org.apache.solr.client.solrj.request.QueryRequest.process(QueryRequest.java:91)
at org.apache.solr.client.solrj.SolrServer.query(SolrServer.java:301)
at org.apache.solr.cloud.AbstractFullDistribZkTestBase.checkShardConsistency(AbstractFullDistribZkTestBase.java:1141)
at org.apache.solr.cloud.AbstractFullDistribZkTestBase.checkShardConsistency(AbstractFullDistribZkTestBase.java:1110)
at org.apache.solr.cloud.SyncSliceTest.doTest(SyncSliceTest.java:236)
at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:863)
at sun.reflect.GeneratedMethodAccessor34.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:483)
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:360)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:793)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:453)
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:43)
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:360)
at java.lang.Thread.run(Thread.java:745)
Build Log:
[...truncated 11257 lines...]
[junit4] Suite: org.apache.solr.cloud.SyncSliceTest
[junit4] 2> Creating dataDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\temp\solr.cloud.SyncSliceTest-6D1AE3DB3CB11AFE-001\init-core-data-001
[junit4] 2> 2792314 T9325 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (false) and clientAuth (true)
[junit4] 2> 2792314 T9325 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
[junit4] 2> 2792321 T9325 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4] 2> 2792325 T9325 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 2792327 T9326 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 2792446 T9325 oasc.ZkTestServer.run start zk server on port:55206
[junit4] 2> 2792451 T9325 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2792459 T9332 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1b412aa name:ZooKeeperConnection Watcher:127.0.0.1:55206 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2792460 T9325 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2792460 T9325 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 2792468 T9327 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x146391473df0000, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 2792470 T9325 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2792474 T9334 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@f18baa name:ZooKeeperConnection Watcher:127.0.0.1:55206/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2792474 T9325 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2792475 T9325 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4] 2> 2792480 T9325 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4] 2> 2792485 T9325 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4] 2> 2792496 T9325 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4] 2> 2792502 T9325 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\core\src\test-files\solr\collection1\conf\solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4] 2> 2792502 T9325 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4] 2> 2792513 T9325 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\core\src\test-files\solr\collection1\conf\schema.xml to /configs/conf1/schema.xml
[junit4] 2> 2792514 T9325 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4] 2> 2792521 T9325 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\core\src\test-files\solr\collection1\conf\solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 2792521 T9325 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 2792528 T9325 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\core\src\test-files\solr\collection1\conf\stopwords.txt to /configs/conf1/stopwords.txt
[junit4] 2> 2792528 T9325 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4] 2> 2792534 T9325 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\core\src\test-files\solr\collection1\conf\protwords.txt to /configs/conf1/protwords.txt
[junit4] 2> 2792535 T9325 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4] 2> 2792541 T9325 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\core\src\test-files\solr\collection1\conf\currency.xml to /configs/conf1/currency.xml
[junit4] 2> 2792541 T9325 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4] 2> 2792547 T9325 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\core\src\test-files\solr\collection1\conf\enumsConfig.xml to /configs/conf1/enumsConfig.xml
[junit4] 2> 2792548 T9325 oascc.SolrZkClient.makePath makePath: /configs/conf1/enumsConfig.xml
[junit4] 2> 2792554 T9325 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\core\src\test-files\solr\collection1\conf\open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4] 2> 2792555 T9325 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4] 2> 2792562 T9325 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\core\src\test-files\solr\collection1\conf\mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 2792564 T9325 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 2792570 T9325 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\core\src\test-files\solr\collection1\conf\old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4] 2> 2792570 T9325 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4] 2> 2792577 T9325 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\core\src\test-files\solr\collection1\conf\synonyms.txt to /configs/conf1/synonyms.txt
[junit4] 2> 2792578 T9325 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4] 2> 2795130 T9325 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 2795146 T9325 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:55213
[junit4] 2> 2795147 T9325 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 2795147 T9325 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 2795147 T9325 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\temp\solr.cloud.SyncSliceTest-6D1AE3DB3CB11AFE-001\tempDir-002
[junit4] 2> 2795147 T9325 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\temp\solr.cloud.SyncSliceTest-6D1AE3DB3CB11AFE-001\tempDir-002\'
[junit4] 2> 2795190 T9325 oasc.ConfigSolr.fromFile Loading container configuration from C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\temp\solr.cloud.SyncSliceTest-6D1AE3DB3CB11AFE-001\tempDir-002\solr.xml
[junit4] 2> 2795204 T9325 oasc.CoreContainer.<init> New CoreContainer 27960997
[junit4] 2> 2795204 T9325 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\temp\solr.cloud.SyncSliceTest-6D1AE3DB3CB11AFE-001\tempDir-002\]
[junit4] 2> 2795207 T9325 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 2795207 T9325 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 2795207 T9325 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 2795207 T9325 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 2795207 T9325 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 2795207 T9325 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 2795210 T9325 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 2795210 T9325 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 2795210 T9325 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 2795210 T9325 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 2795210 T9325 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 2795212 T9325 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 2795212 T9325 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:55206/solr
[junit4] 2> 2795212 T9325 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 2795215 T9325 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2795237 T9345 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@466eaf name:ZooKeeperConnection Watcher:127.0.0.1:55206 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2795237 T9325 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2795240 T9327 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x146391473df0002, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 2795241 T9325 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2795245 T9347 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@8ee1ba name:ZooKeeperConnection Watcher:127.0.0.1:55206/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2795246 T9325 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2795248 T9325 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 2795257 T9325 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 2795263 T9325 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 2795274 T9325 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 2795292 T9325 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 2795299 T9325 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 2795303 T9325 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:55213_
[junit4] 2> 2795305 T9325 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:55213_
[junit4] 2> 2795310 T9325 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 2795314 T9325 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 2795324 T9325 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:55213_
[junit4] 2> 2795324 T9325 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 2795329 T9325 oasc.Overseer.start Overseer (id=91823602413797379-127.0.0.1:55213_-n_0000000000) starting
[junit4] 2> 2795337 T9325 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 2795361 T9325 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 2795361 T9349 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 2795367 T9325 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 2795371 T9325 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 2795377 T9348 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 2795381 T9350 oasc.ZkController.publish publishing core=collection1 state=down collection=control_collection
[junit4] 2> 2795381 T9350 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 2795383 T9347 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2795383 T9350 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 2795385 T9348 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2795386 T9348 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:55213",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:55213_",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"control_collection",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":null}
[junit4] 2> 2795387 T9348 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1]
[junit4] 2> 2795387 T9348 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 2795393 T9347 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2795394 T9347 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> 2796456 T9350 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 2796456 T9350 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4] 2> 2796457 T9350 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 2796457 T9350 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
[junit4] 2> 2796459 T9350 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 2796459 T9350 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\temp\solr.cloud.SyncSliceTest-6D1AE3DB3CB11AFE-001\tempDir-002\collection1\'
[junit4] 2> 2796462 T9350 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/temp/solr.cloud.SyncSliceTest-6D1AE3DB3CB11AFE-001/tempDir-002/collection1/lib/.svn/' to classloader
[junit4] 2> 2796464 T9350 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/temp/solr.cloud.SyncSliceTest-6D1AE3DB3CB11AFE-001/tempDir-002/collection1/lib/classes/' to classloader
[junit4] 2> 2796465 T9350 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/temp/solr.cloud.SyncSliceTest-6D1AE3DB3CB11AFE-001/tempDir-002/collection1/lib/README' to classloader
[junit4] 2> 2796523 T9350 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_5_0
[junit4] 2> 2796532 T9350 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 2796534 T9350 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 2796540 T9350 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 2796666 T9350 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 2796673 T9350 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 2796675 T9350 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 2796696 T9350 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 2796701 T9350 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 2796706 T9350 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 2796708 T9350 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 2796708 T9350 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 2796708 T9350 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 2796711 T9350 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 2796711 T9350 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 2796712 T9350 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection control_collection
[junit4] 2> 2796712 T9350 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 2796712 T9350 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\temp\solr.cloud.SyncSliceTest-6D1AE3DB3CB11AFE-001\tempDir-002\collection1\, dataDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\temp\solr.cloud.SyncSliceTest-6D1AE3DB3CB11AFE-001\tempDir-001/control/data\
[junit4] 2> 2796713 T9350 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@33105d
[junit4] 2> 2796714 T9350 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\temp\solr.cloud.SyncSliceTest-6D1AE3DB3CB11AFE-001\tempDir-001/control/data\
[junit4] 2> 2796714 T9350 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\temp\solr.cloud.SyncSliceTest-6D1AE3DB3CB11AFE-001\tempDir-001/control/data\index/
[junit4] 2> 2796714 T9350 oasc.SolrCore.initIndex WARN [collection1] Solr index directory 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\temp\solr.cloud.SyncSliceTest-6D1AE3DB3CB11AFE-001\tempDir-001\control\data\index' doesn't exist. Creating new index...
[junit4] 2> 2796715 T9350 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\temp\solr.cloud.SyncSliceTest-6D1AE3DB3CB11AFE-001\tempDir-001/control/data\index
[junit4] 2> 2796715 T9350 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=13, maxMergeAtOnceExplicit=20, maxMergedSegmentMB=1.2763671875, floorSegmentMB=1.744140625, forceMergeDeletesPctAllowed=7.573799454162802, segmentsPerTier=27.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 2796716 T9350 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@85f70 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@13d2069),segFN=segments_1,generation=1}
[junit4] 2> 2796716 T9350 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 2796720 T9350 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 2796721 T9350 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 2796721 T9350 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 2796721 T9350 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 2796723 T9350 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 2796723 T9350 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 2796724 T9350 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 2796724 T9350 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 2796724 T9350 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 2796725 T9350 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 2796726 T9350 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 2796726 T9350 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 2796726 T9350 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 2796727 T9350 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 2796727 T9350 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 2796728 T9350 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 2796728 T9350 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
[junit4] 2> 2796739 T9350 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 2796747 T9350 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 2796747 T9350 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 2796748 T9350 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=19, maxMergeAtOnceExplicit=40, maxMergedSegmentMB=20.6083984375, floorSegmentMB=1.2109375, forceMergeDeletesPctAllowed=0.4919785419199596, segmentsPerTier=27.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.42659321616318546
[junit4] 2> 2796749 T9350 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@85f70 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@13d2069),segFN=segments_1,generation=1}
[junit4] 2> 2796749 T9350 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 2796749 T9350 oass.SolrIndexSearcher.<init> Opening Searcher@3a17ed[collection1] main
[junit4] 2> 2796750 T9350 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
[junit4] 2> 2796752 T9350 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 2796752 T9350 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
[junit4] 2> 2796753 T9350 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 2796754 T9350 oasr.RestManager.init Initializing RestManager with initArgs: {}
[junit4] 2> 2796754 T9350 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 2796755 T9350 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
[junit4] 2> 2796756 T9350 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 2796756 T9350 oasr.ManagedResource.notifyObserversDuringInit WARN No registered observers for /rest/managed
[junit4] 2> 2796756 T9350 oasr.RestManager.init Initializing 0 registered ManagedResources
[junit4] 2> 2796759 T9351 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@3a17ed[collection1] main{UninvertingDirectoryReader()}
[junit4] 2> 2796761 T9350 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 2796763 T9354 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:55213 collection:control_collection shard:shard1
[junit4] 2> 2796763 T9325 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0
[junit4] 2> 2796764 T9325 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 2796766 T9354 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4] 2> 2796768 T9325 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2796772 T9356 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@17921b name:ZooKeeperConnection Watcher:127.0.0.1:55206/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2796773 T9325 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2796776 T9325 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 2796782 T9325 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:false
[junit4] 2> 2796783 T9354 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 2796788 T9347 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2796792 T9354 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 2796792 T9354 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> ASYNC NEW_CORE C3373 name=collection1 org.apache.solr.core.SolrCore@aae115 url=http://127.0.0.1:55213/collection1 node=127.0.0.1:55213_ C3373_STATE=coll:control_collection core:collection1 props:{state=down, base_url=http://127.0.0.1:55213, core=collection1, node_name=127.0.0.1:55213_}
[junit4] 2> 2796792 T9354 C3373 P55213 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:55213/collection1/
[junit4] 2> 2796792 T9354 C3373 P55213 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 2796792 T9354 C3373 P55213 oasc.SyncStrategy.syncToMe http://127.0.0.1:55213/collection1/ has no replicas
[junit4] 2> 2796794 T9354 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:55213/collection1/ shard1
[junit4] 2> 2796794 T9354 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4] 2> 2796797 T9348 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2796809 T9347 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2796816 T9347 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2796825 T9347 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2796937 T9347 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> 2796938 T9356 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> 2796984 T9354 oasc.ZkController.register We are http://127.0.0.1:55213/collection1/ and leader is http://127.0.0.1:55213/collection1/
[junit4] 2> 2796984 T9354 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:55213
[junit4] 2> 2796984 T9354 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 2796984 T9354 oasc.ZkController.publish publishing core=collection1 state=active collection=control_collection
[junit4] 2> 2796984 T9354 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 2796988 T9347 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2796988 T9347 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2796988 T9347 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2796992 T9354 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2796995 T9348 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2796997 T9348 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:55213",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:55213_",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"control_collection",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 2797003 T9347 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2797115 T9347 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> 2797116 T9356 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> 2798960 T9325 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 1
[junit4] 2> 2798962 T9325 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 2798966 T9325 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:55225
[junit4] 2> 2798966 T9325 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 2798966 T9325 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 2798966 T9325 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\temp\solr.cloud.SyncSliceTest-6D1AE3DB3CB11AFE-001\tempDir-003
[junit4] 2> 2798966 T9325 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\temp\solr.cloud.SyncSliceTest-6D1AE3DB3CB11AFE-001\tempDir-003\'
[junit4] 2> 2798999 T9325 oasc.ConfigSolr.fromFile Loading container configuration from C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\temp\solr.cloud.SyncSliceTest-6D1AE3DB3CB11AFE-001\tempDir-003\solr.xml
[junit4] 2> 2799011 T9325 oasc.CoreContainer.<init> New CoreContainer 19086017
[junit4] 2> 2799011 T9325 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\temp\solr.cloud.SyncSliceTest-6D1AE3DB3CB11AFE-001\tempDir-003\]
[junit4] 2> 2799013 T9325 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 2799013 T9325 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 2799013 T9325 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 2799013 T9325 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 2799013 T9325 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 2799013 T9325 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 2799015 T9325 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 2799015 T9325 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 2799015 T9325 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 2799015 T9325 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 2799015 T9325 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 2799017 T9325 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 2799017 T9325 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:55206/solr
[junit4] 2> 2799017 T9325 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 2799020 T9325 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2799055 T9367 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1fce4f4 name:ZooKeeperConnection Watcher:127.0.0.1:55206 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2799055 T9325 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2799061 T9325 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2799063 T9369 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1949555 name:ZooKeeperConnection Watcher:127.0.0.1:55206/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2799064 T9325 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2799077 T9325 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 2800153 T9325 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:55225_
[junit4] 2> 2800156 T9325 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:55225_
[junit4] 2> 2800170 T9370 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
[junit4] 2> 2800170 T9370 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 2800172 T9347 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2800172 T9347 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2800172 T9347 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2800172 T9370 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 2800174 T9348 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2800175 T9348 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:55225",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:55225_",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":null}
[junit4] 2> 2800175 T9348 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1]
[junit4] 2> 2800175 T9348 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 2800182 T9347 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2800184 T9369 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 2800184 T9356 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 2800184 T9347 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 2801245 T9370 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 2801245 T9370 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 2801248 T9370 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 2801249 T9370 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 2801252 T9370 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 2801252 T9370 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\temp\solr.cloud.SyncSliceTest-6D1AE3DB3CB11AFE-001\tempDir-003\collection1\'
[junit4] 2> 2801256 T9370 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/temp/solr.cloud.SyncSliceTest-6D1AE3DB3CB11AFE-001/tempDir-003/collection1/lib/.svn/' to classloader
[junit4] 2> 2801257 T9370 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/temp/solr.cloud.SyncSliceTest-6D1AE3DB3CB11AFE-001/tempDir-003/collection1/lib/classes/' to classloader
[junit4] 2> 2801257 T9370 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/temp/solr.cloud.SyncSliceTest-6D1AE3DB3CB11AFE-001/tempDir-003/collection1/lib/README' to classloader
[junit4] 2> 2801304 T9370 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_5_0
[junit4] 2> 2801313 T9370 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 2801315 T9370 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 2801320 T9370 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 2801430 T9370 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 2801438 T9370 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 2801438 T9370 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 2801458 T9370 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 2801462 T9370 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 2801466 T9370 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 2801468 T9370 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 2801469 T9370 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 2801469 T9370 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 2801470 T9370 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 2801470 T9370 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 2801470 T9370 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection collection1
[junit4] 2> 2801470 T9370 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 2801472 T9370 oasc.SolrCore.<init> [collection1] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\temp\solr.cloud.SyncSliceTest-6D1AE3DB3CB11AFE-001\tempDir-003\collection1\, dataDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\temp\solr.cloud.SyncSliceTest-6D1AE3DB3CB11AFE-001\tempDir-001/jetty1\
[junit4] 2> 2801472 T9370 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@33105d
[junit4] 2> 2801472 T9370 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\temp\solr.cloud.SyncSliceTest-6D1AE3DB3CB11AFE-001\tempDir-001/jetty1\
[junit4] 2> 2801472 T9370 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\temp\solr.cloud.SyncSliceTest-6D1AE3DB3CB11AFE-001\tempDir-001/jetty1\index/
[junit4] 2> 2801472 T9370 oasc.SolrCore.initIndex WARN [collection1] Solr index directory 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\temp\solr.cloud.SyncSliceTest-6D1AE3DB3CB11AFE-001\tempDir-001\jetty1\index' doesn't exist. Creating new index...
[junit4] 2> 2801473 T9370 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\temp\solr.cloud.SyncSliceTest-6D1AE3DB3CB11AFE-001\tempDir-001/jetty1\index
[junit4] 2> 2801474 T9370 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=13, maxMergeAtOnceExplicit=20, maxMergedSegmentMB=1.2763671875, floorSegmentMB=1.744140625, forceMergeDeletesPctAllowed=7.573799454162802, segmentsPerTier=27.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 2801474 T9370 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@a6ba88 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1c110eb),segFN=segments_1,generation=1}
[junit4] 2> 2801474 T9370 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 2801477 T9370 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 2801477 T9370 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 2801478 T9370 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 2801478 T9370 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 2801478 T9370 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 2801478 T9370 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 2801479 T9370 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 2801479 T9370 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 2801479 T9370 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 2801480 T9370 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 2801480 T9370 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 2801480 T9370 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 2801480 T9370 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 2801482 T9370 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 2801482 T9370 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 2801482 T9370 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 2801483 T9370 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
[junit4] 2> 2801486 T9370 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 2801491 T9370 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 2801491 T9370 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 2801491 T9370 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=19, maxMergeAtOnceExplicit=40, maxMergedSegmentMB=20.6083984375, floorSegmentMB=1.2109375, forceMergeDeletesPctAllowed=0.4919785419199596, segmentsPerTier=27.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.42659321616318546
[junit4] 2> 2801491 T9370 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@a6ba88 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1c110eb),segFN=segments_1,generation=1}
[junit4] 2> 2801491 T9370 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 2801491 T9370 oass.SolrIndexSearcher.<init> Opening Searcher@4d8f3c[collection1] main
[junit4] 2> 2801491 T9370 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 2801491 T9370 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 2801491 T9370 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
[junit4] 2> 2801491 T9370 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 2801491 T9370 oasr.RestManager.init Initializing RestManager with initArgs: {}
[junit4] 2> 2801491 T9370 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 2801491 T9370 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
[junit4] 2> 2801491 T9370 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 2801491 T9370 oasr.ManagedResource.notifyObserversDuringInit WARN No registered observers for /rest/managed
[junit4] 2> 2801494 T9370 oasr.RestManager.init Initializing 0 registered ManagedResources
[junit4] 2> 2801498 T9371 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@4d8f3c[collection1] main{UninvertingDirectoryReader()}
[junit4] 2> 2801500 T9370 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 2801502 T9374 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:55225 collection:collection1 shard:shard1
[junit4] 2> 2801503 T9325 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0
[junit4] 2> 2801503 T9325 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 2801504 T9374 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 2801519 T9374 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 2801523 T9347 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2801524 T9374 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 2801525 T9374 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> ASYNC NEW_CORE C3374 name=collection1 org.apache.solr.core.SolrCore@102ea3a url=http://127.0.0.1:55225/collection1 node=127.0.0.1:55225_ C3374_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:55225, core=collection1, node_name=127.0.0.1:55225_}
[junit4] 2> 2801525 T9374 C3374 P55225 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:55225/collection1/
[junit4] 2> 2801525 T9374 C3374 P55225 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 2801525 T9374 C3374 P55225 oasc.SyncStrategy.syncToMe http://127.0.0.1:55225/collection1/ has no replicas
[junit4] 2> 2801525 T9374 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:55225/collection1/ shard1
[junit4] 2> 2801526 T9374 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2801529 T9348 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2801537 T9347 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2801542 T9347 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2801550 T9347 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2801661 T9347 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 2801661 T9356 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 2801662 T9369 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 2801709 T9374 oasc.ZkController.register We are http://127.0.0.1:55225/collection1/ and leader is http://127.0.0.1:55225/collection1/
[junit4] 2> 2801709 T9374 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:55225
[junit4] 2> 2801711 T9374 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 2801711 T9374 oasc.ZkController.publish publishing core=collection1 state=active collection=collection1
[junit4] 2> 2801712 T9374 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 2801723 T9347 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2801723 T9347 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2801723 T9347 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2801724 T9374 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2801726 T9348 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2801727 T9348 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:55225",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:55225_",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 2801732 T9347 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2801847 T9369 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 2801848 T9356 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 2801848 T9347 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 2803881 T9325 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 2
[junit4] 2> 2803882 T9325 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 2803886 T9325 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:55234
[junit4] 2> 2803886 T9325 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 2803886 T9325 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 2803886 T9325 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\temp\solr.cloud.SyncSliceTest-6D1AE3DB3CB11AFE-001\tempDir-004
[junit4] 2> 2803888 T9325 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\temp\solr.cloud.SyncSliceTest-6D1AE3DB3CB11AFE-001\tempDir-004\'
[junit4] 2> 2803931 T9325 oasc.ConfigSolr.fromFile Loading container configuration from C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\temp\solr.cloud.SyncSliceTest-6D1AE3DB3CB11AFE-001\tempDir-004\solr.xml
[junit4] 2> 2803960 T9325 oasc.CoreContainer.<init> New CoreContainer 20723444
[junit4] 2> 2803963 T9325 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\temp\solr.cloud.SyncSliceTest-6D1AE3DB3CB11AFE-001\tempDir-004\]
[junit4] 2> 2803963 T9325 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 2803963 T9325 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 2803963 T9325 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 2803963 T9325 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 2803963 T9325 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 2803963 T9325 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 2803965 T9325 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 2803965 T9325 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 2803965 T9325 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 2803965 T9325 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 2803965 T9325 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 2803965 T9325 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 2803965 T9325 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:55206/solr
[junit4] 2> 2803968 T9325 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 2803970 T9325 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2803974 T9385 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1392daf name:ZooKeeperConnection Watcher:127.0.0.1:55206 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2803974 T9325 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2803978 T9327 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x146391473df0007, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 2803979 T9325 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2803981 T9387 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@60ba58 name:ZooKeeperConnection Watcher:127.0.0.1:55206/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2803982 T9325 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2803997 T9325 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 2804967 T9325 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:55234_
[junit4] 2> 2804969 T9325 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:55234_
[junit4] 2> 2804990 T9388 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
[junit4] 2> 2804990 T9388 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 2804993 T9388 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 2804993 T9347 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2804993 T9347 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2804993 T9347 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2804996 T9348 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2804997 T9348 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:55234",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:55234_",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":null}
[junit4] 2> 2804998 T9348 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=1
[junit4] 2> 2804998 T9348 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 2805005 T9347 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2805007 T9369 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 2805007 T9356 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 2805007 T9387 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 2805007 T9347 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 2805957 T9388 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 2805957 T9388 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 2805958 T9388 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 2805959 T9388 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 2805961 T9388 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 2805961 T9388 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\temp\solr.cloud.SyncSliceTest-6D1AE3DB3CB11AFE-001\tempDir-004\collection1\'
[junit4] 2> 2805965 T9388 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/temp/solr.cloud.SyncSliceTest-6D1AE3DB3CB11AFE-001/tempDir-004/collection1/lib/.svn/' to classloader
[junit4] 2> 2805967 T9388 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/temp/solr.cloud.SyncSliceTest-6D1AE3DB3CB11AFE-001/tempDir-004/collection1/lib/classes/' to classloader
[junit4] 2> 2805971 T9388 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/temp/solr.cloud.SyncSliceTest-6D1AE3DB3CB11AFE-001/tempDir-004/collection1/lib/README' to classloader
[junit4] 2> 2806020 T9388 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_5_0
[junit4] 2> 2806032 T9388 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 2806035 T9388 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 2806044 T9388 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 2806191 T9388 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 2806205 T9388 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 2806206 T9388 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 2806229 T9388 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 2806234 T9388 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 2806241 T9388 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 2806243 T9388 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 2806244 T9388 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 2806244 T9388 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 2806248 T9388 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 2806248 T9388 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 2806249 T9388 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection collection1
[junit4] 2> 2806249 T9388 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 2806249 T9388 oasc.SolrCore.<init> [collection1] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\temp\solr.cloud.SyncSliceTest-6D1AE3DB3CB11AFE-001\tempDir-004\collection1\, dataDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\temp\solr.cloud.SyncSliceTest-6D1AE3DB3CB11AFE-001\tempDir-001/jetty2\
[junit4] 2> 2806250 T9388 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@33105d
[junit4] 2> 2806251 T9388 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\temp\solr.cloud.SyncSliceTest-6D1AE3DB3CB11AFE-001\tempDir-001/jetty2\
[junit4] 2> 2806251 T9388 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\temp\solr.cloud.SyncSliceTest-6D1AE3DB3CB11AFE-001\tempDir-001/jetty2\index/
[junit4] 2> 2806251 T9388 oasc.SolrCore.initIndex WARN [collection1] Solr index directory 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\temp\solr.cloud.SyncSliceTest-6D1AE3DB3CB11AFE-001\tempDir-001\jetty2\index' doesn't exist. Creating new index...
[junit4] 2> 2806252 T9388 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\temp\solr.cloud.SyncSliceTest-6D1AE3DB3CB11AFE-001\tempDir-001/jetty2\index
[junit4] 2> 2806253 T9388 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=13, maxMergeAtOnceExplicit=20, maxMergedSegmentMB=1.2763671875, floorSegmentMB=1.744140625, forceMergeDeletesPctAllowed=7.573799454162802, segmentsPerTier=27.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 2806253 T9388 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@5982b3 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6fb45c),segFN=segments_1,generation=1}
[junit4] 2> 2806253 T9388 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 2806258 T9388 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 2806258 T9388 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 2806259 T9388 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 2806259 T9388 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 2806260 T9388 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 2806260 T9388 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 2806260 T9388 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 2806261 T9388 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 2806261 T9388 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 2806262 T9388 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 2806263 T9388 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 2806263 T9388 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 2806263 T9388 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 2806264 T9388 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 2806265 T9388 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 2806265 T9388 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 2806266 T9388 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
[junit4] 2> 2806273 T9388 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 2806277 T9388 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 2806278 T9388 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 2806278 T9388 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=19, maxMergeAtOnceExplicit=40, maxMergedSegmentMB=20.6083984375, floorSegmentMB=1.2109375, forceMergeDeletesPctAllowed=0.4919785419199596, segmentsPerTier=27.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.42659321616318546
[junit4] 2> 2806279 T9388 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@5982b3 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6fb45c),segFN=segments_1,generation=1}
[junit4] 2> 2806279 T9388 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 2806280 T9388 oass.SolrIndexSearcher.<init> Opening Searcher@632458[collection1] main
[junit4] 2> 2806280 T9388 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 2806282 T9388 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 2806282 T9388 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
[junit4] 2> 2806283 T9388 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 2806283 T9388 oasr.RestManager.init Initializing RestManager with initArgs: {}
[junit4] 2> 2806283 T9388 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 2806284 T9388 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
[junit4] 2> 2806284 T9388 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 2806285 T9388 oasr.ManagedResource.notifyObserversDuringInit WARN No registered observers for /rest/managed
[junit4] 2> 2806285 T9388 oasr.RestManager.init Initializing 0 registered ManagedResources
[junit4] 2> 2806286 T9389 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@632458[collection1] main{UninvertingDirectoryReader()}
[junit4] 2> 2806289 T9388 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 2806291 T9392 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:55234 collection:collection1 shard:shard1
[junit4] 2> 2806292 T9325 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0
[junit4] 2> 2806292 T9325 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 2806304 T9392 oasc.ZkController.register We are http://127.0.0.1:55234/collection1/ and leader is http://127.0.0.1:55225/collection1/
[junit4] 2> 2806304 T9392 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:55234
[junit4] 2> 2806304 T9392 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4] 2> 2806304 T9392 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4] 2> ASYNC NEW_CORE C3375 name=collection1 org.apache.solr.core.SolrCore@1e12dcd url=http://127.0.0.1:55234/collection1 node=127.0.0.1:55234_ C3375_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:55234, core=collection1, node_name=127.0.0.1:55234_}
[junit4] 2> 2806307 T9393 C3375 P55234 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4] 2> 2806307 T9393 C3375 P55234 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4] 2> 2806307 T9393 C3375 P55234 oasc.RecoveryStrategy.doRecovery Publishing state of core collection1 as recovering, leader is http://127.0.0.1:55225/collection1/ and I am http://127.0.0.1:55234/collection1/
[junit4] 2> 2806307 T9393 C3375 P55234 oasc.ZkController.publish publishing core=collection1 state=recovering collection=collection1
[junit4] 2> 2806307 T9393 C3375 P55234 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 2806309 T9392 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2806315 T9347 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2806317 T9393 C3375 P55234 oasc.RecoveryStrategy.sendPrepRecoveryCmd Sending prep recovery command to http://127.0.0.1:55225; WaitForState: action=PREPRECOVERY&core=collection1&nodeName=127.0.0.1%3A55234_&coreNodeName=core_node2&state=recovering&checkLive=true&onlyIfLeader=true&onlyIfLeaderActive=true
[junit4] 2> 2806319 T9348 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2806320 T9348 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"recovering",
[junit4] 2> "base_url":"http://127.0.0.1:55234",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:55234_",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":"core_node2"}
[junit4] 2> 2806329 T9362 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: core_node2, state: recovering, checkLive: true, onlyIfLeader: true, onlyIfLeaderActive: true
[junit4] 2> 2806331 T9362 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2806334 T9362 oasha.CoreAdminHandler.handleWaitForStateAction Will wait a max of 183 seconds to see collection1 (shard1 of collection1) have state: recovering
[junit4] 2> 2806335 T9362 oasha.CoreAdminHandler.handleWaitForStateAction In WaitForState(recovering): collection=collection1, shard=shard1, thisCore=collection1, leaderDoesNotNeedRecovery=false, isLeader? true, live=true, checkLive=true, currentState=down, localState=active, nodeName=127.0.0.1:55234_, coreNodeName=core_node2, onlyIfActiveCheckResult=false, nodeProps: core_node2:{"state":"down","base_url":"http://127.0.0.1:55234","core":"collection1","node_name":"127.0.0.1:55234_"}
[junit4] 2> 2806334 T9347 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2806439 T9369 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 2806440 T9347 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 2806441 T9387 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 2806441 T9356 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 2807300 T9362 oasha.CoreAdminHandler.handleWaitForStateAction In WaitForState(recovering): collection=collection1, shard=shard1, thisCore=collection1, leaderDoesNotNeedRecovery=false, isLeader? true, live=true, checkLive=true, currentState=recovering, localState=active, nodeName=127.0.0.1:55234_, coreNodeName=core_node2, onlyIfActiveCheckResult=false, nodeProps: core_node2:{"state":"recovering","base_url":"http://127.0.0.1:55234","core":"collection1","node_name":"127.0.0.1:55234_"}
[junit4] 2> 2807300 T9362 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: core_node2, state: recovering, checkLive: true, onlyIfLeader: true for: 1 seconds.
[junit4] 2> 2807300 T9362 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={nodeName=127.0.0.1:55234_&onlyIfLeaderActive=true&core=collection1&coreNodeName=core_node2&action=PREPRECOVERY&checkLive=true&state=recovering&onlyIfLeader=true&wt=javabin&version=2} status=0 QTime=971
[junit4] 2> 2808988 T9325 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 3
[junit4] 2> 2808990 T9325 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 2808994 T9325 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:55244
[junit4] 2> 2808994 T9325 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 2808994 T9325 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 2808994 T9325 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\temp\solr.cloud.SyncSliceTest-6D1AE3DB3CB11AFE-001\tempDir-005
[junit4] 2> 2808994 T9325 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\temp\solr.cloud.SyncSliceTest-6D1AE3DB3CB11AFE-001\tempDir-005\'
[junit4] 2> 2809039 T9325 oasc.ConfigSolr.fromFile Loading container configuration from C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\temp\solr.cloud.SyncSliceTest-6D1AE3DB3CB11AFE-001\tempDir-005\solr.xml
[junit4] 2> 2809059 T9325 oasc.CoreContainer.<init> New CoreContainer 15852366
[junit4] 2> 2809060 T9325 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\temp\solr.cloud.SyncSliceTest-6D1AE3DB3CB11AFE-001\tempDir-005\]
[junit4] 2> 2809063 T9325 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 2809063 T9325 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 2809063 T9325 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 2809063 T9325 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 2809064 T9325 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 2809064 T9325 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 2809064 T9325 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 2809064 T9325 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 2809068 T9325 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 2809068 T9325 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 2809068 T9325 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 2809068 T9325 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 2809068 T9325 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:55206/solr
[junit4] 2> 2809071 T9325 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 2809088 T9325 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[j
[...truncated too long message...]
path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4] 2> 2856439 T9428 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 2856440 T9428 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 2856440 T9428 oasc.LeaderElector$ElectionWatcher.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/election
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1472)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:260)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:257)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:257)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:94)
[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:303)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:522)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:498)
[junit4] 2>
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=SyncSliceTest -Dtests.method=testDistribSearch -Dtests.seed=6D1AE3DB3CB11AFE -Dtests.slow=true -Dtests.locale=ar_IQ -Dtests.timezone=Europe/Guernsey -Dtests.file.encoding=UTF-8
[junit4] ERROR 64.1s | SyncSliceTest.testDistribSearch <<<
[junit4] > Throwable #1: org.apache.solr.client.solrj.SolrServerException: No live SolrServers available to handle this request
[junit4] > at __randomizedtesting.SeedInfo.seed([6D1AE3DB3CB11AFE:ECFC6DC34BEE7AC2]:0)
[junit4] > at org.apache.solr.client.solrj.impl.LBHttpSolrServer.request(LBHttpSolrServer.java:317)
[junit4] > at org.apache.solr.client.solrj.impl.CloudSolrServer.request(CloudSolrServer.java:650)
[junit4] > at org.apache.solr.client.solrj.request.QueryRequest.process(QueryRequest.java:91)
[junit4] > at org.apache.solr.client.solrj.SolrServer.query(SolrServer.java:301)
[junit4] > at org.apache.solr.cloud.AbstractFullDistribZkTestBase.checkShardConsistency(AbstractFullDistribZkTestBase.java:1141)
[junit4] > at org.apache.solr.cloud.AbstractFullDistribZkTestBase.checkShardConsistency(AbstractFullDistribZkTestBase.java:1110)
[junit4] > at org.apache.solr.cloud.SyncSliceTest.doTest(SyncSliceTest.java:236)
[junit4] > at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:863)
[junit4] > at java.lang.Thread.run(Thread.java:745)
[junit4] 2> 2856446 T9325 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> NOTE: leaving temporary files on disk at: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\temp\solr.cloud.SyncSliceTest-6D1AE3DB3CB11AFE-001
[junit4] 2> NOTE: test params are: codec=Lucene41, sim=RandomSimilarityProvider(queryNorm=false,coord=no): {}, locale=ar_IQ, timezone=Europe/Guernsey
[junit4] 2> NOTE: Windows 7 6.1 x86/Oracle Corporation 1.8.0_05 (32-bit)/cpus=2,threads=1,free=67904496,total=330915840
[junit4] 2> NOTE: All tests run in this JVM: [TestRealTimeGet, MoreLikeThisHandlerTest, NotRequiredUniqueKeyTest, FieldFacetExtrasTest, DistanceFunctionTest, CustomCollectionTest, XmlUpdateRequestHandlerTest, ClusterStateTest, SpellCheckComponentTest, FieldMutatingUpdateProcessorTest, TestDynamicFieldCollectionResource, ZkSolrClientTest, PrimUtilsTest, TestReload, SSLMigrationTest, DeleteReplicaTest, UniqFieldsUpdateProcessorFactoryTest, CoreAdminCreateDiscoverTest, TestComponentsName, TestStressVersions, TestPerFieldSimilarity, TestSearchPerf, ResponseLogComponentTest, TestQueryUtils, AddSchemaFieldsUpdateProcessorFactoryTest, TestUtils, ChaosMonkeyNothingIsSafeTest, BasicFunctionalityTest, TestRangeQuery, SolrCoreCheckLockOnStartupTest, SuggestComponentTest, TestStressLucene, BadIndexSchemaTest, SliceStateTest, SystemInfoHandlerTest, TestQuerySenderListener, TestPhraseSuggestions, StandardRequestHandlerTest, TestManagedSchema, TestOrdValues, DeleteInactiveReplicaTest, TestValueSourceCache, ShardRoutingTest, DirectUpdateHandlerTest, TestDynamicFieldResource, MergeStrategyTest, HighlighterConfigTest, DirectSolrSpellCheckerTest, TestSolrXmlPersistence, TestRandomFaceting, QueryEqualityTest, SolrCmdDistributorTest, TestBinaryResponseWriter, FileBasedSpellCheckerTest, TestReplicationHandler, HdfsCollectionsAPIDistributedZkTest, FullSolrCloudDistribCmdsTest, TestCloudInspectUtil, ReturnFieldsTest, TestJoin, HdfsWriteToMultipleCollectionsTest, TestArbitraryIndexDir, FileUtilsTest, RemoteQueryErrorTest, TestFunctionQuery, TestShardHandlerFactory, SchemaVersionSpecificBehaviorTest, TestCoreContainer, TestExtendedDismaxParser, FieldAnalysisRequestHandlerTest, TestIndexSearcher, TestSerializedLuceneMatchVersion, TestLuceneMatchVersion, UnloadDistributedZkTest, OverseerCollectionProcessorTest, TestDistributedGrouping, TestLFUCache, TestSolrQueryParser, TestRTGBase, TestStressRecovery, TestInfoStreamLogging, SimplePostToolTest, OutputWriterTest, UpdateRequestProcessorFactoryTest, TestFreeTextSuggestions, TestAddFieldRealTimeGet, SearchHandlerTest, TestNoOpRegenerator, CoreAdminHandlerTest, AsyncMigrateRouteKeyTest, RAMDirectoryFactoryTest, TestStressReorder, TestMergePolicyConfig, SpellPossibilityIteratorTest, ExternalFileFieldSortTest, TestCopyFieldCollectionResource, TestFileDictionaryLookup, ReplicationFactorTest, RankQueryTest, DebugComponentTest, TermsComponentTest, TestExceedMaxTermLength, FunctionTest, TestRestManager, HdfsUnloadDistributedZkTest, DeleteShardTest, TestDFRSimilarityFactory, TestMultiCoreConfBootstrap, ModifyConfFileTest, TestCSVLoader, TestFiltering, TestSolrQueryParserDefaultOperatorResource, OverseerTest, HdfsRecoveryZkTest, TestDocSet, SpellingQueryConverterTest, TestShortCircuitedRequests, TestManagedStopFilterFactory, DateFieldTest, ConvertedLegacyTest, NoFacetTest, TestBadConfig, DocumentBuilderTest, TestMaxScoreQueryParser, TestCollapseQParserPlugin, CoreAdminRequestStatusTest, TestLMJelinekMercerSimilarityFactory, TestSchemaVersionResource, TestManagedResource, RegexBoostProcessorTest, TestUniqueKeyFieldResource, RequestHandlersTest, SampleTest, SolrCoreTest, DistributedQueryComponentOptimizationTest, DistributedQueryComponentCustomSortTest, EchoParamsTest, ChangedSchemaMergeTest, RecoveryZkTest, TestWordDelimiterFilterFactory, DocValuesTest, TestRecovery, SignatureUpdateProcessorFactoryTest, AliasIntegrationTest, QueryElevationComponentTest, PingRequestHandlerTest, PathHierarchyTokenizerFactoryTest, AnalysisErrorHandlingTest, BasicDistributedZkTest, TestHighlightDedupGrouping, CircularListTest, QueryResultKeyTest, TestClassNameShortening, TestSolr4Spatial, AlternateDirectoryTest, TestIndexingPerformance, MultiThreadedOCPTest, TestPseudoReturnFields, TestFastWriter, CursorPagingTest, TestCodecSupport, TestAtomicUpdateErrorCases, ParsingFieldUpdateProcessorsTest, StatelessScriptUpdateProcessorFactoryTest, ShardRoutingCustomTest, DistributedExpandComponentTest, TestConfigSets, TestHashPartitioner, HdfsSyncSliceTest, TestXIncludeConfig, TestCustomSort, TestCoreDiscovery, ConnectionManagerTest, TermVectorComponentDistributedTest, TestSolrXmlPersistor, TestStandardQParsers, HdfsDirectoryTest, TestCloudManagedSchemaAddField, MinimalSchemaTest, TestManagedResourceStorage, TestManagedSchemaFieldResource, BasicZkTest, TestRecoveryHdfs, OverseerRolesTest, JSONWriterTest, OpenExchangeRatesOrgProviderTest, AbstractAnalyticsFacetTest, SolrInfoMBeanTest, EnumFieldTest, TestBinaryField, TestWriterPerf, DefaultValueUpdateProcessorTest, BasicDistributedZk2Test, BinaryUpdateRequestHandlerTest, ZkControllerTest, TestStressUserVersions, TestInitQParser, TestSurroundQueryParser, TestModifyConfFiles, ChaosMonkeySafeLeaderTest, CollectionsAPIDistributedZkTest, SyncSliceTest]
[junit4] Completed in 64.18s, 1 test, 1 error <<< FAILURES!
[...truncated 627 lines...]
BUILD FAILED
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\build.xml:467: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\build.xml:447: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\build.xml:45: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\extra-targets.xml:37: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build.xml:189: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\common-build.xml:496: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\common-build.xml:1296: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\common-build.xml:920: There were test failures: 406 suites, 1688 tests, 1 error, 41 ignored (20 assumptions)
Total time: 105 minutes 39 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 32bit/jdk1.8.0_05 -server -XX:+UseSerialGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure