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/07/04 10:11:42 UTC
[JENKINS] Lucene-Solr-4.x-Windows (64bit/jdk1.8.0_05) - Build #
4071 - Still Failing!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-Windows/4071/
Java: 64bit/jdk1.8.0_05 -XX:+UseCompressedOops -XX:+UseParallelGC
1 tests failed.
FAILED: 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([570B0D7AB46D86C7:D6ED8362C332E6FB]:0)
at org.apache.solr.client.solrj.impl.LBHttpSolrServer.request(LBHttpSolrServer.java:317)
at org.apache.solr.client.solrj.impl.CloudSolrServer.request(CloudSolrServer.java:659)
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:1149)
at org.apache.solr.cloud.AbstractFullDistribZkTestBase.checkShardConsistency(AbstractFullDistribZkTestBase.java:1118)
at org.apache.solr.cloud.SyncSliceTest.doTest(SyncSliceTest.java:236)
at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:865)
at sun.reflect.GeneratedMethodAccessor38.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.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:798)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:458)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:836)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:738)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:772)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:783)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java: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:365)
at java.lang.Thread.run(Thread.java:745)
Build Log:
[...truncated 11398 lines...]
[junit4] Suite: org.apache.solr.cloud.SyncSliceTest
[junit4] 2> Creating dataDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solr.cloud.SyncSliceTest-570B0D7AB46D86C7-001\init-core-data-001
[junit4] 2> 2186412 T8212 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (false) and clientAuth (true)
[junit4] 2> 2186413 T8212 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /_ufl/j
[junit4] 2> 2186417 T8212 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4] 2> 2186417 T8212 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 2186419 T8213 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 2186514 T8212 oasc.ZkTestServer.run start zk server on port:50660
[junit4] 2> 2186515 T8212 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2186522 T8219 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@24a577d7 name:ZooKeeperConnection Watcher:127.0.0.1:50660 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2186522 T8212 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2186522 T8212 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 2186527 T8214 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x147004c5cad0000, 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> 2186529 T8212 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2186531 T8221 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@48bf040c name:ZooKeeperConnection Watcher:127.0.0.1:50660/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2186531 T8212 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2186531 T8212 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4] 2> 2186535 T8212 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4] 2> 2186539 T8212 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4] 2> 2186542 T8212 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4] 2> 2186551 T8212 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\core\src\test-files\solr\collection1\conf\solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4] 2> 2186552 T8212 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4] 2> 2186558 T8212 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\core\src\test-files\solr\collection1\conf\schema.xml to /configs/conf1/schema.xml
[junit4] 2> 2186558 T8212 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4] 2> 2186563 T8212 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\core\src\test-files\solr\collection1\conf\solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 2186564 T8212 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 2186568 T8212 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\core\src\test-files\solr\collection1\conf\stopwords.txt to /configs/conf1/stopwords.txt
[junit4] 2> 2186569 T8212 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4] 2> 2186572 T8212 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\core\src\test-files\solr\collection1\conf\protwords.txt to /configs/conf1/protwords.txt
[junit4] 2> 2186572 T8212 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4] 2> 2186577 T8212 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\core\src\test-files\solr\collection1\conf\currency.xml to /configs/conf1/currency.xml
[junit4] 2> 2186577 T8212 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4] 2> 2186582 T8212 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\core\src\test-files\solr\collection1\conf\enumsConfig.xml to /configs/conf1/enumsConfig.xml
[junit4] 2> 2186582 T8212 oascc.SolrZkClient.makePath makePath: /configs/conf1/enumsConfig.xml
[junit4] 2> 2186586 T8212 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\core\src\test-files\solr\collection1\conf\open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4] 2> 2186586 T8212 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4] 2> 2186592 T8212 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\core\src\test-files\solr\collection1\conf\mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 2186592 T8212 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 2186596 T8212 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\core\src\test-files\solr\collection1\conf\old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4] 2> 2186596 T8212 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4] 2> 2186601 T8212 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\core\src\test-files\solr\collection1\conf\synonyms.txt to /configs/conf1/synonyms.txt
[junit4] 2> 2186601 T8212 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4] 2> 2186606 T8214 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x147004c5cad0001, 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> 2188323 T8212 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 2188328 T8212 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:50667
[junit4] 2> 2188329 T8212 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 2188329 T8212 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 2188329 T8212 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solr.cloud.SyncSliceTest-570B0D7AB46D86C7-001\tempDir-002
[junit4] 2> 2188329 T8212 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solr.cloud.SyncSliceTest-570B0D7AB46D86C7-001\tempDir-002\'
[junit4] 2> 2188364 T8212 oasc.ConfigSolr.fromFile Loading container configuration from C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solr.cloud.SyncSliceTest-570B0D7AB46D86C7-001\tempDir-002\solr.xml
[junit4] 2> 2188375 T8212 oasc.CoreContainer.<init> New CoreContainer 1225646920
[junit4] 2> 2188375 T8212 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solr.cloud.SyncSliceTest-570B0D7AB46D86C7-001\tempDir-002\]
[junit4] 2> 2188377 T8212 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 2188377 T8212 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 2188377 T8212 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 2188377 T8212 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 2188377 T8212 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 2188377 T8212 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 2188377 T8212 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 2188379 T8212 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 2188379 T8212 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 2188379 T8212 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 2188379 T8212 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 2188379 T8212 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 2188381 T8212 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:50660/solr
[junit4] 2> 2188381 T8212 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 2188383 T8212 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2188407 T8232 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@15002810 name:ZooKeeperConnection Watcher:127.0.0.1:50660 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2188408 T8212 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2188410 T8214 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x147004c5cad0002, 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> 2188411 T8212 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2188414 T8234 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@67044fb1 name:ZooKeeperConnection Watcher:127.0.0.1:50660/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2188415 T8212 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2188418 T8212 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 2188422 T8212 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 2188428 T8212 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 2188433 T8212 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 2188438 T8212 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 2188443 T8212 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 2188445 T8212 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:50667__ufl%2Fj
[junit4] 2> 2188447 T8212 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:50667__ufl%2Fj
[junit4] 2> 2188457 T8212 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 2188462 T8212 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 2188469 T8212 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:50667__ufl%2Fj
[junit4] 2> 2188469 T8212 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 2188473 T8212 oasc.Overseer.start Overseer (id=92042645356740611-127.0.0.1:50667__ufl%2Fj-n_0000000000) starting
[junit4] 2> 2188479 T8212 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 2188494 T8236 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 2188495 T8212 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 2188499 T8212 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 2188503 T8212 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 2188506 T8235 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 2188510 T8237 oasc.ZkController.publish publishing core=collection1 state=down collection=control_collection
[junit4] 2> 2188510 T8237 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 2188512 T8237 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 2188512 T8234 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2188516 T8235 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2188517 T8235 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:50667/_ufl/j",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:50667__ufl%2Fj",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"control_collection",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":null}
[junit4] 2> 2188517 T8235 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1]
[junit4] 2> 2188517 T8235 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 2188520 T8234 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2188522 T8234 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> 2189457 T8237 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 2189457 T8237 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4] 2> 2189458 T8237 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 2189458 T8237 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
[junit4] 2> 2189460 T8237 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 2189460 T8237 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solr.cloud.SyncSliceTest-570B0D7AB46D86C7-001\tempDir-002\collection1\'
[junit4] 2> 2189463 T8237 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/solr.cloud.SyncSliceTest-570B0D7AB46D86C7-001/tempDir-002/collection1/lib/.svn/' to classloader
[junit4] 2> 2189465 T8237 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/solr.cloud.SyncSliceTest-570B0D7AB46D86C7-001/tempDir-002/collection1/lib/classes/' to classloader
[junit4] 2> 2189466 T8237 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/solr.cloud.SyncSliceTest-570B0D7AB46D86C7-001/tempDir-002/collection1/lib/README' to classloader
[junit4] 2> 2189499 T8237 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_4_10
[junit4] 2> 2189506 T8237 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 2189512 T8237 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 2189517 T8237 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 2189613 T8237 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 2189614 T8237 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 2189615 T8237 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 2189623 T8237 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 2189623 T8237 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 2189639 T8237 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 2189642 T8237 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 2189646 T8237 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 2189647 T8237 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 2189647 T8237 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 2189647 T8237 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 2189648 T8237 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 2189648 T8237 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 2189649 T8237 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection control_collection
[junit4] 2> 2189649 T8237 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 2189649 T8237 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solr.cloud.SyncSliceTest-570B0D7AB46D86C7-001\tempDir-002\collection1\, dataDir=.\solr.cloud.SyncSliceTest-570B0D7AB46D86C7-001\tempDir-001/control/data\
[junit4] 2> 2189649 T8237 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@5cb36c56
[junit4] 2> 2189650 T8237 oasc.CachingDirectoryFactory.get return new directory for .\solr.cloud.SyncSliceTest-570B0D7AB46D86C7-001\tempDir-001/control/data\
[junit4] 2> 2189650 T8237 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\solr.cloud.SyncSliceTest-570B0D7AB46D86C7-001\tempDir-001/control/data\index/
[junit4] 2> 2189650 T8237 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '.\solr.cloud.SyncSliceTest-570B0D7AB46D86C7-001\tempDir-001\control\data\index' doesn't exist. Creating new index...
[junit4] 2> 2189651 T8237 oasc.CachingDirectoryFactory.get return new directory for .\solr.cloud.SyncSliceTest-570B0D7AB46D86C7-001\tempDir-001/control/data\index
[junit4] 2> 2189651 T8237 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=12, maxMergeAtOnceExplicit=46, maxMergedSegmentMB=7.7900390625, floorSegmentMB=0.86328125, forceMergeDeletesPctAllowed=5.161321432597553, segmentsPerTier=20.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 2189652 T8237 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@5f61bb4 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@64d56930),segFN=segments_1,generation=1}
[junit4] 2> 2189652 T8237 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 2189654 T8237 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 2189654 T8237 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 2189655 T8237 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 2189655 T8237 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 2189655 T8237 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 2189655 T8237 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 2189656 T8237 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 2189656 T8237 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 2189656 T8237 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 2189656 T8237 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 2189657 T8237 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 2189657 T8237 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 2189657 T8237 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 2189658 T8237 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 2189658 T8237 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 2189658 T8237 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 2189663 T8237 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 2189667 T8237 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 2189667 T8237 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 2189668 T8237 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=31, maxMergeAtOnceExplicit=26, maxMergedSegmentMB=25.5576171875, floorSegmentMB=0.8564453125, forceMergeDeletesPctAllowed=10.111174969491634, segmentsPerTier=27.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.764443888052419
[junit4] 2> 2189668 T8237 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@5f61bb4 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@64d56930),segFN=segments_1,generation=1}
[junit4] 2> 2189668 T8237 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 2189669 T8237 oass.SolrIndexSearcher.<init> Opening Searcher@26417c39[collection1] main
[junit4] 2> 2189669 T8237 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
[junit4] 2> 2189671 T8237 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 2189671 T8237 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
[junit4] 2> 2189671 T8237 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 2189671 T8237 oasr.RestManager.init Initializing RestManager with initArgs: {}
[junit4] 2> 2189671 T8237 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 2189672 T8237 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
[junit4] 2> 2189672 T8237 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 2189673 T8237 oasr.ManagedResource.notifyObserversDuringInit WARN No registered observers for /rest/managed
[junit4] 2> 2189673 T8237 oasr.RestManager.init Initializing 0 registered ManagedResources
[junit4] 2> 2189674 T8238 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@26417c39[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 2189675 T8237 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 2189676 T8241 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:50667/_ufl/j collection:control_collection shard:shard1
[junit4] 2> 2189676 T8212 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0
[junit4] 2> 2189677 T8212 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 2189678 T8241 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4] 2> 2189679 T8212 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2189681 T8243 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7b9484b name:ZooKeeperConnection Watcher:127.0.0.1:50660/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2189682 T8212 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2189684 T8212 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 2189689 T8212 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:false
[junit4] 2> 2189690 T8241 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 2189693 T8234 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2189695 T8241 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 2189695 T8241 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> ASYNC NEW_CORE C1671 name=collection1 org.apache.solr.core.SolrCore@5f616f8b url=http://127.0.0.1:50667/_ufl/j/collection1 node=127.0.0.1:50667__ufl%2Fj C1671_STATE=coll:control_collection core:collection1 props:{state=down, base_url=http://127.0.0.1:50667/_ufl/j, core=collection1, node_name=127.0.0.1:50667__ufl%2Fj}
[junit4] 2> 2189695 T8241 C1671 P50667 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:50667/_ufl/j/collection1/
[junit4] 2> 2189695 T8241 C1671 P50667 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 2189695 T8241 C1671 P50667 oasc.SyncStrategy.syncToMe http://127.0.0.1:50667/_ufl/j/collection1/ has no replicas
[junit4] 2> 2189695 T8241 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:50667/_ufl/j/collection1/ shard1
[junit4] 2> 2189696 T8241 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4] 2> 2189702 T8235 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2189710 T8234 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2189713 T8234 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2189719 T8234 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2189819 T8234 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> 2189819 T8243 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> 2189860 T8241 oasc.ZkController.register We are http://127.0.0.1:50667/_ufl/j/collection1/ and leader is http://127.0.0.1:50667/_ufl/j/collection1/
[junit4] 2> 2189860 T8241 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:50667/_ufl/j
[junit4] 2> 2189860 T8241 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 2189860 T8241 oasc.ZkController.publish publishing core=collection1 state=active collection=control_collection
[junit4] 2> 2189860 T8241 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 2189863 T8234 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2189863 T8234 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2189863 T8234 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2189865 T8241 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2189867 T8235 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2189868 T8235 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:50667/_ufl/j",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:50667__ufl%2Fj",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"control_collection",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 2189872 T8234 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2189979 T8234 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> 2189979 T8243 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> 2191381 T8212 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 1
[junit4] 2> 2191382 T8212 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 2191386 T8212 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:50679
[junit4] 2> 2191387 T8212 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 2191387 T8212 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 2191388 T8212 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: .\solr.cloud.SyncSliceTest-570B0D7AB46D86C7-001\tempDir-003
[junit4] 2> 2191388 T8212 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '.\solr.cloud.SyncSliceTest-570B0D7AB46D86C7-001\tempDir-003\'
[junit4] 2> 2191418 T8212 oasc.ConfigSolr.fromFile Loading container configuration from C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solr.cloud.SyncSliceTest-570B0D7AB46D86C7-001\tempDir-003\solr.xml
[junit4] 2> 2191428 T8212 oasc.CoreContainer.<init> New CoreContainer 138355874
[junit4] 2> 2191429 T8212 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=.\solr.cloud.SyncSliceTest-570B0D7AB46D86C7-001\tempDir-003\]
[junit4] 2> 2191429 T8212 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 2191430 T8212 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 2191430 T8212 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 2191430 T8212 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 2191431 T8212 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 2191431 T8212 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 2191431 T8212 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 2191432 T8212 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 2191433 T8212 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 2191433 T8212 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 2191434 T8212 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 2191434 T8212 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 2191434 T8212 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:50660/solr
[junit4] 2> 2191435 T8212 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 2191437 T8212 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2191455 T8254 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@306cdbb9 name:ZooKeeperConnection Watcher:127.0.0.1:50660 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2191456 T8212 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2191465 T8214 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x147004c5cad0005, 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> 2191467 T8212 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2191470 T8256 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6b6183e5 name:ZooKeeperConnection Watcher:127.0.0.1:50660/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2191470 T8212 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2191481 T8212 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 2192524 T8212 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:50679__ufl%2Fj
[junit4] 2> 2192526 T8212 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:50679__ufl%2Fj
[junit4] 2> 2192531 T8256 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 2192532 T8243 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 2192532 T8234 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 2192541 T8257 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
[junit4] 2> 2192541 T8257 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 2192543 T8234 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2192543 T8234 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2192543 T8234 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2192543 T8257 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 2192545 T8235 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2192546 T8235 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:50679/_ufl/j",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:50679__ufl%2Fj",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":null}
[junit4] 2> 2192546 T8235 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1]
[junit4] 2> 2192547 T8235 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 2192552 T8234 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2192554 T8234 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> 2192554 T8256 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> 2192554 T8243 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> 2193583 T8257 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 2193583 T8257 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 2193584 T8257 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 2193584 T8257 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 2193586 T8257 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 2193587 T8257 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '.\solr.cloud.SyncSliceTest-570B0D7AB46D86C7-001\tempDir-003\collection1\'
[junit4] 2> 2193590 T8257 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/solr.cloud.SyncSliceTest-570B0D7AB46D86C7-001/tempDir-003/collection1/lib/.svn/' to classloader
[junit4] 2> 2193591 T8257 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/solr.cloud.SyncSliceTest-570B0D7AB46D86C7-001/tempDir-003/collection1/lib/classes/' to classloader
[junit4] 2> 2193592 T8257 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/solr.cloud.SyncSliceTest-570B0D7AB46D86C7-001/tempDir-003/collection1/lib/README' to classloader
[junit4] 2> 2193625 T8257 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_4_10
[junit4] 2> 2193633 T8257 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 2193636 T8257 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 2193642 T8257 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 2193741 T8257 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 2193741 T8257 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 2193743 T8257 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 2193749 T8257 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 2193749 T8257 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 2193766 T8257 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 2193770 T8257 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 2193773 T8257 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 2193774 T8257 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 2193774 T8257 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 2193774 T8257 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 2193776 T8257 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 2193776 T8257 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 2193776 T8257 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection collection1
[junit4] 2> 2193776 T8257 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 2193777 T8257 oasc.SolrCore.<init> [collection1] Opening new SolrCore at .\solr.cloud.SyncSliceTest-570B0D7AB46D86C7-001\tempDir-003\collection1\, dataDir=.\solr.cloud.SyncSliceTest-570B0D7AB46D86C7-001\tempDir-001/jetty1\
[junit4] 2> 2193777 T8257 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@5cb36c56
[junit4] 2> 2193778 T8257 oasc.CachingDirectoryFactory.get return new directory for .\solr.cloud.SyncSliceTest-570B0D7AB46D86C7-001\tempDir-001/jetty1\
[junit4] 2> 2193778 T8257 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\solr.cloud.SyncSliceTest-570B0D7AB46D86C7-001\tempDir-001/jetty1\index/
[junit4] 2> 2193778 T8257 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '.\solr.cloud.SyncSliceTest-570B0D7AB46D86C7-001\tempDir-001\jetty1\index' doesn't exist. Creating new index...
[junit4] 2> 2193778 T8257 oasc.CachingDirectoryFactory.get return new directory for .\solr.cloud.SyncSliceTest-570B0D7AB46D86C7-001\tempDir-001/jetty1\index
[junit4] 2> 2193779 T8257 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=12, maxMergeAtOnceExplicit=46, maxMergedSegmentMB=7.7900390625, floorSegmentMB=0.86328125, forceMergeDeletesPctAllowed=5.161321432597553, segmentsPerTier=20.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 2193779 T8257 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@4db55f14 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@886a7de),segFN=segments_1,generation=1}
[junit4] 2> 2193779 T8257 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 2193782 T8257 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 2193782 T8257 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 2193783 T8257 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 2193783 T8257 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 2193783 T8257 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 2193783 T8257 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 2193784 T8257 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 2193784 T8257 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 2193784 T8257 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 2193784 T8257 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 2193785 T8257 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 2193785 T8257 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 2193785 T8257 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 2193786 T8257 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 2193786 T8257 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 2193786 T8257 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 2193793 T8257 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 2193796 T8257 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 2193796 T8257 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 2193797 T8257 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=31, maxMergeAtOnceExplicit=26, maxMergedSegmentMB=25.5576171875, floorSegmentMB=0.8564453125, forceMergeDeletesPctAllowed=10.111174969491634, segmentsPerTier=27.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.764443888052419
[junit4] 2> 2193797 T8257 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@4db55f14 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@886a7de),segFN=segments_1,generation=1}
[junit4] 2> 2193797 T8257 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 2193798 T8257 oass.SolrIndexSearcher.<init> Opening Searcher@798fb5b6[collection1] main
[junit4] 2> 2193798 T8257 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 2193799 T8257 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 2193800 T8257 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
[junit4] 2> 2193801 T8257 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 2193801 T8257 oasr.RestManager.init Initializing RestManager with initArgs: {}
[junit4] 2> 2193801 T8257 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 2193802 T8257 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
[junit4] 2> 2193802 T8257 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 2193802 T8257 oasr.ManagedResource.notifyObserversDuringInit WARN No registered observers for /rest/managed
[junit4] 2> 2193803 T8257 oasr.RestManager.init Initializing 0 registered ManagedResources
[junit4] 2> 2193807 T8258 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@798fb5b6[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 2193808 T8257 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 2193809 T8261 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:50679/_ufl/j collection:collection1 shard:shard1
[junit4] 2> 2193810 T8212 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0
[junit4] 2> 2193811 T8212 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 2193812 T8261 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 2193829 T8261 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 2193835 T8234 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2193836 T8261 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 2193836 T8261 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> ASYNC NEW_CORE C1672 name=collection1 org.apache.solr.core.SolrCore@68a9d551 url=http://127.0.0.1:50679/_ufl/j/collection1 node=127.0.0.1:50679__ufl%2Fj C1672_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:50679/_ufl/j, core=collection1, node_name=127.0.0.1:50679__ufl%2Fj}
[junit4] 2> 2193836 T8261 C1672 P50679 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:50679/_ufl/j/collection1/
[junit4] 2> 2193836 T8261 C1672 P50679 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 2193836 T8261 C1672 P50679 oasc.SyncStrategy.syncToMe http://127.0.0.1:50679/_ufl/j/collection1/ has no replicas
[junit4] 2> 2193836 T8261 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:50679/_ufl/j/collection1/ shard1
[junit4] 2> 2193838 T8261 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2193842 T8235 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2193852 T8234 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2193857 T8234 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2193866 T8234 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2193978 T8234 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> 2193979 T8243 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> 2193979 T8256 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> 2194021 T8261 oasc.ZkController.register We are http://127.0.0.1:50679/_ufl/j/collection1/ and leader is http://127.0.0.1:50679/_ufl/j/collection1/
[junit4] 2> 2194021 T8261 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:50679/_ufl/j
[junit4] 2> 2194021 T8261 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 2194021 T8261 oasc.ZkController.publish publishing core=collection1 state=active collection=collection1
[junit4] 2> 2194021 T8261 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 2194026 T8234 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2194026 T8234 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2194026 T8234 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2194028 T8261 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2194031 T8235 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2194032 T8235 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:50679/_ufl/j",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:50679__ufl%2Fj",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 2194037 T8234 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2194146 T8234 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> 2194147 T8243 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> 2194147 T8256 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> 2195792 T8212 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 2
[junit4] 2> 2195794 T8212 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 2195798 T8212 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:50688
[junit4] 2> 2195799 T8212 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 2195800 T8212 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 2195800 T8212 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: .\solr.cloud.SyncSliceTest-570B0D7AB46D86C7-001\tempDir-004
[junit4] 2> 2195800 T8212 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '.\solr.cloud.SyncSliceTest-570B0D7AB46D86C7-001\tempDir-004\'
[junit4] 2> 2195833 T8212 oasc.ConfigSolr.fromFile Loading container configuration from C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solr.cloud.SyncSliceTest-570B0D7AB46D86C7-001\tempDir-004\solr.xml
[junit4] 2> 2195845 T8212 oasc.CoreContainer.<init> New CoreContainer 292854391
[junit4] 2> 2195845 T8212 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=.\solr.cloud.SyncSliceTest-570B0D7AB46D86C7-001\tempDir-004\]
[junit4] 2> 2195846 T8212 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 2195846 T8212 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 2195846 T8212 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 2195847 T8212 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 2195847 T8212 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 2195847 T8212 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 2195849 T8212 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 2195849 T8212 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 2195849 T8212 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 2195850 T8212 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 2195850 T8212 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 2195850 T8212 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 2195851 T8212 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:50660/solr
[junit4] 2> 2195851 T8212 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 2195853 T8212 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2195862 T8272 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@68ff950d name:ZooKeeperConnection Watcher:127.0.0.1:50660 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2195863 T8212 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2195868 T8214 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x147004c5cad0007, 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> 2195871 T8212 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2195873 T8274 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6f7e2ce3 name:ZooKeeperConnection Watcher:127.0.0.1:50660/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2195873 T8212 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2195893 T8212 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 2196939 T8212 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:50688__ufl%2Fj
[junit4] 2> 2196941 T8212 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:50688__ufl%2Fj
[junit4] 2> 2196946 T8234 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 2196947 T8256 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 2196947 T8243 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 2196947 T8274 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 2196955 T8275 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
[junit4] 2> 2196956 T8275 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 2196957 T8275 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 2196957 T8234 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2196957 T8234 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2196957 T8234 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2196959 T8235 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2196962 T8235 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:50688/_ufl/j",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:50688__ufl%2Fj",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":null}
[junit4] 2> 2196962 T8235 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=1
[junit4] 2> 2196962 T8235 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 2196967 T8234 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2196968 T8234 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> 2196968 T8243 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> 2196969 T8274 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> 2196968 T8256 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> 2197997 T8275 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 2197997 T8275 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 2197998 T8275 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 2197998 T8275 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 2198000 T8275 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 2198001 T8275 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '.\solr.cloud.SyncSliceTest-570B0D7AB46D86C7-001\tempDir-004\collection1\'
[junit4] 2> 2198003 T8275 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/solr.cloud.SyncSliceTest-570B0D7AB46D86C7-001/tempDir-004/collection1/lib/.svn/' to classloader
[junit4] 2> 2198005 T8275 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/solr.cloud.SyncSliceTest-570B0D7AB46D86C7-001/tempDir-004/collection1/lib/classes/' to classloader
[junit4] 2> 2198006 T8275 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/solr.cloud.SyncSliceTest-570B0D7AB46D86C7-001/tempDir-004/collection1/lib/README' to classloader
[junit4] 2> 2198049 T8275 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_4_10
[junit4] 2> 2198056 T8275 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 2198060 T8275 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 2198064 T8275 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 2198165 T8275 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 2198165 T8275 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 2198166 T8275 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 2198174 T8275 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 2198176 T8275 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 2198192 T8275 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 2198195 T8275 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 2198198 T8275 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 2198200 T8275 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 2198200 T8275 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 2198201 T8275 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 2198202 T8275 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 2198202 T8275 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 2198203 T8275 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection collection1
[junit4] 2> 2198203 T8275 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 2198203 T8275 oasc.SolrCore.<init> [collection1] Opening new SolrCore at .\solr.cloud.SyncSliceTest-570B0D7AB46D86C7-001\tempDir-004\collection1\, dataDir=.\solr.cloud.SyncSliceTest-570B0D7AB46D86C7-001\tempDir-001/jetty2\
[junit4] 2> 2198203 T8275 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@5cb36c56
[junit4] 2> 2198205 T8275 oasc.CachingDirectoryFactory.get return new directory for .\solr.cloud.SyncSliceTest-570B0D7AB46D86C7-001\tempDir-001/jetty2\
[junit4] 2> 2198205 T8275 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\solr.cloud.SyncSliceTest-570B0D7AB46D86C7-001\tempDir-001/jetty2\index/
[junit4] 2> 2198205 T8275 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '.\solr.cloud.SyncSliceTest-570B0D7AB46D86C7-001\tempDir-001\jetty2\index' doesn't exist. Creating new index...
[junit4] 2> 2198205 T8275 oasc.CachingDirectoryFactory.get return new directory for .\solr.cloud.SyncSliceTest-570B0D7AB46D86C7-001\tempDir-001/jetty2\index
[junit4] 2> 2198207 T8275 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=12, maxMergeAtOnceExplicit=46, maxMergedSegmentMB=7.7900390625, floorSegmentMB=0.86328125, forceMergeDeletesPctAllowed=5.161321432597553, segmentsPerTier=20.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 2198207 T8275 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@33929136 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1b4b8580),segFN=segments_1,generation=1}
[junit4] 2> 2198207 T8275 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 2198210 T8275 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 2198210 T8275 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 2198211 T8275 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 2198211 T8275 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 2198211 T8275 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 2198211 T8275 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 2198212 T8275 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 2198212 T8275 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 2198212 T8275 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 2198212 T8275 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 2198213 T8275 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 2198213 T8275 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 2198213 T8275 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 2198214 T8275 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 2198214 T8275 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 2198222 T8275 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 2198227 T8275 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 2198231 T8275 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 2198231 T8275 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 2198231 T8275 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=31, maxMergeAtOnceExplicit=26, maxMergedSegmentMB=25.5576171875, floorSegmentMB=0.8564453125, forceMergeDeletesPctAllowed=10.111174969491634, segmentsPerTier=27.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.764443888052419
[junit4] 2> 2198232 T8275 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@33929136 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1b4b8580),segFN=segments_1,generation=1}
[junit4] 2> 2198232 T8275 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 2198232 T8275 oass.SolrIndexSearcher.<init> Opening Searcher@5fed9d24[collection1] main
[junit4] 2> 2198233 T8275 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 2198235 T8275 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 2198235 T8275 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
[junit4] 2> 2198236 T8275 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 2198236 T8275 oasr.RestManager.init Initializing RestManager with initArgs: {}
[junit4] 2> 2198236 T8275 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 2198237 T8275 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
[junit4] 2> 2198237 T8275 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 2198237 T8275 oasr.ManagedResource.notifyObserversDuringInit WARN No registered observers for /rest/managed
[junit4] 2> 2198237 T8275 oasr.RestManager.init Initializing 0 registered ManagedResources
[junit4] 2> 2198240 T8276 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@5fed9d24[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 2198241 T8275 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 2198243 T8279 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:50688/_ufl/j collection:collection1 shard:shard1
[junit4] 2> 2198243 T8212 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0
[junit4] 2> 2198243 T8212 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 2198249 T8279 oasc.ZkController.register We are http://127.0.0.1:50688/_ufl/j/collection1/ and leader is http://127.0.0.1:50679/_ufl/j/collection1/
[junit4] 2> 2198249 T8279 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:50688/_ufl/j
[junit4] 2> 2198249 T8279 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4] 2> 2198249 T8279 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4] 2> ASYNC NEW_CORE C1673 name=collection1 org.apache.solr.core.SolrCore@4313d68b url=http://127.0.0.1:50688/_ufl/j/collection1 node=127.0.0.1:50688__ufl%2Fj C1673_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:50688/_ufl/j, core=collection1, node_name=127.0.0.1:50688__ufl%2Fj}
[junit4] 2> 2198250 T8280 C1673 P50688 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4] 2> 2198250 T8280 C1673 P50688 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4] 2> 2198251 T8280 C1673 P50688 oasc.RecoveryStrategy.doRecovery Publishing state of core collection1 as recovering, leader is http://127.0.0.1:50679/_ufl/j/collection1/ and I am http://127.0.0.1:50688/_ufl/j/collection1/
[junit4] 2> 2198251 T8280 C1673 P50688 oasc.ZkController.publish publishing core=collection1 state=recovering collection=collection1
[junit4] 2> 2198251 T8280 C1673 P50688 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 2198252 T8279 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2198255 T8234 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2198256 T8280 C1673 P50688 oasc.RecoveryStrategy.sendPrepRecoveryCmd Sending prep recovery command to http://127.0.0.1:50679/_ufl/j; WaitForState: action=PREPRECOVERY&core=collection1&nodeName=127.0.0.1%3A50688__ufl%252Fj&coreNodeName=core_node2&state=recovering&checkLive=true&onlyIfLeader=true&onlyIfLeaderActive=true
[junit4] 2> 2198259 T8251 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: core_node2, state: recovering, checkLive: true, onlyIfLeader: true, onlyIfLeaderActive: true
[junit4] 2> 2198260 T8235 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2198261 T8251 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2198262 T8251 oasha.CoreAdminHandler.handleWaitForStateAction Will wait a max of 183 seconds to see collection1 (shard1 of collection1) have state: recovering
[junit4] 2> 2198262 T8251 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:50688__ufl%2Fj, coreNodeName=core_node2, onlyIfActiveCheckResult=false, nodeProps: core_node2:{"state":"down","base_url":"http://127.0.0.1:50688/_ufl/j","core":"collection1","node_name":"127.0.0.1:50688__ufl%2Fj"}
[junit4] 2> 2198263 T8235 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:50688/_ufl/j",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:50688__ufl%2Fj",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":"core_node2"}
[junit4] 2> 2198268 T8234 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2198378 T8256 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> 2198378 T8234 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> 2198379 T8243 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> 2198379 T8274 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> 2199302 T8251 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:50688__ufl%2Fj, coreNodeName=core_node2, onlyIfActiveCheckResult=false, nodeProps: core_node2:{"state":"recovering","base_url":"http://127.0.0.1:50688/_ufl/j","core":"collection1","node_name":"127.0.0.1:50688__ufl%2Fj"}
[junit4] 2> 2199302 T8251 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: core_node2, state: recovering, checkLive: true, onlyIfLeader: true for: 1 seconds.
[junit4] 2> 2199302 T8251 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={nodeName=127.0.0.1:50688__ufl%252Fj&onlyIfLeaderActive=true&core=collection1&coreNodeName=core_node2&action=PREPRECOVERY&checkLive=true&state=recovering&onlyIfLeader=true&wt=javabin&version=2} status=0 QTime=1043
[junit4] 2> 2200109 T8212 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 3
[junit4] 2> 2200110 T8212 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 2200114 T8212 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:50698
[junit4] 2> 2200115 T8212 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 2200116 T8212 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 2200116 T8212 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solr.cloud.SyncSliceTest-570B0D7AB46D86C7-001\tempDir-005
[junit4] 2> 2200116 T8212 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solr.cloud.SyncSliceTest-570B0D7AB46D86C7-001\tempDir-005\'
[junit4] 2> 2200149 T8212 oasc.ConfigSolr.fromFile Loading container configuration from C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solr.cloud.SyncSliceTest-570B0D7AB46D86C7-001\tempDir-005\solr.xml
[junit4] 2> 2200161 T8212 oasc.CoreContainer.<init> New CoreContainer 535411066
[junit4] 2> 2200162 T8212 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solr.cloud.SyncSliceTest-570B0D7AB46D86C7-001\tempDir-005\]
[junit4] 2> 2200162 T8212 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 2200163 T8212 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 2200163 T8212 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 2200163 T8212 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 2200164 T8212 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 2200164 T8212 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 2200164 T8212 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 2200164 T8212 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 2200165 T8212 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 2200165 T8212 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 2200166 T8212 oasl.LogWatcher.newRegisteredLogWatch
[...truncated too long message...]
ter state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4] 2> 2269655 T8315 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 2269655 T8315 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 2269657 T8315 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:358)
[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=570B0D7AB46D86C7 -Dtests.slow=true -Dtests.locale=cs -Dtests.timezone=Europe/Sarajevo -Dtests.file.encoding=UTF-8
[junit4] ERROR 83.3s | SyncSliceTest.testDistribSearch <<<
[junit4] > Throwable #1: org.apache.solr.client.solrj.SolrServerException: No live SolrServers available to handle this request
[junit4] > at __randomizedtesting.SeedInfo.seed([570B0D7AB46D86C7:D6ED8362C332E6FB]: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:659)
[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:1149)
[junit4] > at org.apache.solr.cloud.AbstractFullDistribZkTestBase.checkShardConsistency(AbstractFullDistribZkTestBase.java:1118)
[junit4] > at org.apache.solr.cloud.SyncSliceTest.doTest(SyncSliceTest.java:236)
[junit4] > at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:865)
[junit4] > at java.lang.Thread.run(Thread.java:745)
[junit4] 2> 2269667 T8212 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> NOTE: leaving temporary files on disk at: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solr.cloud.SyncSliceTest-570B0D7AB46D86C7-001
[junit4] 2> NOTE: test params are: codec=Lucene41, sim=RandomSimilarityProvider(queryNorm=true,coord=no): {}, locale=cs, timezone=Europe/Sarajevo
[junit4] 2> NOTE: Windows 7 6.1 amd64/Oracle Corporation 1.8.0_05 (64-bit)/cpus=2,threads=1,free=172730984,total=421003264
[junit4] 2> NOTE: All tests run in this JVM: [DirectUpdateHandlerOptimizeTest, CacheHeaderTest, TestChildDocTransformer, ResourceLoaderTest, TestNRTOpen, SolrTestCaseJ4Test, RankQueryTest, TestSort, TestCoreDiscovery, AliasIntegrationTest, CoreContainerCoreInitFailuresTest, BinaryUpdateRequestHandlerTest, TestAddFieldRealTimeGet, PeerSyncTest, TestSchemaResource, SuggesterFSTTest, DefaultValueUpdateProcessorTest, HdfsBasicDistributedZk2Test, SchemaVersionSpecificBehaviorTest, TestRestManager, DistributedQueryComponentOptimizationTest, HdfsDirectoryTest, QueryResultKeyTest, TestPHPSerializedResponseWriter, TestComplexPhraseQParserPlugin, TestFastLRUCache, AddSchemaFieldsUpdateProcessorFactoryTest, TestImplicitCoreProperties, TestDistributedGrouping, PreAnalyzedUpdateProcessorTest, TestCloudManagedSchema, TestBM25SimilarityFactory, TestReloadAndDeleteDocs, TestQuerySenderNoQuery, StressHdfsTest, InfoHandlerTest, SuggestComponentTest, TestBlendedInfixSuggestions, CursorPagingTest, TestRTGBase, TestBinaryField, TestConfigSets, QueryElevationComponentTest, ShardRoutingTest, TestCloudManagedSchemaConcurrent, AnalyticsMergeStrategyTest, TestDefaultSearchFieldResource, OverseerRolesTest, UpdateParamsTest, TestMultiCoreConfBootstrap, TestSolrCoreProperties, TestCSVLoader, TestSolrIndexConfig, TestLMDirichletSimilarityFactory, TestZkChroot, TestComponentsName, TestQueryUtils, TestDocumentBuilder, PolyFieldTest, ShardSplitTest, TestHighlightDedupGrouping, PluginInfoTest, SuggesterTSTTest, SliceStateTest, TestManagedResourceStorage, TestShardHandlerFactory, TermVectorComponentDistributedTest, TestDynamicFieldCollectionResource, HdfsCollectionsAPIDistributedZkTest, TestAtomicUpdateErrorCases, TestRealTimeGet, TestConfig, HdfsSyncSliceTest, TestManagedSchema, OverseerCollectionProcessorTest, TestCodecSupport, SignatureUpdateProcessorFactoryTest, TestSystemIdResolver, FileUtilsTest, ChangedSchemaMergeTest, TestSimpleQParserPlugin, TestSolrXml, HdfsBasicDistributedZkTest, NumericFieldsTest, IndexSchemaTest, DirectUpdateHandlerTest, AnalysisErrorHandlingTest, HdfsRecoveryZkTest, DistributedTermsComponentTest, EchoParamsTest, TestSolrQueryParserDefaultOperatorResource, DocValuesMissingTest, MinimalSchemaTest, ScriptEngineTest, QueryEqualityTest, MultiTermTest, TestLMJelinekMercerSimilarityFactory, TestHighFrequencyDictionaryFactory, TestSearcherReuse, TestCollationFieldDocValues, TestCopyFieldCollectionResource, AsyncMigrateRouteKeyTest, SearchHandlerTest, NotRequiredUniqueKeyTest, TestSolrQueryParser, TestFieldTypeCollectionResource, CSVRequestHandlerTest, ChaosMonkeyNothingIsSafeTest, AssignTest, MergeStrategyTest, OpenExchangeRatesOrgProviderTest, TestMiniSolrCloudCluster, SpellCheckCollatorTest, DistributedQueryComponentCustomSortTest, HdfsLockFactoryTest, TestPerFieldSimilarity, TestJmxMonitoredMap, TestManagedResource, TestInitQParser, ChaosMonkeySafeLeaderTest, DistributedDebugComponentTest, DebugComponentTest, TestLRUCache, TestDistribDocBasedVersion, TestSearchPerf, BadIndexSchemaTest, OutputWriterTest, DateFieldTest, QueryParsingTest, DocValuesMultiTest, SolrRequestParserTest, DistribDocExpirationUpdateProcessorTest, HdfsUnloadDistributedZkTest, TestClassNameShortening, DocValuesTest, ZkSolrClientTest, DocumentBuilderTest, TestFileDictionaryLookup, RegexBoostProcessorTest, TestFuzzyAnalyzedSuggestions, JSONWriterTest, TestPartialUpdateDeduplication, TestWordDelimiterFilterFactory, SpatialFilterTest, TestSolrDeletionPolicy1, TestFieldSortValues, DistanceFunctionTest, DateMathParserTest, CopyFieldTest, TestUtils, TestCoreContainer, OverseerStatusTest, TestSolrQueryParserResource, SolrCmdDistributorTest, TestNonNRTOpen, TestWriterPerf, ConnectionManagerTest, SolrCoreCheckLockOnStartupTest, TestStressVersions, ResponseHeaderTest, AlternateDirectoryTest, SimplePostToolTest, RAMDirectoryFactoryTest, TestValueSourceCache, UpdateRequestProcessorFactoryTest, BadComponentTest, DistribCursorPagingTest, AnalyticsQueryTest, TestIndexSearcher, DirectSolrConnectionTest, DistributedSuggestComponentTest, ZkCLITest, RequestHandlersTest, TestGroupingSearch, TermsComponentTest, TestDocSet, TestFunctionQuery, AddBlockUpdateTest, TestSchemaSimilarityResource, PreAnalyzedFieldTest, SynonymTokenizerTest, RequiredFieldsTest, TestSolrDeletionPolicy2, FullSolrCloudDistribCmdsTest, DirectSolrSpellCheckerTest, TestJoin, TestNoOpRegenerator, SpellingQueryConverterTest, HttpPartitionTest, TestCursorMarkWithoutUniqueKey, LukeRequestHandlerTest, NoCacheHeaderTest, EnumFieldTest, MultiThreadedOCPTest, BasicDistributedZkTest, BasicDistributedZk2Test, UnloadDistributedZkTest, CollectionsAPIDistributedZkTest, SyncSliceTest]
[junit4] Completed in 83.28s, 1 test, 1 error <<< FAILURES!
[...truncated 628 lines...]
BUILD FAILED
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\build.xml:467: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\build.xml:447: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\build.xml:45: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\extra-targets.xml:37: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build.xml:189: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\common-build.xml:496: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\lucene\common-build.xml:1299: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\lucene\common-build.xml:923: There were test failures: 404 suites, 1654 tests, 1 error, 42 ignored (21 assumptions)
Total time: 106 minutes 28 seconds
Build step 'Invoke Ant' marked build as failure
[description-setter] Description set: Java: 64bit/jdk1.8.0_05 -XX:+UseCompressedOops -XX:+UseParallelGC
Archiving artifacts
Recording test results
Email was triggered for: Failure - Any
Sending email for trigger: Failure - Any