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/03 16:21:40 UTC
[JENKINS] Lucene-Solr-4.x-Windows (64bit/jdk1.8.0_05) - Build #
4069 - Failure!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-Windows/4069/
Java: 64bit/jdk1.8.0_05 -XX:-UseCompressedOops -XX:+UseConcMarkSweepGC
All tests passed
Build Log:
[...truncated 44872 lines...]
-documentation-lint:
[echo] checking for broken html...
[jtidy] Checking for broken html (such as invalid tags)...
[delete] Deleting directory C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\lucene\build\jtidy_tmp
[echo] Checking for broken links...
[exec]
[exec] Crawl/parse...
[exec]
[exec] Verify...
[echo] Checking for missing docs...
[exec] Traceback (most recent call last):
[exec] File "C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\dev-tools/scripts/checkJavaDocs.py", line 371, in <module>
[exec] if checkPackageSummaries(sys.argv[1], level):
[exec] File "C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\dev-tools/scripts/checkJavaDocs.py", line 351, in checkPackageSummaries
[exec] if checkClassSummaries(fullPath):
[exec] File "C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\dev-tools/scripts/checkJavaDocs.py", line 215, in checkClassSummaries
[exec] missing.append((lastCaption, unEscapeURL(lastItem)))
[exec] File "C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\dev-tools/scripts/checkJavaDocs.py", line 303, in unEscapeURL
[exec] s = s.replace('%20', ' ')
[exec] AttributeError: 'NoneType' object has no attribute 'replace'
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:63: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\lucene\build.xml:212: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\lucene\build.xml:247: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\lucene\common-build.xml:2338: exec returned: 1
Total time: 128 minutes 15 seconds
Build step 'Invoke Ant' marked build as failure
[description-setter] Description set: Java: 64bit/jdk1.8.0_05 -XX:-UseCompressedOops -XX:+UseConcMarkSweepGC
Archiving artifacts
Recording test results
Email was triggered for: Failure - Any
Sending email for trigger: Failure - Any
[JENKINS] Lucene-Solr-4.x-Windows (64bit/jdk1.8.0_05) - Build #
4071 - Still Failing!
Posted by Policeman Jenkins Server <je...@thetaphi.de>.
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
[JENKINS] Lucene-Solr-4.x-Windows (32bit/jdk1.8.0_20-ea-b15) -
Build # 4070 - Still Failing!
Posted by Policeman Jenkins Server <je...@thetaphi.de>.
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-Windows/4070/
Java: 32bit/jdk1.8.0_20-ea-b15 -client -XX:+UseParallelGC
1 tests failed.
REGRESSION: org.apache.solr.cloud.SyncSliceTest.testDistribSearch
Error Message:
No live SolrServers available to handle this request
Stack Trace:
org.apache.solr.client.solrj.SolrServerException: No live SolrServers available to handle this request
at __randomizedtesting.SeedInfo.seed([8EC19F4B1F713221:F271153682E521D]: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.GeneratedMethodAccessor39.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 11547 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-8EC19F4B1F713221-001\init-core-data-001
[junit4] 2> 2059029 T7695 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (false) and clientAuth (true)
[junit4] 2> 2059029 T7695 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
[junit4] 2> 2059043 T7695 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4] 2> 2059045 T7695 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 2059047 T7696 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 2059140 T7695 oasc.ZkTestServer.run start zk server on port:60596
[junit4] 2> 2059142 T7695 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2059152 T7702 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@140e4ec name:ZooKeeperConnection Watcher:127.0.0.1:60596 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2059154 T7695 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2059154 T7695 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 2059175 T7695 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2059179 T7704 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@515939 name:ZooKeeperConnection Watcher:127.0.0.1:60596/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2059180 T7695 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2059180 T7695 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4] 2> 2059187 T7695 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4] 2> 2059192 T7695 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4] 2> 2059197 T7695 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4] 2> 2059203 T7695 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> 2059205 T7695 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4] 2> 2059216 T7695 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> 2059216 T7695 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4] 2> 2059225 T7695 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> 2059225 T7695 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 2059231 T7695 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> 2059231 T7695 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4] 2> 2059239 T7695 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> 2059239 T7695 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4] 2> 2059245 T7695 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> 2059246 T7695 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4] 2> 2059251 T7695 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> 2059251 T7695 oascc.SolrZkClient.makePath makePath: /configs/conf1/enumsConfig.xml
[junit4] 2> 2059258 T7695 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> 2059258 T7695 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4] 2> 2059265 T7695 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> 2059266 T7695 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 2059272 T7695 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> 2059272 T7695 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4] 2> 2059277 T7695 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> 2059278 T7695 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4] 2> 2061188 T7695 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 2061207 T7695 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:60603
[junit4] 2> 2061208 T7695 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 2061209 T7695 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 2061209 T7695 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: .\solr.cloud.SyncSliceTest-8EC19F4B1F713221-001\tempDir-002
[junit4] 2> 2061209 T7695 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '.\solr.cloud.SyncSliceTest-8EC19F4B1F713221-001\tempDir-002\'
[junit4] 2> 2061269 T7695 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-8EC19F4B1F713221-001\tempDir-002\solr.xml
[junit4] 2> 2061295 T7695 oasc.CoreContainer.<init> New CoreContainer 19209101
[junit4] 2> 2061295 T7695 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=.\solr.cloud.SyncSliceTest-8EC19F4B1F713221-001\tempDir-002\]
[junit4] 2> 2061297 T7695 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 2061297 T7695 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 2061297 T7695 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 2061297 T7695 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 2061297 T7695 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 2061297 T7695 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 2061299 T7695 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 2061299 T7695 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 2061299 T7695 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 2061299 T7695 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 2061301 T7695 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 2061301 T7695 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 2061301 T7695 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:60596/solr
[junit4] 2> 2061301 T7695 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 2061304 T7695 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2061318 T7715 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1539b2c name:ZooKeeperConnection Watcher:127.0.0.1:60596 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2061319 T7695 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2061323 T7695 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2061326 T7717 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@a5c610 name:ZooKeeperConnection Watcher:127.0.0.1:60596/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2061327 T7695 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2061328 T7695 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 2061334 T7695 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 2061339 T7695 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 2061345 T7695 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 2061350 T7695 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 2061355 T7695 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 2061358 T7695 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:60603_
[junit4] 2> 2061360 T7695 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:60603_
[junit4] 2> 2061365 T7695 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 2061368 T7695 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 2061375 T7695 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:60603_
[junit4] 2> 2061375 T7695 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 2061378 T7695 oasc.Overseer.start Overseer (id=92040462515503107-127.0.0.1:60603_-n_0000000000) starting
[junit4] 2> 2061384 T7695 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 2061400 T7719 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 2061401 T7695 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 2061405 T7695 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 2061408 T7695 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 2061413 T7718 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 2061419 T7720 oasc.ZkController.publish publishing core=collection1 state=down collection=control_collection
[junit4] 2> 2061419 T7720 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 2061421 T7720 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 2061421 T7717 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2061423 T7718 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2061424 T7718 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:60603",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:60603_",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"control_collection",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":null}
[junit4] 2> 2061424 T7718 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1]
[junit4] 2> 2061429 T7718 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 2061433 T7717 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2061434 T7717 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> 2062350 T7720 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 2062350 T7720 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4] 2> 2062352 T7720 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 2062352 T7720 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
[junit4] 2> 2062353 T7720 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 2062353 T7720 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '.\solr.cloud.SyncSliceTest-8EC19F4B1F713221-001\tempDir-002\collection1\'
[junit4] 2> 2062356 T7720 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/solr.cloud.SyncSliceTest-8EC19F4B1F713221-001/tempDir-002/collection1/lib/.svn/' to classloader
[junit4] 2> 2062358 T7720 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/solr.cloud.SyncSliceTest-8EC19F4B1F713221-001/tempDir-002/collection1/lib/classes/' to classloader
[junit4] 2> 2062360 T7720 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/solr.cloud.SyncSliceTest-8EC19F4B1F713221-001/tempDir-002/collection1/lib/README' to classloader
[junit4] 2> 2062422 T7720 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_4_10
[junit4] 2> 2062440 T7720 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 2062442 T7720 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 2062484 T7720 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 2062657 T7720 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 2062657 T7720 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 2062659 T7720 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 2062669 T7720 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 2062669 T7720 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 2062700 T7720 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 2062706 T7720 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 2062712 T7720 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 2062715 T7720 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 2062715 T7720 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 2062716 T7720 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 2062718 T7720 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 2062718 T7720 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 2062718 T7720 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection control_collection
[junit4] 2> 2062718 T7720 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 2062720 T7720 oasc.SolrCore.<init> [collection1] Opening new SolrCore at .\solr.cloud.SyncSliceTest-8EC19F4B1F713221-001\tempDir-002\collection1\, dataDir=.\solr.cloud.SyncSliceTest-8EC19F4B1F713221-001\tempDir-001/control/data\
[junit4] 2> 2062720 T7720 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1b72d26
[junit4] 2> 2062722 T7720 oasc.CachingDirectoryFactory.get return new directory for .\solr.cloud.SyncSliceTest-8EC19F4B1F713221-001\tempDir-001/control/data\
[junit4] 2> 2062722 T7720 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\solr.cloud.SyncSliceTest-8EC19F4B1F713221-001\tempDir-001/control/data\index/
[junit4] 2> 2062722 T7720 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '.\solr.cloud.SyncSliceTest-8EC19F4B1F713221-001\tempDir-001\control\data\index' doesn't exist. Creating new index...
[junit4] 2> 2062723 T7720 oasc.CachingDirectoryFactory.get return new directory for .\solr.cloud.SyncSliceTest-8EC19F4B1F713221-001\tempDir-001/control/data\index
[junit4] 2> 2062724 T7720 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=40, maxMergeAtOnceExplicit=43, maxMergedSegmentMB=58.9296875, floorSegmentMB=1.8408203125, forceMergeDeletesPctAllowed=7.305760150884263, segmentsPerTier=48.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.86311055422684
[junit4] 2> 2062725 T7720 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@51c96e lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@c66332),segFN=segments_1,generation=1}
[junit4] 2> 2062725 T7720 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 2062730 T7720 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 2062731 T7720 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 2062731 T7720 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 2062732 T7720 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 2062732 T7720 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 2062732 T7720 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 2062733 T7720 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 2062733 T7720 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 2062733 T7720 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 2062734 T7720 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 2062736 T7720 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 2062736 T7720 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 2062736 T7720 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 2062737 T7720 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 2062737 T7720 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 2062738 T7720 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 2062745 T7720 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 2062751 T7720 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 2062751 T7720 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 2062752 T7720 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=17, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
[junit4] 2> 2062753 T7720 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@51c96e lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@c66332),segFN=segments_1,generation=1}
[junit4] 2> 2062753 T7720 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 2062754 T7720 oass.SolrIndexSearcher.<init> Opening Searcher@17b3e95[collection1] main
[junit4] 2> 2062754 T7720 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
[junit4] 2> 2062755 T7720 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 2062756 T7720 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
[junit4] 2> 2062757 T7720 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 2062758 T7720 oasr.RestManager.init Initializing RestManager with initArgs: {}
[junit4] 2> 2062758 T7720 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 2062759 T7720 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
[junit4] 2> 2062759 T7720 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 2062759 T7720 oasr.ManagedResource.notifyObserversDuringInit WARN No registered observers for /rest/managed
[junit4] 2> 2062759 T7720 oasr.RestManager.init Initializing 0 registered ManagedResources
[junit4] 2> 2062765 T7720 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 2062767 T7721 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@17b3e95[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 2062769 T7724 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:60603 collection:control_collection shard:shard1
[junit4] 2> 2062770 T7695 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0
[junit4] 2> 2062770 T7695 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 2062772 T7724 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4] 2> 2062774 T7695 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2062776 T7726 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1c5b1e2 name:ZooKeeperConnection Watcher:127.0.0.1:60596/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2062777 T7695 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2062780 T7695 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 2062785 T7724 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 2062786 T7695 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:false
[junit4] 2> 2062790 T7717 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2062793 T7724 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 2062793 T7724 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> ASYNC NEW_CORE C1334 name=collection1 org.apache.solr.core.SolrCore@1cf8e34 url=http://127.0.0.1:60603/collection1 node=127.0.0.1:60603_ C1334_STATE=coll:control_collection core:collection1 props:{state=down, base_url=http://127.0.0.1:60603, core=collection1, node_name=127.0.0.1:60603_}
[junit4] 2> 2062793 T7724 C1334 P60603 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:60603/collection1/
[junit4] 2> 2062793 T7724 C1334 P60603 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 2062793 T7724 C1334 P60603 oasc.SyncStrategy.syncToMe http://127.0.0.1:60603/collection1/ has no replicas
[junit4] 2> 2062793 T7724 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:60603/collection1/ shard1
[junit4] 2> 2062794 T7724 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4] 2> 2062797 T7718 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2062805 T7717 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2062810 T7717 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2062819 T7717 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2062917 T7717 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> 2062917 T7726 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> 2062957 T7724 oasc.ZkController.register We are http://127.0.0.1:60603/collection1/ and leader is http://127.0.0.1:60603/collection1/
[junit4] 2> 2062957 T7724 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:60603
[junit4] 2> 2062957 T7724 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 2062957 T7724 oasc.ZkController.publish publishing core=collection1 state=active collection=control_collection
[junit4] 2> 2062957 T7724 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 2062966 T7717 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2062966 T7717 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2062967 T7717 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2062970 T7724 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2062973 T7718 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2062980 T7718 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:60603",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:60603_",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"control_collection",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 2062987 T7717 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2063090 T7717 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> 2063091 T7726 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> 2065212 T7695 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 1
[junit4] 2> 2065214 T7695 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 2065221 T7695 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:60615
[junit4] 2> 2065222 T7695 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 2065222 T7695 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 2065225 T7695 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: .\solr.cloud.SyncSliceTest-8EC19F4B1F713221-001\tempDir-003
[junit4] 2> 2065225 T7695 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '.\solr.cloud.SyncSliceTest-8EC19F4B1F713221-001\tempDir-003\'
[junit4] 2> 2065285 T7695 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-8EC19F4B1F713221-001\tempDir-003\solr.xml
[junit4] 2> 2065332 T7695 oasc.CoreContainer.<init> New CoreContainer 30267164
[junit4] 2> 2065333 T7695 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=.\solr.cloud.SyncSliceTest-8EC19F4B1F713221-001\tempDir-003\]
[junit4] 2> 2065337 T7695 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 2065337 T7695 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 2065337 T7695 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 2065337 T7695 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 2065340 T7695 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 2065340 T7695 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 2065340 T7695 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 2065340 T7695 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 2065342 T7695 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 2065342 T7695 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 2065343 T7695 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 2065343 T7695 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 2065346 T7695 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:60596/solr
[junit4] 2> 2065346 T7695 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 2065348 T7695 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2065372 T7737 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1e2afef name:ZooKeeperConnection Watcher:127.0.0.1:60596 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2065373 T7695 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2065391 T7695 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2065394 T7739 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@d42b8e name:ZooKeeperConnection Watcher:127.0.0.1:60596/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2065394 T7695 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2065430 T7695 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 2066431 T7695 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:60615_
[junit4] 2> 2066433 T7695 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:60615_
[junit4] 2> 2066441 T7717 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 2066441 T7726 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 2066443 T7739 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 2066461 T7740 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
[junit4] 2> 2066464 T7740 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 2066467 T7717 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2066468 T7740 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 2066468 T7717 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2066469 T7717 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2066472 T7718 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2066474 T7718 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:60615",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:60615_",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":null}
[junit4] 2> 2066474 T7718 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1]
[junit4] 2> 2066474 T7718 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 2066480 T7717 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2066482 T7717 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> 2066483 T7739 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> 2066483 T7726 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> 2067488 T7740 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 2067488 T7740 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 2067490 T7740 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 2067490 T7740 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 2067492 T7740 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 2067492 T7740 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '.\solr.cloud.SyncSliceTest-8EC19F4B1F713221-001\tempDir-003\collection1\'
[junit4] 2> 2067494 T7740 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/solr.cloud.SyncSliceTest-8EC19F4B1F713221-001/tempDir-003/collection1/lib/.svn/' to classloader
[junit4] 2> 2067496 T7740 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/solr.cloud.SyncSliceTest-8EC19F4B1F713221-001/tempDir-003/collection1/lib/classes/' to classloader
[junit4] 2> 2067496 T7740 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/solr.cloud.SyncSliceTest-8EC19F4B1F713221-001/tempDir-003/collection1/lib/README' to classloader
[junit4] 2> 2067558 T7740 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_4_10
[junit4] 2> 2067579 T7740 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 2067583 T7740 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 2067602 T7740 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 2067794 T7740 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 2067794 T7740 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 2067796 T7740 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 2067808 T7740 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 2067808 T7740 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 2067844 T7740 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 2067851 T7740 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 2067856 T7740 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 2067859 T7740 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 2067860 T7740 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 2067860 T7740 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 2067862 T7740 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 2067862 T7740 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 2067863 T7740 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection collection1
[junit4] 2> 2067863 T7740 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 2067863 T7740 oasc.SolrCore.<init> [collection1] Opening new SolrCore at .\solr.cloud.SyncSliceTest-8EC19F4B1F713221-001\tempDir-003\collection1\, dataDir=.\solr.cloud.SyncSliceTest-8EC19F4B1F713221-001\tempDir-001/jetty1\
[junit4] 2> 2067864 T7740 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1b72d26
[junit4] 2> 2067865 T7740 oasc.CachingDirectoryFactory.get return new directory for .\solr.cloud.SyncSliceTest-8EC19F4B1F713221-001\tempDir-001/jetty1\
[junit4] 2> 2067865 T7740 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\solr.cloud.SyncSliceTest-8EC19F4B1F713221-001\tempDir-001/jetty1\index/
[junit4] 2> 2067866 T7740 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '.\solr.cloud.SyncSliceTest-8EC19F4B1F713221-001\tempDir-001\jetty1\index' doesn't exist. Creating new index...
[junit4] 2> 2067866 T7740 oasc.CachingDirectoryFactory.get return new directory for .\solr.cloud.SyncSliceTest-8EC19F4B1F713221-001\tempDir-001/jetty1\index
[junit4] 2> 2067867 T7740 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=40, maxMergeAtOnceExplicit=43, maxMergedSegmentMB=58.9296875, floorSegmentMB=1.8408203125, forceMergeDeletesPctAllowed=7.305760150884263, segmentsPerTier=48.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.86311055422684
[junit4] 2> 2067868 T7740 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@6c34fe lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1e1ce24),segFN=segments_1,generation=1}
[junit4] 2> 2067868 T7740 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 2067875 T7740 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 2067876 T7740 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 2067876 T7740 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 2067877 T7740 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 2067877 T7740 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 2067877 T7740 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 2067878 T7740 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 2067879 T7740 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 2067879 T7740 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 2067880 T7740 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 2067882 T7740 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 2067882 T7740 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 2067883 T7740 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 2067884 T7740 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 2067884 T7740 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 2067886 T7740 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 2067897 T7740 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 2067901 T7740 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 2067901 T7740 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 2067903 T7740 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=17, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
[junit4] 2> 2067904 T7740 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@6c34fe lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1e1ce24),segFN=segments_1,generation=1}
[junit4] 2> 2067904 T7740 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 2067904 T7740 oass.SolrIndexSearcher.<init> Opening Searcher@10af6e1[collection1] main
[junit4] 2> 2067904 T7740 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 2067908 T7740 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 2067908 T7740 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
[junit4] 2> 2067909 T7740 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 2067910 T7740 oasr.RestManager.init Initializing RestManager with initArgs: {}
[junit4] 2> 2067910 T7740 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 2067912 T7740 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
[junit4] 2> 2067912 T7740 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 2067912 T7740 oasr.ManagedResource.notifyObserversDuringInit WARN No registered observers for /rest/managed
[junit4] 2> 2067913 T7740 oasr.RestManager.init Initializing 0 registered ManagedResources
[junit4] 2> 2067922 T7741 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@10af6e1[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 2067927 T7740 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 2067929 T7744 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:60615 collection:collection1 shard:shard1
[junit4] 2> 2067930 T7695 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0
[junit4] 2> 2067931 T7695 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 2067933 T7744 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 2067954 T7744 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 2067970 T7717 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2067972 T7744 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 2067972 T7744 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> ASYNC NEW_CORE C1335 name=collection1 org.apache.solr.core.SolrCore@d7b270 url=http://127.0.0.1:60615/collection1 node=127.0.0.1:60615_ C1335_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:60615, core=collection1, node_name=127.0.0.1:60615_}
[junit4] 2> 2067972 T7744 C1335 P60615 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:60615/collection1/
[junit4] 2> 2067972 T7744 C1335 P60615 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 2067972 T7744 C1335 P60615 oasc.SyncStrategy.syncToMe http://127.0.0.1:60615/collection1/ has no replicas
[junit4] 2> 2067974 T7744 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:60615/collection1/ shard1
[junit4] 2> 2067975 T7744 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2067979 T7718 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2067994 T7717 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2067998 T7717 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2068011 T7717 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2068122 T7739 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> 2068123 T7717 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> 2068124 T7726 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> 2068160 T7744 oasc.ZkController.register We are http://127.0.0.1:60615/collection1/ and leader is http://127.0.0.1:60615/collection1/
[junit4] 2> 2068160 T7744 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:60615
[junit4] 2> 2068161 T7744 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 2068161 T7744 oasc.ZkController.publish publishing core=collection1 state=active collection=collection1
[junit4] 2> 2068161 T7744 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 2068168 T7744 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2068168 T7717 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2068168 T7717 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2068168 T7717 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2068173 T7718 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2068174 T7718 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:60615",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:60615_",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 2068179 T7717 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2068285 T7739 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> 2068286 T7726 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> 2068286 T7717 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> 2070107 T7695 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 2
[junit4] 2> 2070108 T7695 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 2070113 T7695 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:60624
[junit4] 2> 2070115 T7695 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 2070115 T7695 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 2070115 T7695 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: .\solr.cloud.SyncSliceTest-8EC19F4B1F713221-001\tempDir-004
[junit4] 2> 2070115 T7695 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '.\solr.cloud.SyncSliceTest-8EC19F4B1F713221-001\tempDir-004\'
[junit4] 2> 2070161 T7695 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-8EC19F4B1F713221-001\tempDir-004\solr.xml
[junit4] 2> 2070179 T7695 oasc.CoreContainer.<init> New CoreContainer 32306466
[junit4] 2> 2070179 T7695 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=.\solr.cloud.SyncSliceTest-8EC19F4B1F713221-001\tempDir-004\]
[junit4] 2> 2070182 T7695 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 2070182 T7695 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 2070182 T7695 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 2070182 T7695 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 2070182 T7695 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 2070182 T7695 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 2070182 T7695 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 2070182 T7695 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 2070184 T7695 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 2070184 T7695 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 2070185 T7695 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 2070186 T7695 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 2070186 T7695 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:60596/solr
[junit4] 2> 2070187 T7695 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 2070189 T7695 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2070212 T7755 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1efd782 name:ZooKeeperConnection Watcher:127.0.0.1:60596 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2070212 T7695 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2070222 T7695 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2070225 T7757 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@278461 name:ZooKeeperConnection Watcher:127.0.0.1:60596/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2070225 T7695 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2070241 T7695 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 2071268 T7695 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:60624_
[junit4] 2> 2071271 T7695 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:60624_
[junit4] 2> 2071278 T7717 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 2071279 T7739 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 2071280 T7726 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 2071281 T7757 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 2071298 T7758 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
[junit4] 2> 2071299 T7758 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 2071302 T7758 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 2071302 T7717 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2071303 T7717 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2071303 T7717 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2071307 T7718 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2071309 T7718 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:60624",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:60624_",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":null}
[junit4] 2> 2071309 T7718 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=1
[junit4] 2> 2071310 T7718 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 2071327 T7717 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2071329 T7717 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> 2071330 T7726 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> 2071330 T7757 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> 2071330 T7739 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> 2072323 T7758 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 2072323 T7758 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 2072324 T7758 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 2072325 T7758 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 2072327 T7758 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 2072327 T7758 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '.\solr.cloud.SyncSliceTest-8EC19F4B1F713221-001\tempDir-004\collection1\'
[junit4] 2> 2072330 T7758 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/solr.cloud.SyncSliceTest-8EC19F4B1F713221-001/tempDir-004/collection1/lib/.svn/' to classloader
[junit4] 2> 2072332 T7758 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/solr.cloud.SyncSliceTest-8EC19F4B1F713221-001/tempDir-004/collection1/lib/classes/' to classloader
[junit4] 2> 2072333 T7758 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/solr.cloud.SyncSliceTest-8EC19F4B1F713221-001/tempDir-004/collection1/lib/README' to classloader
[junit4] 2> 2072400 T7758 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_4_10
[junit4] 2> 2072413 T7758 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 2072417 T7758 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 2072429 T7758 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 2072592 T7758 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 2072592 T7758 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 2072593 T7758 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 2072604 T7758 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 2072604 T7758 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 2072631 T7758 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 2072636 T7758 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 2072642 T7758 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 2072644 T7758 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 2072644 T7758 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 2072645 T7758 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 2072647 T7758 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 2072647 T7758 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 2072648 T7758 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection collection1
[junit4] 2> 2072648 T7758 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 2072648 T7758 oasc.SolrCore.<init> [collection1] Opening new SolrCore at .\solr.cloud.SyncSliceTest-8EC19F4B1F713221-001\tempDir-004\collection1\, dataDir=.\solr.cloud.SyncSliceTest-8EC19F4B1F713221-001\tempDir-001/jetty2\
[junit4] 2> 2072649 T7758 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1b72d26
[junit4] 2> 2072651 T7758 oasc.CachingDirectoryFactory.get return new directory for .\solr.cloud.SyncSliceTest-8EC19F4B1F713221-001\tempDir-001/jetty2\
[junit4] 2> 2072651 T7758 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\solr.cloud.SyncSliceTest-8EC19F4B1F713221-001\tempDir-001/jetty2\index/
[junit4] 2> 2072651 T7758 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '.\solr.cloud.SyncSliceTest-8EC19F4B1F713221-001\tempDir-001\jetty2\index' doesn't exist. Creating new index...
[junit4] 2> 2072652 T7758 oasc.CachingDirectoryFactory.get return new directory for .\solr.cloud.SyncSliceTest-8EC19F4B1F713221-001\tempDir-001/jetty2\index
[junit4] 2> 2072652 T7758 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=40, maxMergeAtOnceExplicit=43, maxMergedSegmentMB=58.9296875, floorSegmentMB=1.8408203125, forceMergeDeletesPctAllowed=7.305760150884263, segmentsPerTier=48.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.86311055422684
[junit4] 2> 2072653 T7758 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@f646b8 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1740aa9),segFN=segments_1,generation=1}
[junit4] 2> 2072654 T7758 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 2072659 T7758 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 2072660 T7758 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 2072660 T7758 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 2072660 T7758 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 2072661 T7758 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 2072662 T7758 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 2072662 T7758 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 2072663 T7758 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 2072663 T7758 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 2072675 T7758 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 2072676 T7758 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 2072676 T7758 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 2072677 T7758 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 2072678 T7758 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 2072678 T7758 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 2072680 T7758 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 2072686 T7758 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 2072690 T7758 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 2072690 T7758 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 2072692 T7758 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=17, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
[junit4] 2> 2072692 T7758 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@f646b8 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1740aa9),segFN=segments_1,generation=1}
[junit4] 2> 2072693 T7758 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 2072693 T7758 oass.SolrIndexSearcher.<init> Opening Searcher@8755e4[collection1] main
[junit4] 2> 2072693 T7758 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 2072696 T7758 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 2072696 T7758 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
[junit4] 2> 2072698 T7758 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 2072698 T7758 oasr.RestManager.init Initializing RestManager with initArgs: {}
[junit4] 2> 2072698 T7758 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 2072699 T7758 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
[junit4] 2> 2072700 T7758 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 2072700 T7758 oasr.ManagedResource.notifyObserversDuringInit WARN No registered observers for /rest/managed
[junit4] 2> 2072700 T7758 oasr.RestManager.init Initializing 0 registered ManagedResources
[junit4] 2> 2072710 T7759 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@8755e4[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 2072714 T7758 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 2072716 T7762 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:60624 collection:collection1 shard:shard1
[junit4] 2> 2072717 T7695 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0
[junit4] 2> 2072717 T7695 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 2072724 T7762 oasc.ZkController.register We are http://127.0.0.1:60624/collection1/ and leader is http://127.0.0.1:60615/collection1/
[junit4] 2> 2072724 T7762 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:60624
[junit4] 2> 2072725 T7762 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4] 2> 2072725 T7762 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4] 2> 2072726 T7762 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> ASYNC NEW_CORE C1336 name=collection1 org.apache.solr.core.SolrCore@13a22de url=http://127.0.0.1:60624/collection1 node=127.0.0.1:60624_ C1336_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:60624, core=collection1, node_name=127.0.0.1:60624_}
[junit4] 2> 2072726 T7763 C1336 P60624 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4] 2> 2072726 T7763 C1336 P60624 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4] 2> 2072727 T7763 C1336 P60624 oasc.RecoveryStrategy.doRecovery Publishing state of core collection1 as recovering, leader is http://127.0.0.1:60615/collection1/ and I am http://127.0.0.1:60624/collection1/
[junit4] 2> 2072727 T7763 C1336 P60624 oasc.ZkController.publish publishing core=collection1 state=recovering collection=collection1
[junit4] 2> 2072727 T7763 C1336 P60624 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 2072731 T7763 C1336 P60624 oasc.RecoveryStrategy.sendPrepRecoveryCmd Sending prep recovery command to http://127.0.0.1:60615; WaitForState: action=PREPRECOVERY&core=collection1&nodeName=127.0.0.1%3A60624_&coreNodeName=core_node2&state=recovering&checkLive=true&onlyIfLeader=true&onlyIfLeaderActive=true
[junit4] 2> 2072731 T7717 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2072736 T7718 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2072737 T7718 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:60624",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:60624_",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":"core_node2"}
[junit4] 2> 2072743 T7734 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: core_node2, state: recovering, checkLive: true, onlyIfLeader: true, onlyIfLeaderActive: true
[junit4] 2> 2072746 T7734 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2072747 T7734 oasha.CoreAdminHandler.handleWaitForStateAction Will wait a max of 183 seconds to see collection1 (shard1 of collection1) have state: recovering
[junit4] 2> 2072748 T7734 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:60624_, coreNodeName=core_node2, onlyIfActiveCheckResult=false, nodeProps: core_node2:{"state":"down","base_url":"http://127.0.0.1:60624","core":"collection1","node_name":"127.0.0.1:60624_"}
[junit4] 2> 2072750 T7717 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2072859 T7739 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> 2072860 T7717 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> 2072862 T7726 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> 2072863 T7757 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> 2073768 T7734 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:60624_, coreNodeName=core_node2, onlyIfActiveCheckResult=false, nodeProps: core_node2:{"state":"recovering","base_url":"http://127.0.0.1:60624","core":"collection1","node_name":"127.0.0.1:60624_"}
[junit4] 2> 2073768 T7734 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: core_node2, state: recovering, checkLive: true, onlyIfLeader: true for: 1 seconds.
[junit4] 2> 2073769 T7734 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={nodeName=127.0.0.1:60624_&onlyIfLeaderActive=true&core=collection1&coreNodeName=core_node2&action=PREPRECOVERY&checkLive=true&state=recovering&onlyIfLeader=true&wt=javabin&version=2} status=0 QTime=1026
[junit4] 2> 2074824 T7695 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 3
[junit4] 2> 2074825 T7695 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 2074829 T7695 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:60634
[junit4] 2> 2074830 T7695 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 2074830 T7695 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 2074830 T7695 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-8EC19F4B1F713221-001\tempDir-005
[junit4] 2> 2074831 T7695 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solr.cloud.SyncSliceTest-8EC19F4B1F713221-001\tempDir-005\'
[junit4] 2> 2074889 T7695 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-8EC19F4B1F713221-001\tempDir-005\solr.xml
[junit4] 2> 2074911 T7695 oasc.CoreContainer.<init> New CoreContainer 30503467
[junit4] 2> 2074911 T7695 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-8EC19F4B1F713221-001\tempDir-005\]
[junit4] 2> 2074914 T7695 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 2074914 T7695 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 2074914 T7695 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 2074914 T7695 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 2074914 T7695 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 2074914 T7695 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 2074914 T7695 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 2074914 T7695 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 2074914 T7695 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 2074916 T7695 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 2074916 T7695 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 2074916 T7695 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 2074916 T7695 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:60596/solr
[junit4] 2> 2074918 T7695 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 2074921 T7695 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2074940 T7775 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@92a898 name:ZooKeeperConnection Watcher:127.0.0.1:60596 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2074940 T7695 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2074952 T7695 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2074955 T7777 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@37b5af name:ZooKeeperConnection Watcher:127.0.0.1:60596/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2074955 T7695 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2074972 T7695 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> ASYNC NEW_CORE C1337 name=collection1 org.apache.solr.core.SolrCore@13a22de url=http://127.0.0.1:60624/collection1 node=127.0.0.1:60624_ C1337_STATE=coll:collection1 core:collection1 props:{state=recovering, base_url=http://127.0.0.1:60624, core=collection1, node_name=127.0.0.1:60624_}
[junit4] 2> 2075810 T7763 C1337 P60624 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:60615/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4] 2> 2075810 T7763 C1337 P60624 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:60624 START replicas=[http://127.0.0.1:60615/collection1/] nUpdates=100
[junit4] 2> 2075811 T7763 C1337 P60624 oasu.PeerSync.sync WARN no frame of reference to tell if we've missed updates
[junit4] 2> 2075812 T7763 C1337 P60624 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4] 2> 2075813 T7763 C1337 P60624 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4] 2> 2075815 T7763 C1337 P60624 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4] 2> 2075815 T7763 C1337 P60624 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4] 2> 2075815 T7763 C1337 P60624 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:60615/collection1/. core=collection1
[junit4] 2> ASYNC NEW_CORE C1338 name=collection1 org.apache.solr.core.SolrCore@d7b270 url=http://127.0.0.1:60615/collection1 node=127.0.0.1:60615_ C1338_STATE=coll:collection1 core:collection1 props:{state=active, base_url=http://127.0.0.1:60615, core=collection1, node_name=127.0.0.1:60615_, leader=true}
[junit4] 2> 2075816 T7732 C1338 P60615 oasc.SolrCore.execute [collection1] webapp= path=/get params={distrib=false&qt=/get&getVersions=100&wt=javabin&version=2} status=0 QTime=1
[junit4] 2> 2075820 T7733 C1338 P60615 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 2075
[...truncated too long message...]
] 2> ... 39 more
[junit4] 2>
[junit4] 2> 2139161 T7798 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4] 2> 2139161 T7798 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 2139161 T7798 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 2139162 T7798 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=8EC19F4B1F713221 -Dtests.slow=true -Dtests.locale=zh -Dtests.timezone=NET -Dtests.file.encoding=US-ASCII
[junit4] ERROR 80.1s | SyncSliceTest.testDistribSearch <<<
[junit4] > Throwable #1: org.apache.solr.client.solrj.SolrServerException: No live SolrServers available to handle this request
[junit4] > at __randomizedtesting.SeedInfo.seed([8EC19F4B1F713221:F271153682E521D]: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> 2139169 T7695 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-8EC19F4B1F713221-001
[junit4] 2> NOTE: test params are: codec=Lucene40, sim=RandomSimilarityProvider(queryNorm=true,coord=no): {}, locale=zh, timezone=NET
[junit4] 2> NOTE: Windows 7 6.1 x86/Oracle Corporation 1.8.0_20-ea (32-bit)/cpus=2,threads=1,free=64543536,total=355991552
[junit4] 2> NOTE: All tests run in this JVM: [PeerSyncTest, SolrInfoMBeanTest, TestElisionMultitermQuery, TestBadConfig, JsonLoaderTest, TestArbitraryIndexDir, TestSurroundQueryParser, DocValuesTest, MultiThreadedOCPTest, TestLazyCores, AssignTest, TestManagedSchemaFieldResource, UpdateRequestProcessorFactoryTest, CircularListTest, CSVRequestHandlerTest, TestJmxMonitoredMap, TestXIncludeConfig, DocumentAnalysisRequestHandlerTest, TestCollapseQParserPlugin, SchemaVersionSpecificBehaviorTest, TestSolrIndexConfig, TestStressLucene, BasicDistributedZkTest, TestRecoveryHdfs, FieldAnalysisRequestHandlerTest, TestSolrXMLSerializer, SynonymTokenizerTest, TestPartialUpdateDeduplication, TestConfig, ZkSolrClientTest, TestReload, TestCloudManagedSchema, TestManagedResource, TestLFUCache, UnloadDistributedZkTest, TestSolrDeletionPolicy2, TestSolrQueryParserDefaultOperatorResource, TestStressVersions, TestFaceting, EchoParamsTest, TestConfigSets, TestRecovery, TestFuzzyAnalyzedSuggestions, MultiTermTest, TestTrie, PrimUtilsTest, SliceStateTest, SuggestComponentTest, TestMergePolicyConfig, SolrCoreCheckLockOnStartupTest, TestManagedResourceStorage, BinaryUpdateRequestHandlerTest, ShardRoutingCustomTest, TestAnalyzedSuggestions, TestOmitPositions, TestQueryUtils, TestStressReorder, SolrXmlInZkTest, TestCollationKeyRangeQueries, BadCopyFieldTest, SoftAutoCommitTest, TestExceedMaxTermLength, SystemInfoHandlerTest, NumericFieldsTest, BasicZkTest, ConnectionManagerTest, TestSolr4Spatial, SolrTestCaseJ4Test, TestStressRecovery, NoCacheHeaderTest, TestLMDirichletSimilarityFactory, FileBasedSpellCheckerTest, XmlUpdateRequestHandlerTest, ShowFileRequestHandlerTest, TestExpandComponent, SortByFunctionTest, DistributedSuggestComponentTest, TestManagedStopFilterFactory, TestDefaultSimilarityFactory, CoreAdminCreateDiscoverTest, TestDocSet, SimpleFacetsTest, CollectionsAPIAsyncDistributedZkTest, TestHighlightDedupGrouping, DefaultValueUpdateProcessorTest, MBeansHandlerTest, XsltUpdateRequestHandlerTest, AddSchemaFieldsUpdateProcessorFactoryTest, TestFoldingMultitermQuery, TestSweetSpotSimilarityFactory, DistributedTermsComponentTest, PrimitiveFieldTypeTest, BadIndexSchemaTest, TestMaxScoreQueryParser, RegexBoostProcessorTest, ResponseLogComponentTest, UUIDFieldTest, HardAutoCommitTest, DirectSolrSpellCheckerTest, RequestHandlersTest, TestMiniSolrCloudCluster, StandardRequestHandlerTest, HdfsLockFactoryTest, TestFieldTypeResource, TestCopyFieldCollectionResource, DistribCursorPagingTest, ReturnFieldsTest, FullSolrCloudDistribCmdsTest, ShardSplitTest, TestDocumentBuilder, TestSearchPerf, DisMaxRequestHandlerTest, TestRemoteStreaming, TestSchemaNameResource, TestCodecSupport, DistributedExpandComponentTest, TestInitQParser, TestCoreContainer, TestSolrQueryParserResource, SpellPossibilityIteratorTest, TestJoin, TimeZoneUtilsTest, TestDocBasedVersionConstraints, TestShortCircuitedRequests, LukeRequestHandlerTest, HighlighterMaxOffsetTest, TestReRankQParserPlugin, TestValueSourceCache, AnalyticsQueryTest, TestPostingsSolrHighlighter, ConvertedLegacyTest, RequiredFieldsTest, TestSimpleQParserPlugin, TestCloudInspectUtil, TermVectorComponentDistributedTest, DocValuesMultiTest, AlternateDirectoryTest, TestFiltering, HdfsBasicDistributedZkTest, TestIndexSearcher, NotRequiredUniqueKeyTest, TestAnalyzeInfixSuggestions, TestMultiCoreConfBootstrap, DocValuesMissingTest, TestPseudoReturnFields, ClusterStateTest, TestQueryTypes, DebugComponentTest, TestFieldCollectionResource, AtomicUpdatesTest, TestDistributedSearch, TestUtils, RollingRestartTest, TestLuceneMatchVersion, DOMUtilTest, TestCoreDiscovery, TestQuerySenderListener, SpatialFilterTest, LeaderElectionIntegrationTest, CoreAdminRequestStatusTest, TestDynamicFieldResource, TestSolrXmlPersistor, TestClassNameShortening, SuggesterFSTTest, TestNonDefinedSimilarityFactory, TestReloadAndDeleteDocs, SolrIndexSplitterTest, ZkCLITest, TestCSVLoader, TestLRUCache, TestNoOpRegenerator, TestRandomMergePolicy, TestBlendedInfixSuggestions, TestRangeQuery, TestSchemaSimilarityResource, StressHdfsTest, SuggesterWFSTTest, SolrRequestParserTest, DistributedQueryComponentOptimizationTest, TestPerFieldSimilarity, RAMDirectoryFactoryTest, TestSolrQueryParser, TestPhraseSuggestions, BlockDirectoryTest, TestFreeTextSuggestions, ResourceLoaderTest, PingRequestHandlerTest, TestSerializedLuceneMatchVersion, TestRealTimeGet, QueryEqualityTest, TestZkChroot, CollectionsAPIDistributedZkTest, TestIBSimilarityFactory, TestDynamicFieldCollectionResource, ChaosMonkeySafeLeaderTest, BasicDistributedZk2Test, SyncSliceTest]
[junit4] Completed in 80.22s, 1 test, 1 error <<< FAILURES!
[...truncated 638 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, 43 ignored (22 assumptions)
Total time: 112 minutes 29 seconds
Build step 'Invoke Ant' marked build as failure
[description-setter] Description set: Java: 32bit/jdk1.8.0_20-ea-b15 -client -XX:+UseParallelGC
Archiving artifacts
Recording test results
Email was triggered for: Failure - Any
Sending email for trigger: Failure - Any