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 2013/05/24 23:58:42 UTC
[JENKINS] Lucene-Solr-trunk-Windows (64bit/jdk1.7.0_21) - Build #
2857 - Still Failing!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Windows/2857/
Java: 64bit/jdk1.7.0_21 -XX:+UseCompressedOops -XX:+UseParallelGC
1 tests failed.
FAILED: org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testDistribSearch
Error Message:
There are still nodes recoverying - waited for 230 seconds
Stack Trace:
java.lang.AssertionError: There are still nodes recoverying - waited for 230 seconds
at __randomizedtesting.SeedInfo.seed([38F1683D98ABC1F1:B917E625EFF4A1CD]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.apache.solr.cloud.AbstractDistribZkTestBase.waitForRecoveriesToFinish(AbstractDistribZkTestBase.java:173)
at org.apache.solr.cloud.AbstractDistribZkTestBase.waitForRecoveriesToFinish(AbstractDistribZkTestBase.java:131)
at org.apache.solr.cloud.AbstractDistribZkTestBase.waitForRecoveriesToFinish(AbstractDistribZkTestBase.java:126)
at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testCollectionsAPI(CollectionsAPIDistributedZkTest.java:512)
at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.doTest(CollectionsAPIDistributedZkTest.java:146)
at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:815)
at sun.reflect.GeneratedMethodAccessor37.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:601)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
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:70)
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:358)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
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 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:70)
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:358)
at java.lang.Thread.run(Thread.java:722)
Build Log:
[...truncated 9572 lines...]
[junit4:junit4] Suite: org.apache.solr.cloud.CollectionsAPIDistributedZkTest
[junit4:junit4] 2> 1455052 T4898 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /smgeb/
[junit4:junit4] 2> 1455059 T4898 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4:junit4] 2> Creating dataDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\solrtest-CollectionsAPIDistributedZkTest-1369431557092
[junit4:junit4] 2> 1455063 T4898 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4:junit4] 2> 1455065 T4899 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4:junit4] 2> 1455183 T4898 oasc.ZkTestServer.run start zk server on port:63238
[junit4:junit4] 2> 1455186 T4898 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 1455200 T4905 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6e04ea6 name:ZooKeeperConnection Watcher:127.0.0.1:63238 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 1455200 T4898 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 1455200 T4898 oascc.SolrZkClient.makePath makePath: /solr
[junit4:junit4] 2> 1455208 T4900 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x13ed87b43f60000, likely client has closed socket
[junit4:junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:220)
[junit4:junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4:junit4] 2> at java.lang.Thread.run(Thread.java:722)
[junit4:junit4] 2>
[junit4:junit4] 2> 1455212 T4898 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 1455217 T4907 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@42e35a35 name:ZooKeeperConnection Watcher:127.0.0.1:63238/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 1455218 T4898 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 1455218 T4898 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4:junit4] 2> 1455227 T4898 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4:junit4] 2> 1455233 T4898 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4:junit4] 2> 1455239 T4898 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4:junit4] 2> 1455246 T4898 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4:junit4] 2> 1455247 T4898 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4:junit4] 2> 1455259 T4898 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\schema.xml to /configs/conf1/schema.xml
[junit4:junit4] 2> 1455259 T4898 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4:junit4] 2> 1455268 T4898 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\stopwords.txt to /configs/conf1/stopwords.txt
[junit4:junit4] 2> 1455269 T4898 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4:junit4] 2> 1455274 T4898 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\protwords.txt to /configs/conf1/protwords.txt
[junit4:junit4] 2> 1455276 T4898 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4:junit4] 2> 1455283 T4898 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\currency.xml to /configs/conf1/currency.xml
[junit4:junit4] 2> 1455284 T4898 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4:junit4] 2> 1455291 T4898 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4:junit4] 2> 1455292 T4898 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4:junit4] 2> 1455300 T4898 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4] 2> 1455300 T4898 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4] 2> 1455307 T4898 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4:junit4] 2> 1455308 T4898 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4:junit4] 2> 1455315 T4898 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\synonyms.txt to /configs/conf1/synonyms.txt
[junit4:junit4] 2> 1455316 T4898 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4:junit4] 2> 1455325 T4900 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x13ed87b43f60001, likely client has closed socket
[junit4:junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:220)
[junit4:junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4:junit4] 2> at java.lang.Thread.run(Thread.java:722)
[junit4:junit4] 2>
[junit4:junit4] 2> 1455922 T4898 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 1455930 T4898 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:63245
[junit4:junit4] 2> 1455931 T4898 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 1455931 T4898 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 1455932 T4898 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369431557356
[junit4:junit4] 2> 1455932 T4898 oasc.CoreContainer$Initializer.initialize looking for solr config file: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369431557356\solr.xml
[junit4:junit4] 2> 1455932 T4898 oasc.CoreContainer.<init> New CoreContainer 939847018
[junit4:junit4] 2> 1455933 T4898 oasc.CoreContainer.load Loading CoreContainer using Solr Home: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369431557356\'
[junit4:junit4] 2> 1455933 T4898 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369431557356\'
[junit4:junit4] 2> 1456046 T4898 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369431557356
[junit4:junit4] 2> 1456048 T4898 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369431557356\collection1
[junit4:junit4] 2> 1456050 T4898 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369431557356\collection1\conf
[junit4:junit4] 2> 1456346 T4898 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369431557356\collection1\conf\xslt
[junit4:junit4] 2> 1456355 T4898 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369431557356\collection1\lib
[junit4:junit4] 2> 1456358 T4898 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369431557356\collection1\lib\classes
[junit4:junit4] 2> 1456368 T4898 oasc.SolrCoreDiscoverer.addCore Discovered properties file C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369431557356\conf\core.properties, adding to cores
[junit4:junit4] 2> 1456390 T4898 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4] 2> 1456390 T4898 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 1456390 T4898 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4] 2> 1456390 T4898 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 1456392 T4898 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 1456392 T4898 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 1456392 T4898 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 1456393 T4898 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 1456393 T4898 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 1456393 T4898 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4] 2> 1456404 T4898 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 1456405 T4898 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:63238/solr
[junit4:junit4] 2> 1456405 T4898 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 1456406 T4898 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 1456427 T4918 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@110838f name:ZooKeeperConnection Watcher:127.0.0.1:63238 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 1456428 T4898 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 1456431 T4898 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 1456433 T4900 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x13ed87b43f60002, likely client has closed socket
[junit4:junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:220)
[junit4:junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4:junit4] 2> at java.lang.Thread.run(Thread.java:722)
[junit4:junit4] 2>
[junit4:junit4] 2> 1456441 T4898 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 1456445 T4920 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5122bed0 name:ZooKeeperConnection Watcher:127.0.0.1:63238/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 1456446 T4898 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 1456450 T4898 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4:junit4] 2> 1456460 T4898 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4:junit4] 2> 1456468 T4898 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4:junit4] 2> 1456474 T4898 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:63245_smgeb
[junit4:junit4] 2> 1456479 T4898 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:63245_smgeb
[junit4:junit4] 2> 1456487 T4898 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4:junit4] 2> 1456503 T4898 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4] 2> 1456510 T4898 oasc.Overseer.start Overseer (id=89747066526760963-127.0.0.1:63245_smgeb-n_0000000000) starting
[junit4:junit4] 2> 1456521 T4898 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4:junit4] 2> 1456531 T4922 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4] 2> 1456532 T4898 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4:junit4] 2> 1456539 T4898 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4:junit4] 2> 1456544 T4898 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 1456550 T4921 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4] 2> 1456555 T4898 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0
[junit4:junit4] 2> 1456555 T4898 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 1456556 T4898 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 1456562 T4898 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4] 2> 1456565 T4898 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 1456569 T4925 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3c858faf name:ZooKeeperConnection Watcher:127.0.0.1:63238/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 1456570 T4898 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 1456572 T4898 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 1456577 T4898 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4:junit4] 2> 1457118 T4898 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 1457123 T4898 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:63257
[junit4:junit4] 2> 1457124 T4898 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 1457124 T4898 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 1457124 T4898 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1369431558608
[junit4:junit4] 2> 1457125 T4898 oasc.CoreContainer$Initializer.initialize looking for solr config file: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1369431558608\solr.xml
[junit4:junit4] 2> 1457125 T4898 oasc.CoreContainer.<init> New CoreContainer 1029151174
[junit4:junit4] 2> 1457126 T4898 oasc.CoreContainer.load Loading CoreContainer using Solr Home: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1369431558608\'
[junit4:junit4] 2> 1457126 T4898 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1369431558608\'
[junit4:junit4] 2> 1457250 T4898 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1369431558608
[junit4:junit4] 2> 1457254 T4898 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1369431558608\collection1
[junit4:junit4] 2> 1457256 T4898 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1369431558608\collection1\conf
[junit4:junit4] 2> 1457548 T4898 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1369431558608\collection1\conf\xslt
[junit4:junit4] 2> 1457559 T4898 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1369431558608\collection1\lib
[junit4:junit4] 2> 1457565 T4898 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1369431558608\collection1\lib\classes
[junit4:junit4] 2> 1457574 T4898 oasc.SolrCoreDiscoverer.addCore Discovered properties file C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1369431558608\conf\core.properties, adding to cores
[junit4:junit4] 2> 1457598 T4898 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4] 2> 1457599 T4898 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 1457599 T4898 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4] 2> 1457599 T4898 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 1457599 T4898 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 1457599 T4898 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 1457600 T4898 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 1457600 T4898 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 1457601 T4898 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 1457601 T4898 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4] 2> 1457610 T4898 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 1457610 T4898 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:63238/solr
[junit4:junit4] 2> 1457612 T4898 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 1457614 T4898 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 1457639 T4936 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@62276600 name:ZooKeeperConnection Watcher:127.0.0.1:63238 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 1457640 T4898 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 1457644 T4898 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 1457652 T4898 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 1457657 T4938 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1598f8d5 name:ZooKeeperConnection Watcher:127.0.0.1:63238/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 1457658 T4898 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 1457667 T4898 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 1458862 T4898 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:63257_smgeb
[junit4:junit4] 2> 1458869 T4898 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:63257_smgeb
[junit4:junit4] 2> 1458878 T4938 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 1458878 T4920 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 1458878 T4925 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 1458890 T4898 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0
[junit4:junit4] 2> 1458890 T4898 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 1458891 T4898 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 1459511 T4898 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 1459515 T4898 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:63266
[junit4:junit4] 2> 1459515 T4898 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 1459517 T4898 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 1459517 T4898 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1369431560928
[junit4:junit4] 2> 1459517 T4898 oasc.CoreContainer$Initializer.initialize looking for solr config file: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1369431560928\solr.xml
[junit4:junit4] 2> 1459518 T4898 oasc.CoreContainer.<init> New CoreContainer 2022253301
[junit4:junit4] 2> 1459518 T4898 oasc.CoreContainer.load Loading CoreContainer using Solr Home: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1369431560928\'
[junit4:junit4] 2> 1459518 T4898 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1369431560928\'
[junit4:junit4] 2> 1459627 T4898 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1369431560928
[junit4:junit4] 2> 1459629 T4898 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1369431560928\collection1
[junit4:junit4] 2> 1459632 T4898 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1369431560928\collection1\conf
[junit4:junit4] 2> 1459939 T4898 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1369431560928\collection1\conf\xslt
[junit4:junit4] 2> 1459950 T4898 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1369431560928\collection1\lib
[junit4:junit4] 2> 1459953 T4898 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1369431560928\collection1\lib\classes
[junit4:junit4] 2> 1459962 T4898 oasc.SolrCoreDiscoverer.addCore Discovered properties file C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1369431560928\conf\core.properties, adding to cores
[junit4:junit4] 2> 1459984 T4898 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4] 2> 1459986 T4898 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 1459986 T4898 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4] 2> 1459986 T4898 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 1459987 T4898 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 1459987 T4898 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 1459987 T4898 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 1459988 T4898 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 1459988 T4898 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 1459988 T4898 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4] 2> 1459997 T4898 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 1459997 T4898 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:63238/solr
[junit4:junit4] 2> 1459998 T4898 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 1460001 T4898 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 1460020 T4950 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6ac750e9 name:ZooKeeperConnection Watcher:127.0.0.1:63238 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 1460023 T4898 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 1460027 T4898 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 1460034 T4898 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 1460039 T4952 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@745b88de name:ZooKeeperConnection Watcher:127.0.0.1:63238/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 1460040 T4898 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 1460050 T4898 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 1461243 T4898 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:63266_smgeb
[junit4:junit4] 2> 1461247 T4898 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:63266_smgeb
[junit4:junit4] 2> 1461255 T4920 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 1461255 T4925 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 1461255 T4938 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 1461256 T4952 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 1461269 T4898 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0
[junit4:junit4] 2> 1461269 T4898 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 1461270 T4898 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 1461887 T4898 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 1461893 T4898 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:63275
[junit4:junit4] 2> 1461893 T4898 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 1461893 T4898 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 1461893 T4898 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369431563307
[junit4:junit4] 2> 1461893 T4898 oasc.CoreContainer$Initializer.initialize looking for solr config file: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369431563307\solr.xml
[junit4:junit4] 2> 1461893 T4898 oasc.CoreContainer.<init> New CoreContainer 1623536080
[junit4:junit4] 2> 1461893 T4898 oasc.CoreContainer.load Loading CoreContainer using Solr Home: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369431563307\'
[junit4:junit4] 2> 1461893 T4898 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369431563307\'
[junit4:junit4] 2> 1462022 T4898 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369431563307
[junit4:junit4] 2> 1462024 T4898 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369431563307\collection1
[junit4:junit4] 2> 1462026 T4898 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369431563307\collection1\conf
[junit4:junit4] 2> 1462301 T4898 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369431563307\collection1\conf\xslt
[junit4:junit4] 2> 1462313 T4898 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369431563307\collection1\lib
[junit4:junit4] 2> 1462318 T4898 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369431563307\collection1\lib\classes
[junit4:junit4] 2> 1462327 T4898 oasc.SolrCoreDiscoverer.addCore Discovered properties file C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369431563307\conf\core.properties, adding to cores
[junit4:junit4] 2> 1462352 T4898 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4] 2> 1462352 T4898 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 1462353 T4898 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4] 2> 1462353 T4898 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 1462353 T4898 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 1462354 T4898 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 1462354 T4898 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 1462355 T4898 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 1462356 T4898 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 1462356 T4898 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4] 2> 1462371 T4898 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 1462371 T4898 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:63238/solr
[junit4:junit4] 2> 1462371 T4898 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 1462376 T4898 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 1462405 T4964 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2b6fcb73 name:ZooKeeperConnection Watcher:127.0.0.1:63238 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 1462407 T4898 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 1462422 T4898 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 1462438 T4898 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 1462444 T4966 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3ab78b29 name:ZooKeeperConnection Watcher:127.0.0.1:63238/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 1462444 T4898 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 1462456 T4898 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 1463649 T4898 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:63275_smgeb
[junit4:junit4] 2> 1463652 T4898 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:63275_smgeb
[junit4:junit4] 2> 1463659 T4925 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 1463659 T4966 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 1463660 T4920 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 1463660 T4938 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 1463660 T4952 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 1463670 T4898 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0
[junit4:junit4] 2> 1463671 T4898 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 1463671 T4898 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 1464218 T4898 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 1464223 T4898 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:63284
[junit4:junit4] 2> 1464224 T4898 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 1464224 T4898 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 1464225 T4898 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1369431565710
[junit4:junit4] 2> 1464225 T4898 oasc.CoreContainer$Initializer.initialize looking for solr config file: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1369431565710\solr.xml
[junit4:junit4] 2> 1464225 T4898 oasc.CoreContainer.<init> New CoreContainer 1691804310
[junit4:junit4] 2> 1464225 T4898 oasc.CoreContainer.load Loading CoreContainer using Solr Home: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1369431565710\'
[junit4:junit4] 2> 1464227 T4898 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1369431565710\'
[junit4:junit4] 2> 1464330 T4898 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1369431565710
[junit4:junit4] 2> 1464333 T4898 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1369431565710\collection1
[junit4:junit4] 2> 1464334 T4898 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1369431565710\collection1\conf
[junit4:junit4] 2> 1464560 T4898 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1369431565710\collection1\conf\xslt
[junit4:junit4] 2> 1464568 T4898 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1369431565710\collection1\lib
[junit4:junit4] 2> 1464571 T4898 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1369431565710\collection1\lib\classes
[junit4:junit4] 2> 1464576 T4898 oasc.SolrCoreDiscoverer.addCore Discovered properties file C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1369431565710\conf\core.properties, adding to cores
[junit4:junit4] 2> 1464595 T4898 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4] 2> 1464595 T4898 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 1464596 T4898 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4] 2> 1464596 T4898 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 1464596 T4898 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 1464597 T4898 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 1464597 T4898 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 1464597 T4898 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 1464598 T4898 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 1464598 T4898 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4] 2> 1464608 T4898 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 1464608 T4898 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:63238/solr
[junit4:junit4] 2> 1464609 T4898 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 1464611 T4898 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 1464632 T4978 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7b1cfb65 name:ZooKeeperConnection Watcher:127.0.0.1:63238 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 1464633 T4898 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 1464637 T4898 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 1464637 T4900 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x13ed87b43f6000b, likely client has closed socket
[junit4:junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:220)
[junit4:junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4:junit4] 2> at java.lang.Thread.run(Thread.java:722)
[junit4:junit4] 2>
[junit4:junit4] 2> 1464643 T4898 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 1464649 T4980 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3a699444 name:ZooKeeperConnection Watcher:127.0.0.1:63238/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 1464649 T4898 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 1464659 T4898 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 1465784 T4898 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:63284_smgeb
[junit4:junit4] 2> 1465788 T4898 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:63284_smgeb
[junit4:junit4] 2> 1465798 T4952 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 1465798 T4980 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 1465798 T4920 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 1465799 T4938 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 1465798 T4966 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 1465798 T4925 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 1465812 T4898 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0
[junit4:junit4] 2> 1465812 T4898 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 1465813 T4898 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 1465817 T4898 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 1465826 T4929 oasha.CollectionsHandler.handleCreateAction Creating Collection : numShards=2&name=nodes_used_collection&replicationFactor=2&action=CREATE&wt=javabin&version=2
[junit4:junit4] 2> 1465829 T4920 oasc.DistributedQueue$LatchChildWatcher.process Watcher fired on path: /overseer/collection-queue-work state: SyncConnected type NodeChildrenChanged
[junit4:junit4] 2> 1465833 T4920 oasc.DistributedQueue$LatchChildWatcher.process Watcher fired on path: /overseer/collection-queue-work state: SyncConnected type NodeChildrenChanged
[junit4:junit4] 2> 1465833 T4922 oasc.OverseerCollectionProcessor.run Overseer Collection Processor: Get the message id:/overseer/collection-queue-work/qn-0000000000 message:{
[junit4:junit4] 2> "operation":"createcollection",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "maxShardsPerNode":null,
[junit4:junit4] 2> "createNodeSet":null,
[junit4:junit4] 2> "name":"nodes_used_collection",
[junit4:junit4] 2> "replicationFactor":"2"}
[junit4:junit4] 2> 1465833 T4922 oasc.OverseerCollectionProcessor.createCollection Creating shard nodes_used_collection_shard1_replica1 as part of slice shard1 of collection nodes_used_collection on 127.0.0.1:63245_smgeb
[junit4:junit4] 2> 1465834 T4922 oasc.OverseerCollectionProcessor.createCollection Creating shard nodes_used_collection_shard1_replica2 as part of slice shard1 of collection nodes_used_collection on 127.0.0.1:63284_smgeb
[junit4:junit4] 2> 1465834 T4922 oasc.OverseerCollectionProcessor.createCollection Creating shard nodes_used_collection_shard2_replica1 as part of slice shard2 of collection nodes_used_collection on 127.0.0.1:63266_smgeb
[junit4:junit4] 2> 1465839 T4922 oasc.OverseerCollectionProcessor.createCollection Creating shard nodes_used_collection_shard2_replica2 as part of slice shard2 of collection nodes_used_collection on 127.0.0.1:63275_smgeb
[junit4:junit4] 2> 1465839 T4974 oasc.CoreContainer.create Creating SolrCore 'nodes_used_collection_shard1_replica2' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1369431565710\nodes_used_collection_shard1_replica2
[junit4:junit4] 2> 1465839 T4974 oasc.ZkController.createCollectionZkNode Check for collection zkNode:nodes_used_collection
[junit4:junit4] 2> 1465839 T4912 oasc.CoreContainer.create Creating SolrCore 'nodes_used_collection_shard1_replica1' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369431557356\nodes_used_collection_shard1_replica1
[junit4:junit4] 2> 1465841 T4912 oasc.ZkController.createCollectionZkNode Check for collection zkNode:nodes_used_collection
[junit4:junit4] 2> 1465844 T4974 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:nodes_used_collection
[junit4:junit4] 2> 1465845 T4974 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 1465845 T4912 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:nodes_used_collection
[junit4:junit4] 2> 1465845 T4912 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 1465845 T4959 oasc.CoreContainer.create Creating SolrCore 'nodes_used_collection_shard2_replica2' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369431563307\nodes_used_collection_shard2_replica2
[junit4:junit4] 2> 1465847 T4959 oasc.ZkController.createCollectionZkNode Check for collection zkNode:nodes_used_collection
[junit4:junit4] 2> 1465847 T4944 oasc.CoreContainer.create Creating SolrCore 'nodes_used_collection_shard2_replica1' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1369431560928\nodes_used_collection_shard2_replica1
[junit4:junit4] 2> 1465849 T4944 oasc.ZkController.createCollectionZkNode Check for collection zkNode:nodes_used_collection
[junit4:junit4] 2> 1465849 T4912 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4:junit4] 2> 1465849 T4912 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection
[junit4:junit4] 2> 1465850 T4959 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:nodes_used_collection
[junit4:junit4] 2> 1465851 T4959 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 1465847 T4974 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4:junit4] 2> 1465852 T4974 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection
[junit4:junit4] 2> 1465850 T4944 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:nodes_used_collection
[junit4:junit4] 2> 1465853 T4944 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 1465857 T4912 oasc.ZkController.readConfigName Load collection config from:/collections/nodes_used_collection
[junit4:junit4] 2> 1465858 T4944 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection
[junit4:junit4] 2> 1465857 T4959 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection
[junit4:junit4] 2> 1465862 T4974 oasc.ZkController.readConfigName Load collection config from:/collections/nodes_used_collection
[junit4:junit4] 2> 1465866 T4912 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369431557356\nodes_used_collection_shard1_replica1\'
[junit4:junit4] 2> 1465870 T4959 oasc.ZkController.readConfigName Load collection config from:/collections/nodes_used_collection
[junit4:junit4] 2> 1465872 T4974 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1369431565710\nodes_used_collection_shard1_replica2\'
[junit4:junit4] 2> 1465875 T4944 oasc.ZkController.readConfigName Load collection config from:/collections/nodes_used_collection
[junit4:junit4] 2> 1465885 T4959 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369431563307\nodes_used_collection_shard2_replica2\'
[junit4:junit4] 2> 1465887 T4944 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1369431560928\nodes_used_collection_shard2_replica1\'
[junit4:junit4] 2> 1465978 T4912 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 1466021 T4959 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 1466085 T4974 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 1466111 T4912 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 1466148 T4959 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 1466150 T4974 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 1466154 T4959 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 1466159 T4959 oass.IndexSchema.readSchema [nodes_used_collection_shard2_replica2] Schema name=test
[junit4:junit4] 2> 1466160 T4912 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 1466161 T4974 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 1466167 T4974 oass.IndexSchema.readSchema [nodes_used_collection_shard1_replica2] Schema name=test
[junit4:junit4] 2> 1466174 T4912 oass.IndexSchema.readSchema [nodes_used_collection_shard1_replica1] Schema name=test
[junit4:junit4] 2> 1466178 T4944 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 1466280 T4944 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 1466513 T4944 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 1466520 T4944 oass.IndexSchema.readSchema [nodes_used_collection_shard2_replica1] Schema name=test
[junit4:junit4] 2> 1467164 T4959 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 1467512 T4974 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 1467584 T4959 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 1467590 T4959 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 1467602 T4912 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 1467609 T4912 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 1467613 T4912 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 1467619 T4974 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 1467623 T4974 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 1467653 T4912 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 1467661 T4912 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 1467671 T4912 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 1467673 T4959 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 1467674 T4912 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 1467677 T4912 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 1467677 T4912 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 1467682 T4959 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 1467684 T4974 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 1467685 T4912 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 1467685 T4912 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 1467686 T4912 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 1467686 T4912 oasc.SolrCore.<init> [nodes_used_collection_shard1_replica1] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369431557356\nodes_used_collection_shard1_replica1\, dataDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369431557356\nodes_used_collection_shard1_replica1\data\
[junit4:junit4] 2> 1467687 T4912 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@5f20a14c
[junit4:junit4] 2> 1467688 T4912 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 1467688 T4912 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369431557356\nodes_used_collection_shard1_replica1\data\
[junit4:junit4] 2> 1467689 T4912 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369431557356\nodes_used_collection_shard1_replica1\data\index/
[junit4:junit4] 2> 1467689 T4912 oasc.SolrCore.initIndex WARN [nodes_used_collection_shard1_replica1] Solr index directory 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369431557356\nodes_used_collection_shard1_replica1\data\index' doesn't exist. Creating new index...
[junit4:junit4] 2> 1467689 T4912 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369431557356\nodes_used_collection_shard1_replica1\data\index
[junit4:junit4] 2> 1467696 T4912 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@2406ed74 lockFactory=org.apache.lucene.store.NativeFSLockFactory@a8e1bf9),segFN=segments_1,generation=1}
[junit4:junit4] 2> 1467696 T4912 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 1467713 T4959 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 1467715 T4912 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 1467717 T4912 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 1467717 T4912 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 1467718 T4912 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 1467718 T4912 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 1467719 T4912 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 1467719 T4912 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 1467719 T4912 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 1467720 T4912 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 1467727 T4974 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 1467733 T4959 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 1467733 T4959 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 1467733 T4959 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 1467734 T4912 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 1467739 T4912 oass.SolrIndexSearcher.<init> Opening Searcher@24bc793a main
[junit4:junit4] 2> 1467739 T4912 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369431557356\nodes_used_collection_shard1_replica1\data\tlog
[junit4:junit4] 2> 1467742 T4959 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 1467742 T4959 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 1467742 T4959 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 1467743 T4959 oasc.SolrCore.<init> [nodes_used_collection_shard2_replica2] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369431563307\nodes_used_collection_shard2_replica2\, dataDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369431563307\nodes_used_collection_shard2_replica2\data\
[junit4:junit4] 2> 1467743 T4959 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@5f20a14c
[junit4:junit4] 2> 1467744 T4959 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 1467744 T4959 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369431563307\nodes_used_collection_shard2_replica2\data\
[junit4:junit4] 2> 1467744 T4959 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369431563307\nodes_used_collection_shard2_replica2\data\index/
[junit4:junit4] 2> 1467745 T4959 oasc.SolrCore.initIndex WARN [nodes_used_collection_shard2_replica2] Solr index directory 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369431563307\nodes_used_collection_shard2_replica2\data\index' doesn't exist. Creating new index...
[junit4:junit4] 2> 1467745 T4959 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369431563307\nodes_used_collection_shard2_replica2\data\index
[junit4:junit4] 2> 1467753 T4974 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 1467756 T4912 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 1467756 T4912 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 1467760 T4959 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@4620e2fa lockFactory=org.apache.lucene.store.NativeFSLockFactory@4013a9dd),segFN=segments_1,generation=1}
[junit4:junit4] 2> 1467767 T4959 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 1467772 T4959 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 1467772 T4959 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 1467773 T4959 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 1467774 T4959 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 1467774 T4959 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 1467774 T4959 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 1467775 T4959 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 1467775 T4959 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 1467776 T4959 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 1467777 T4974 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 1467777 T4974 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 1467777 T4974 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 1467787 T4959 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 1467793 T4959 oass.SolrIndexSearcher.<init> Opening Searcher@50f3e184 main
[junit4:junit4] 2> 1467795 T4959 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369431563307\nodes_used_collection_shard2_replica2\data\tlog
[junit4:junit4] 2> 1467796 T4959 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 1467797 T4959 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 1467802 T4959 oasc.ZkController.publish publishing core=nodes_used_collection_shard2_replica2 state=down
[junit4:junit4] 2> 1467803 T4974 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 1467803 T4974 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 1467804 T4974 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 1467805 T4974 oasc.SolrCore.<init> [nodes_used_collection_shard1_replica2] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1369431565710\nodes_used_collection_shard1_replica2\, dataDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1369431565710\nodes_used_collection_shard1_replica2\data\
[junit4:junit4] 2> 1467805 T4974 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@5f20a14c
[junit4:junit4] 2> 1467805 T4974 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 1467806 T4974 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1369431565710\nodes_used_collection_shard1_replica2\data\
[junit4:junit4] 2> 1467806 T4974 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1369431565710\nodes_used_collection_shard1_replica2\data\index/
[junit4:junit4] 2> 1467806 T4974 oasc.SolrCore.initIndex WARN [nodes_used_collection_shard1_replica2] Solr index directory 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1369431565710\nodes_used_collection_shard1_replica2\data\index' doesn't exist. Creating new index...
[junit4:junit4] 2> 1467807 T4974 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1369431565710\nodes_used_collection_shard1_replica2\data\index
[junit4:junit4] 2> 1467812 T4974 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@4fb57a6a lockFactory=org.apache.lucene.store.NativeFSLockFactory@7d1478c1),segFN=segments_1,generation=1}
[junit4:junit4] 2> 1467812 T4974 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 1467817 T4974 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 1467818 T4974 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 1467818 T4974 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 1467819 T4974 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 1467819 T4974 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 1467819 T4974 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 1467820 T4974 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 1467821 T4974 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 1467822 T4974 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 1467830 T4912 oasc.ZkController.publish publishing core=nodes_used_collection_shard1_replica1 state=down
[junit4:junit4] 2> 1467832 T4987 oasc.SolrCore.registerSearcher [nodes_used_collection_shard2_replica2] Registered new searcher Searcher@50f3e184 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 1467835 T4986 oasc.SolrCore.registerSearcher [nodes_used_collection_shard1_replica1] Registered new searcher Searcher@24bc793a main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 1467844 T4974 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 1467848 T4974 oass.SolrIndexSearcher.<init> Opening Searcher@2394576c main
[junit4:junit4] 2> 1467850 T4974 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1369431565710\nodes_used_collection_shard1_replica2\data\tlog
[junit4:junit4] 2> 1467851 T4974 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 1467852 T4974 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 1467857 T4974 oasc.ZkController.publish publishing core=nodes_used_collection_shard1_replica2 state=down
[junit4:junit4] 2> 1467858 T4988 oasc.SolrCore.registerSearcher [nodes_used_collection_shard1_replica2] Registered new searcher Searcher@2394576c main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 1467890 T4944 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 1467901 T4944 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 1467908 T4944 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 1467933 T4944 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 1467955 T4944 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 1467961 T4944 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 1467965 T4944 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 1467965 T4944 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 1467965 T4944 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 1467967 T4944 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 1467967 T4944 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 1467968 T4944 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 1467968 T4944 oasc.SolrCore.<init> [nodes_used_collection_shard2_replica1] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1369431560928\nodes_used_collection_shard2_replica1\, dataDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1369431560928\nodes_used_collection_shard2_replica1\data\
[junit4:junit4] 2> 1467968 T4944 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@5f20a14c
[junit4:junit4] 2> 1467969 T4944 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 1467970 T4944 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1369431560928\nodes_used_collection_shard2_replica1\data\
[junit4:junit4] 2> 1467970 T4944 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1369431560928\nodes_used_collection_shard2_replica1\data\index/
[junit4:junit4] 2> 1467970 T4944 oasc.SolrCore.initIndex WARN [nodes_used_collection_shard2_replica1] Solr index directory 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1369431560928\nodes_used_collection_shard2_replica1\data\index' doesn't exist. Creating new index...
[junit4:junit4] 2> 1467971 T4944 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1369431560928\nodes_used_collection_shard2_replica1\data\index
[junit4:junit4] 2> 1467977 T4944 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@2eb982e7 lockFactory=org.apache.lucene.store.NativeFSLockFactory@15a2584e),segFN=segments_1,generation=1}
[junit4:junit4] 2> 1467977 T4944 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 1467981 T4944 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 1467981 T4944 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 1467982 T4944 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 1467983 T4944 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 1467983 T4944 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 1467984 T4944 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 1467984 T4944 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 1467985 T4944 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 1467985 T4944 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 1467995 T4944 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 1468012 T4944 oass.SolrIndexSearcher.<init> Opening Searcher@15264dcb main
[junit4:junit4] 2> 1468013 T4944 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1369431560928\nodes_used_collection_shard2_replica1\data\tlog
[junit4:junit4] 2> 1468016 T4944 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 1468016 T4944 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 1468020 T4989 oasc.SolrCore.registerSearcher [nodes_used_collection_shard2_replica1] Registered new searcher Searcher@15264dcb main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 1468021 T4944 oasc.ZkController.publish publishing core=nodes_used_collection_shard2_replica1 state=down
[junit4:junit4] 2> 1468974 T4921 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1468976 T4921 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":"shard2",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"nodes_used_collection_shard2_replica2",
[junit4:junit4] 2> "collection":"nodes_used_collection",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:63275_smgeb",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:63275/smgeb"}
[junit4:junit4] 2> 1468976 T4921 oasc.Overseer$ClusterStateUpdater.createCollection Create collection nodes_used_collection with numShards 2
[junit4:junit4] 2> 1468992 T4921 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"nodes_used_collection_shard1_replica1",
[junit4:junit4] 2> "collection":"nodes_used_collection",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:63245_smgeb",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:63245/smgeb"}
[junit4:junit4] 2> 1469005 T4921 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"nodes_used_collection_shard1_replica2",
[junit4:junit4] 2> "collection":"nodes_used_collection",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:63284_smgeb",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:63284/smgeb"}
[junit4:junit4] 2> 1469013 T4921 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":"shard2",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"nodes_used_collection_shard2_replica1",
[junit4:junit4] 2> "collection":"nodes_used_collection",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:63266_smgeb",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:63266/smgeb"}
[junit4:junit4] 2> 1469024 T4952 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 1469024 T4966 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 1469025 T4920 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 1469024 T4925 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 1469025 T4938 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 1469025 T4980 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 1469091 T4944 oasc.CoreContainer.registerCore registering core: nodes_used_collection_shard2_replica1
[junit4:junit4] 2> 1469091 T4944 oasc.ZkController.register Register replica - core:nodes_used_collection_shard2_replica1 address:http://127.0.0.1:63266/smgeb collection:nodes_used_collection shard:shard2
[junit4:junit4] 2> 1469092 T4944 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection/leader_elect/shard2/election
[junit4:junit4] 2> 1469114 T4944 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 1469122 T4944 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=179999
[junit4:junit4] 2> 1469982 T4959 oasc.CoreContainer.registerCore registering core: nodes_used_collection_shard2_replica2
[junit4:junit4] 2> 1469982 T4959 oasc.ZkController.register Register replica - core:nodes_used_collection_shard2_replica2 address:http://127.0.0.1:63275/smgeb collection:nodes_used_collection shard:shard2
[junit4:junit4] 2> 1469998 T4974 oasc.CoreContainer.registerCore registering core: nodes_used_collection_shard1_replica2
[junit4:junit4] 2> 1469998 T4974 oasc.ZkController.register Register replica - core:nodes_used_collection_shard1_replica2 address:http://127.0.0.1:63284/smgeb collection:nodes_used_collection shard:shard1
[junit4:junit4] 2> 1469998 T4912 oasc.CoreContainer.registerCore registering core: nodes_used_collection_shard1_replica1
[junit4:junit4] 2> 1469998 T4912 oasc.ZkController.register Register replica - core:nodes_used_collection_shard1_replica1 address:http://127.0.0.1:63245/smgeb collection:nodes_used_collection shard:shard1
[junit4:junit4] 2> 1470001 T4912 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection/leader_elect/shard1/election
[junit4:junit4] 2> 1470004 T4974 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection/leader_elect/shard1/election
[junit4:junit4] 2> 1470038 T4912 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 1470067 T4912 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 1470067 T4912 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 1470067 T4912 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:63245/smgeb/nodes_used_collection_shard1_replica1/
[junit4:junit4] 2> 1470067 T4912 oasu.PeerSync.sync PeerSync: core=nodes_used_collection_shard1_replica1 url=http://127.0.0.1:63245/smgeb START replicas=[http://127.0.0.1:63284/smgeb/nodes_used_collection_shard1_replica2/] nUpdates=100
[junit4:junit4] 2> 1470069 T4912 oasu.PeerSync.sync PeerSync: core=nodes_used_collection_shard1_replica1 url=http://127.0.0.1:63245/smgeb DONE. We have no versions. sync failed.
[junit4:junit4] 2> 1470069 T4912 oasc.SyncStrategy.syncReplicas Leader's attempt to sync with shard failed, moving to the next canidate
[junit4:junit4] 2> 1470070 T4912 oasc.ShardLeaderElectionContext.runLeaderProcess We failed sync, but we have no versions - we can't sync in that case - we were active before, so become leader anyway
[junit4:junit4] 2> 1470070 T4912 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:63245/smgeb/nodes_used_collection_shard1_replica1/
[junit4:junit4] 2> 1470070 T4912 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection/leaders/shard1
[junit4:junit4] 2> ASYNC NEW_CORE C833 name=nodes_used_collection_shard1_replica2 org.apache.solr.core.SolrCore@2ef01b20 url=http://127.0.0.1:63284/smgeb/nodes_used_collection_shard1_replica2 node=127.0.0.1:63284_smgeb C833_STATE=coll:nodes_used_collection core:nodes_used_collection_shard1_replica2 props:{shard=shard1, state=down, core=nodes_used_collection_shard1_replica2, collection=nodes_used_collection, node_name=127.0.0.1:63284_smgeb, base_url=http://127.0.0.1:63284/smgeb}
[junit4:junit4] 2> 1470090 T4973 C833 P63284 oasc.SolrCore.execute [nodes_used_collection_shard1_replica2] webapp=/smgeb path=/get params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=1
[junit4:junit4] 2> 1470192 T4944 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 1470192 T4944 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 1470192 T4944 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:63266/smgeb/nodes_used_collection_shard2_replica1/
[junit4:junit4] 2> 1470194 T4944 oasu.PeerSync.sync PeerSync: core=nodes_used_collection_shard2_replica1 url=http://127.0.0.1:63266/smgeb START replicas=[http://127.0.0.1:63275/smgeb/nodes_used_collection_shard2_replica2/] nUpdates=100
[junit4:junit4] 2> 1470195 T4944 oasu.PeerSync.sync PeerSync: core=nodes_used_collection_shard2_replica1 url=http://127.0.0.1:63266/smgeb DONE. We have no versions. sync failed.
[junit4:junit4] 2> 1470195 T4944 oasc.SyncStrategy.syncReplicas Leader's attempt to sync with shard failed, moving to the next canidate
[junit4:junit4] 2> 1470195 T4944 oasc.ShardLeaderElectionContext.runLeaderProcess We failed sync, but we have no versions - we can't sync in that case - we were active before, so become leader anyway
[junit4:junit4] 2> 1470195 T4944 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:63266/smgeb/nodes_used_collection_shard2_replica1/
[junit4:junit4] 2> 1470195 T4944 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection/leaders/shard2
[junit4:junit4] 2> ASYNC NEW_CORE C834 name=nodes_used_collection_shard2_replica2 org.apache.solr.core.SolrCore@51bae1ad url=http://127.0.0.1:63275/smgeb/nodes_used_collection_shard2_replica2 node=127.0.0.1:63275_smgeb C834_STATE=coll:nodes_used_collection core:nodes_used_collection_shard2_replica2 props:{shard=shard2, state=down, core=nodes_used_collection_shard2_replica2, collection=nodes_used_collection, node_name=127.0.0.1:63275_smgeb, base_url=http://127.0.0.1:63275/smgeb}
[junit4:junit4] 2> 1470216 T4960 C834 P63275 oasc.SolrCore.execute [nodes_used_collection_shard2_replica2] webapp=/smgeb path=/get params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=1
[junit4:junit4] 2> 1470650 T4921 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1470694 T4952 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 1470694 T4920 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 1470695 T4966 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 1470694 T4925 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 1470696 T4938 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 1470695 T4980 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 1470703 T4944 oasc.ZkController.register We are http://127.0.0.1:63266/smgeb/nodes_used_collection_shard2_replica1/ and leader is http://127.0.0.1:63266/smgeb/nodes_used_collection_shard2_replica1/
[junit4:junit4] 2> 1470703 T4944 oasc.ZkController.register No LogReplay needed for core=nodes_used_collection_shard2_replica1 baseURL=http://127.0.0.1:63266/smgeb
[junit4:junit4] 2> 1470704 T4944 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 1470705 T4944 oasc.ZkController.publish publishing core=nodes_used_collection_shard2_replica1 state=active
[junit4:junit4] 2> 1470709 T4944 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1470712 T4944 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={numShards=2&shard=shard2&name=nodes_used_collection_shard2_replica1&action=CREATE&collection=nodes_used_collection&wt=javabin&qt=/admin/cores&version=2} status=0 QTime=4866
[junit4:junit4] 2> 1470741 T4912 oasc.ZkController.register We are http://127.0.0.1:63245/smgeb/nodes_used_collection_shard1_replica1/ and leader is http://127.0.0.1:63245/smgeb/nodes_used_collection_shard1_replica1/
[junit4:junit4] 2> 1470741 T4912 oasc.ZkController.register No LogReplay needed for core=nodes_used_collection_shard1_replica1 baseURL=http://127.0.0.1:63245/smgeb
[junit4:junit4] 2> 1470741 T4912 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 1470741 T4912 oasc.ZkController.publish publishing core=nodes_used_collection_shard1_replica1 state=active
[junit4:junit4] 2> 1470745 T4912 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1470748 T4912 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={numShards=2&shard=shard1&name=nodes_used_collection_shard1_replica1&action=CREATE&collection=nodes_used_collection&wt=javabin&qt=/admin/cores&version=2} status=0 QTime=4909
[junit4:junit4] 2> 1471070 T4959 oasc.ZkController.register We are http://127.0.0.1:63275/smgeb/nodes_used_collection_shard2_replica2/ and leader is http://127.0.0.1:63266/smgeb/nodes_used_collection_shard2_replica1/
[junit4:junit4] 2> 1471071 T4959 oasc.ZkController.register No LogReplay needed for core=nodes_used_collection_shard2_replica2 baseURL=http://127.0.0.1:63275/smgeb
[junit4:junit4] 2> 1471071 T4959 oasc.ZkController.checkRecovery Core needs to recover:nodes_used_collection_shard2_replica2
[junit4:junit4] 2> 1471071 T4959 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4] 2> 1471072 T4992 C834 P63275 oasc.RecoveryStrategy.run Starting recovery process. core=nodes_used_collection_shard2_replica2 recoveringAfterStartup=true
[junit4:junit4] 2> 1471073 T4992 C834 P63275 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4] 2> 1471073 T4992 C834 P63275 oasc.ZkController.publish publishing core=nodes_used_collection_shard2_replica2 state=recovering
[junit4:junit4] 2> 1471073 T4959 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1471077 T4992 C834 P63275 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 1471077 T4959 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={numShards=2&shard=shard2&name=nodes_used_collection_shard2_replica2&action=CREATE&collection=nodes_used_collection&wt=javabin&qt=/admin/cores&version=2} status=0 QTime=5232
[junit4:junit4] 2> 1471094 T4947 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: 127.0.0.1:63275_smgeb_nodes_used_collection_shard2_replica2, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4] 2> 1471105 T4974 oasc.ZkController.register We are http://127.0.0.1:63284/smgeb/nodes_used_collection_shard1_replica2/ and leader is http://127.0.0.1:63245/smgeb/nodes_used_collection_shard1_replica1/
[junit4:junit4] 2> 1471105 T4974 oasc.ZkController.register No LogReplay needed for core=nodes_used_collection_shard1_replica2 baseURL=http://127.0.0.1:63284/smgeb
[junit4:junit4] 2> 1471106 T4974 oasc.ZkController.checkRecovery Core needs to recover:nodes_used_collection_shard1_replica2
[junit4:junit4] 2> 1471106 T4974 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4] 2> 1471107 T4993 C833 P63284 oasc.RecoveryStrategy.run Starting recovery process. core=nodes_used_collection_shard1_replica2 recoveringAfterStartup=true
[junit4:junit4] 2> 1471107 T4993 C833 P63284 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4] 2> 1471107 T4993 C833 P63284 oasc.ZkController.publish publishing core=nodes_used_collection_shard1_replica2 state=recovering
[junit4:junit4] 2> 1471108 T4974 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1471111 T4993 C833 P63284 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 1471111 T4974 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={numShards=2&shard=shard1&name=nodes_used_collection_shard1_replica2&action=CREATE&collection=nodes_used_collection&wt=javabin&qt=/admin/cores&version=2} status=0 QTime=5272
[junit4:junit4] 2> 1471112 T4922 oasc.OverseerCollectionProcessor.createCollection Finished create command on all shards for collection: nodes_used_collection
[junit4:junit4] 2> 1471123 T4916 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: 127.0.0.1:63284_smgeb_nodes_used_collection_shard1_replica2, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4] 2> 1471128 T4938 oasc.DistributedQueue$LatchChildWatcher.process Watcher fired on path: /overseer/collection-queue-work/qnr-0000000000 state: SyncConnected type NodeDataChanged
[junit4:junit4] 2> 1471132 T4922 oasc.OverseerCollectionProcessor.run Overseer Collection Processor: Message id:/overseer/collection-queue-work/qn-0000000000 complete, response:{success={null={responseHeader={status=0,QTime=4866},core=nodes_used_collection_shard2_replica1},null={responseHeader={status=0,QTime=4909},core=nodes_used_collection_shard1_replica1},null={responseHeader={status=0,QTime=5232},core=nodes_used_collection_shard2_replica2},null={responseHeader={status=0,QTime=5272},core=nodes_used_collection_shard1_replica2}}}
[junit4:junit4] 2> 1471136 T4929 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/collections params={numShards=2&name=nodes_used_collection&replicationFactor=2&action=CREATE&wt=javabin&version=2} status=0 QTime=5310
[junit4:junit4] 2> 1471137 T4898 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4] 2> 1471139 T4898 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 1471148 T4995 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2618f353 name:ZooKeeperConnection Watcher:127.0.0.1:63238/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 1471148 T4898 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 1471150 T4898 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 1471155 T4898 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4] 2> 1471159 T4898 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 1471164 T4997 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7990448a name:ZooKeeperConnection Watcher:127.0.0.1:63238/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 1471164 T4898 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 1471167 T4898 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 1471182 T4948 oasha.CollectionsHandler.handleCreateAction Creating Collection : numShards=5&maxShardsPerNode=3&name=awholynewcollection_0&replicationFactor=2&action=CREATE&wt=javabin&version=2
[junit4:junit4] 2> 1471186 T4920 oasc.DistributedQueue$LatchChildWatcher.process Watcher fired on path: /overseer/collection-queue-work state: SyncConnected type NodeChildrenChanged
[junit4:junit4] 2> 1471191 T4922 oasc.OverseerCollectionProcessor.run Overseer Collection Processor: Get the message id:/overseer/collection-queue-work/qn-0000000002 message:{
[junit4:junit4] 2> "operation":"createcollection",
[junit4:junit4] 2> "numShards":"5",
[junit4:junit4] 2> "maxShardsPerNode":"3",
[junit4:junit4] 2> "createNodeSet":null,
[junit4:junit4] 2> "name":"awholynewcollection_0",
[junit4:junit4] 2> "replicationFactor":"2"}
[junit4:junit4] 2> 1471192 T4922 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard1_replica1 as part of slice shard1 of collection awholynewcollection_0 on 127.0.0.1:63245_smgeb
[junit4:junit4] 2> 1471192 T4922 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard1_replica2 as part of slice shard1 of collection awholynewcollection_0 on 127.0.0.1:63284_smgeb
[junit4:junit4] 2> 1471192 T4922 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard2_replica1 as part of slice shard2 of collection awholynewcollection_0 on 127.0.0.1:63257_smgeb
[junit4:junit4] 2> 1471193 T4922 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard2_replica2 as part of slice shard2 of collection awholynewcollection_0 on 127.0.0.1:63266_smgeb
[junit4:junit4] 2> 1471193 T4922 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard3_replica1 as part of slice shard3 of collection awholynewcollection_0 on 127.0.0.1:63275_smgeb
[junit4:junit4] 2> 1471194 T4922 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard3_replica2 as part of slice shard3 of collection awholynewcollection_0 on 127.0.0.1:63245_smgeb
[junit4:junit4] 2> 1471195 T4913 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard1_replica1' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369431557356\awholynewcollection_0_shard1_replica1
[junit4:junit4] 2> 1471196 T4913 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 1471197 T4932 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard2_replica1' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1369431558608\awholynewcollection_0_shard2_replica1
[junit4:junit4] 2> 1471197 T4932 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 1471195 T4972 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard1_replica2' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1369431565710\awholynewcollection_0_shard1_replica2
[junit4:junit4] 2> 1471198 T4972 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 1471198 T4922 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard4_replica1 as part of slice shard4 of collection awholynewcollection_0 on 127.0.0.1:63284_smgeb
[junit4:junit4] 2> 1471199 T4913 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:awholynewcollection_0
[junit4:junit4] 2> 1471200 T4913 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 1471198 T4943 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard2_replica2' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1369431560928\awholynewcollection_0_shard2_replica2
[junit4:junit4] 2> 1471202 T4943 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 1471197 T4957 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard3_replica1' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369431563307\awholynewcollection_0_shard3_replica1
[junit4:junit4] 2> 1471205 T4957 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 1471204 T4973 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard4_replica1' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1369431565710\awholynewcollection_0_shard4_replica1
[junit4:junit4] 2> 1471206 T4973 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 1471202 T4972 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:awholynewcollection_0
[junit4:junit4] 2> 1471207 T4972 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 1471200 T4922 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard4_replica2 as part of slice shard4 of collection awholynewcollection_0 on 127.0.0.1:63257_smgeb
[junit4:junit4] 2> 1471199 T4932 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:awholynewcollection_0
[junit4:junit4] 2> 1471209 T4932 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 1471210 T4922 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard5_replica1 as part of slice shard5 of collection awholynewcollection_0 on 127.0.0.1:63266_smgeb
[junit4:junit4] 2> 1471207 T4973 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:awholynewcollection_0
[junit4:junit4] 2> 1471211 T4973 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 1471207 T4957 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:awholynewcollection_0
[junit4:junit4] 2> 1471214 T4957 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 1471206 T4943 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:awholynewcollection_0
[junit4:junit4] 2> 1471218 T4933 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard4_replica2' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1369431558608\awholynewcollection_0_shard4_replica2
[junit4:junit4] 2> 1471218 T4933 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 1471206 T4913 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4:junit4] 2> 1471220 T4933 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:awholynewcollection_0
[junit4:junit4] 2> 1471220 T4957 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4:junit4] 2> 1471221 T4957 oascc.SolrZkClient.makePath makePath: /collections/awholynewcollection_0
[junit4:junit4] 2> 1471205 T4914 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard3_replica2' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369431557356\awholynewcollection_0_shard3_replica2
[junit4:junit4] 2> 1471222 T4914 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 1471220 T4933 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 1471223 T4914 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:awholynewcollection_0
[junit4:junit4] 2> 1471224 T4914 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 1471220 T4913 oascc.SolrZkClient.makePath makePath: /collections/awholynewcollection_0
[junit4:junit4] 2> 1471219 T4973 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4:junit4] 2> 1471226 T4973 oascc.SolrZkClient.makePath makePath: /collections/awholynewcollection_0
[junit4:junit4] 2> 1471218 T4943 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 1471217 T4932 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4:junit4] 2> 1471228 T4932 oascc.SolrZkClient.makePath makePath: /collections/awholynewcollection_0
[junit4:junit4] 2> 1471216 T4945 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard5_replica1' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1369431560928\awholynewcollection_0_shard5_replica1
[junit4:junit4] 2> 1471229 T4945 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 1471216 T4972 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4:junit4] 2> 1471231 T4972 oascc.SolrZkClient.makePath makePath: /collections/awholynewcollection_0
[junit4:junit4] 2> 1471233 T4914 oascc.SolrZkClient.makePath makePath: /collections/awholynewcollection_0
[junit4:junit4] 2> 1471211 T4922 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard5_replica2 as part of slice shard5 of collection awholynewcollection_0 on 127.0.0.1:63275_smgeb
[junit4:junit4] 2> 1471233 T4933 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4:junit4] 2> 1471236 T4933 oascc.SolrZkClient.makePath makePath: /collections/awholynewcollection_0
[junit4:junit4] 2> 1471238 T4945 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 1471238 T4945 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 1471241 T4943 oascc.SolrZkClient.makePath makePath: /collections/awholynewcollection_0
[junit4:junit4] 2> 1471240 T4957 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 1471246 T4958 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard5_replica2' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369431563307\awholynewcollection_0_shard5_replica2
[junit4:junit4] 2> 1471247 T4958 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 1471248 T4932 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 1471248 T4972 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 1471249 T4914 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 1471250 T4913 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 1471253 T4973 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 1471257 T4958 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 1471257 T4958 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 1471257 T4945 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1369431560928\awholynewcollection_0_shard5_replica1\'
[junit4:junit4] 2> 1471260 T4933 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 1471265 T4914 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369431557356\awholynewcollection_0_shard3_replica2\'
[junit4:junit4] 2> 1471270 T4972 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1369431565710\awholynewcollection_0_shard1_replica2\'
[junit4:junit4] 2> 1471273 T4932 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1369431558608\awholynewcollection_0_shard2_replica1\'
[junit4:junit4] 2> 1471274 T4913 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369431557356\awholynewcollection_0_shard1_replica1\'
[junit4:junit4] 2> 1471276 T4957 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369431563307\awholynewcollection_0_shard3_replica1\'
[junit4:junit4] 2> 1471279 T4958 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369431563307\awholynewcollection_0_shard5_replica2\'
[junit4:junit4] 2> 1471282 T4973 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1369431565710\awholynewcollection_0_shard4_replica1\'
[junit4:junit4] 2> 1471339 T4943 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 1471342 T4933 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1369431558608\awholynewcollection_0_shard4_replica2\'
[junit4:junit4] 2> 1471398 T4958 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 1471476 T4945 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 1471505 T4943 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1369431560928\awholynewcollection_0_shard2_replica2\'
[junit4:junit4] 2> 1471528 T4914 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 1471668 T4958 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 1471669 T4945 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 1471717 T4945 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 1471721 T4958 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 1471736 T4945 oass.IndexSchema.readSchema [awholynewcollection_0_shard5_replica1] Schema name=test
[junit4:junit4] 2> 1471736 T4913 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 1471742 T4958 oass.IndexSchema.readSchema [awholynewcollection_0_shard5_replica2] Schema name=test
[junit4:junit4] 2> 1471777 T4973 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 1471811 T4932 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 1471812 T4957 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 1471824 T4972 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 1471895 T4943 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 1471916 T4972 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 1471931 T4957 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 1471960 T4972 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 1471961 T4957 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 1472075 T4943 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 1472087 T4933 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 1472088 T4914 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 1472150 T4933 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 1472076 T4972 oass.IndexSchema.readSchema [awholynewcollection_0_shard1_replica2] Schema name=test
[junit4:junit4] 2> 1472199 T4913 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 1472213 T4973 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 1472243 T4957 oass.IndexSchema.readSchema [awholynewcollection_0_shard3_replica1] Schema name=test
[junit4:junit4] 2> 1472087 T4932 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 1472648 T4943 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 1472653 T4943 oass.IndexSchema.readSchema [awholynewcollection_0_shard2_replica2] Schema name=test
[junit4:junit4] 2> 1472676 T4933 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 1472677 T4913 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 1472679 T4973 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 1472681 T4914 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 1472681 T4932 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 1472686 T4973 oass.IndexSchema.readSchema [awholynewcollection_0_shard4_replica1] Schema name=test
[junit4:junit4] 2> 1472716 T4933 oass.IndexSchema.readSchema [awholynewcollection_0_shard4_replica2] Schema name=test
[junit4:junit4] 2> 1472766 T4914 oass.IndexSchema.readSchema [awholynewcollection_0_shard3_replica2] Schema name=test
[junit4:junit4] 2> 1472809 T4921 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1472817 T4921 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:63266_smgeb_nodes_used_collection_shard2_replica1",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":"shard2",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"nodes_used_collection_shard2_replica1",
[junit4:junit4] 2> "collection":"nodes_used_collection",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:63266_smgeb",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:63266/smgeb"}
[junit4:junit4] 2> 1472822 T4932 oass.IndexSchema.readSchema [awholynewcollection_0_shard2_replica1] Schema name=test
[junit4:junit4] 2> 1472824 T4913 oass.IndexSchema.readSchema [awholynewcollection_0_shard1_replica1] Schema name=test
[junit4:junit4] 2> 1472848 T4921 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:63245_smgeb_nodes_used_collection_shard1_replica1",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"nodes_used_collection_shard1_replica1",
[junit4:junit4] 2> "collection":"nodes_used_collection",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:63245_smgeb",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:63245/smgeb"}
[junit4:junit4] 2> 1472865 T4921 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:63275_smgeb_nodes_used_collection_shard2_replica2",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":"shard2",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"recovering",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"nodes_used_collection_shard2_replica2",
[junit4:junit4] 2> "collection":"nodes_used_collection",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:63275_smgeb",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:63275/smgeb"}
[junit4:junit4] 2> 1472888 T4921 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:63284_smgeb_nodes_used_collection_shard1_replica2",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"recovering",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"nodes_used_collection_shard1_replica2",
[junit4:junit4] 2> "collection":"nodes_used_collection",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:63284_smgeb",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:63284/smgeb"}
[junit4:junit4] 2> 1472914 T4920 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 1472914 T4980 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 1472914 T4938 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 1472916 T4952 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 1472916 T4966 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 1472916 T4997 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 1472919 T4995 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 1472919 T4925 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 1473561 T4916 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: 127.0.0.1:63284_smgeb_nodes_used_collection_shard1_replica2, state: recovering, checkLive: true, onlyIfLeader: true for: 2 seconds.
[junit4:junit4] 2> 1473561 T4916 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={coreNodeName=127.0.0.1:63284_smgeb_nodes_used_collection_shard1_replica2&state=recovering&nodeName=127.0.0.1:63284_smgeb&action=PREPRECOVERY&checkLive=true&core=nodes_used_collection_shard1_replica1&wt=javabin&onlyIfLeader=true&version=2} status=0 QTime=2438
[junit4:junit4] 2> 1473596 T4958 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 1473702 T4947 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: 127.0.0.1:63275_smgeb_nodes_used_collection_shard2_replica2, state: recovering, checkLive: true, onlyIfLeader: true for: 2 seconds.
[junit4:junit4] 2> 1473702 T4947 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={coreNodeName=127.0.0.1:63275_smgeb_nodes_used_collection_shard2_replica2&state=recovering&nodeName=127.0.0.1:63275_smgeb&action=PREPRECOVERY&checkLive=true&core=nodes_used_collection_shard2_replica1&wt=javabin&onlyIfLeader=true&version=2} status=0 QTime=2608
[junit4:junit4] 2> 1473709 T4958 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 1473715 T4958 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 1475044 T4958 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 1475067 T4958 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 1475091 T4958 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 1475100 T4958 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 1475101 T4958 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 1475101 T4958 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 1475115 T4958 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 1475115 T4958 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 1475116 T4958 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 1475116 T4958 oasc.SolrCore.<init> [awholynewcollection_0_shard5_replica2] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369431563307\awholynewcollection_0_shard5_replica2\, dataDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369431563307\awholynewcollection_0_shard5_replica2\data\
[junit4:junit4] 2> 1475118 T4958 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@5f20a14c
[junit4:junit4] 2> 1475119 T4958 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 1475123 T4958 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369431563307\awholynewcollection_0_shard5_replica2\data\
[junit4:junit4] 2> 1475123 T4958 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369431563307\awholynewcollection_0_shard5_replica2\data\index/
[junit4:junit4] 2> 1475124 T4958 oasc.SolrCore.initIndex WARN [awholynewcollection_0_shard5_replica2] Solr index directory 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369431563307\awholynewcollection_0_shard5_replica2\data\index' doesn't exist. Creating new index...
[junit4:junit4] 2> 1475144 T4958 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369431563307\awholynewcollection_0_shard5_replica2\data\index
[junit4:junit4] 2> 1475298 T4972 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 1475351 T4972 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 1475358 T4972 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 1475677 T4932 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 1475686 T4932 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 1475693 T4932 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 1475715 T4958 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@2c350d9 lockFactory=org.apache.lucene.store.NativeFSLockFactory@3f16c78c),segFN=segments_1,generation=1}
[junit4:junit4] 2> 1475715 T4958 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 1475734 T4958 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 1475734 T4958 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 1475736 T4958 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 1475737 T4958 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 1475738 T4958 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 1475738 T4958 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 1475739 T4958 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 1475739 T4958 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 1475740 T4958 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> ASYNC NEW_CORE C835 name=nodes_used_collection_shard1_replica2 org.apache.solr.core.SolrCore@2ef01b20 url=http://127.0.0.1:63284/smgeb/nodes_used_collection_shard1_replica2 node=127.0.0.1:63284_smgeb C835_STATE=coll:nodes_used_collection core:nodes_used_collection_shard1_replica2 props:{shard=shard1, state=recovering, core=nodes_used_collection_shard1_replica2, collection=nodes_used_collection, node_name=127.0.0.1:63284_smgeb, base_url=http://127.0.0.1:63284/smgeb}
[junit4:junit4] 2> 1475743 T4993 C835 P63284 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:63245/smgeb/nodes_used_collection_shard1_replica1/ core=nodes_used_collection_shard1_replica2 - recoveringAfterStartup=true
[junit4:junit4] 2> 1475743 T4993 C835 P63284 oasu.PeerSync.sync PeerSync: core=nodes_used_collection_shard1_replica2 url=http://127.0.0.1:63284/smgeb START replicas=[http://127.0.0.1:63245/smgeb/nodes_used_collection_shard1_replica1/] nUpdates=100
[junit4:junit4] 2> 1475744 T4993 C835 P63284 oasu.PeerSync.sync WARN no frame of reference to tell of we've missed updates
[junit4:junit4] 2> 1475745 T4993 C835 P63284 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=nodes_used_collection_shard1_replica2
[junit4:junit4] 2> 1475745 T4993 C835 P63284 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=nodes_used_collection_shard1_replica2
[junit4:junit4] 2> 1475745 T4993 C835 P63284 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=nodes_used_collection_shard1_replica2
[junit4:junit4] 2> 1475746 T4993 C835 P63284 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4] 2> 1475746 T4993 C835 P63284 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:63245/smgeb/nodes_used_collection_shard1_replica1/. core=nodes_used_collection_shard1_replica2
[junit4:junit4] 2> 1475746 T4993 C835 P63284 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> ASYNC NEW_CORE C836 name=nodes_used_collection_shard2_replica2 org.apache.solr.core.SolrCore@51bae1ad url=http://127.0.0.1:63275/smgeb/nodes_used_collection_shard2_replica2 node=127.0.0.1:63275_smgeb C836_STATE=coll:nodes_used_collection core:nodes_used_collection_shard2_replica2 props:{shard=shard2, state=recovering, core=nodes_used_collection_shard2_replica2, collection=nodes_used_collection, node_name=127.0.0.1:63275_smgeb, base_url=http://127.0.0.1:63275/smgeb}
[junit4:junit4] 2> 1475839 T4992 C836 P63275 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:63266/smgeb/nodes_used_collection_shard2_replica1/ core=nodes_used_collection_shard2_replica2 - recoveringAfterStartup=true
[junit4:junit4] 2> 1475859 T4992 C836 P63275 oasu.PeerSync.sync PeerSync: core=nodes_used_collection_shard2_replica2 url=http://127.0.0.1:63275/smgeb START replicas=[http://127.0.0.1:63266/smgeb/nodes_used_collection_shard2_replica1/] nUpdates=100
[junit4:junit4] 2> ASYNC NEW_CORE C837 name=nodes_used_collection_shard1_replica1 org.apache.solr.core.SolrCore@761e0226 url=http://127.0.0.1:63245/smgeb/nodes_used_collection_shard1_replica1 node=127.0.0.1:63245_smgeb C837_STATE=coll:nodes_used_collection core:nodes_used_collection_shard1_replica1 props:{shard=shard1, state=active, core=nodes_used_collection_shard1_replica1, collection=nodes_used_collection, node_name=127.0.0.1:63245_smgeb, base_url=http://127.0.0.1:63245/smgeb, leader=true}
[junit4:junit4] 2> 1475858 T4912 C837 P63245 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 1475861 T4992 C836 P63275 oasu.PeerSync.sync WARN no frame of reference to tell of we've missed updates
[junit4:junit4] 2> 1475861 T4992 C836 P63275 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=nodes_used_collection_shard2_replica2
[junit4:junit4] 2> 1475862 T4992 C836 P63275 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=nodes_used_collection_shard2_replica2
[junit4:junit4] 2> 1475862 T4992 C836 P63275 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=nodes_used_collection_shard2_replica2
[junit4:junit4] 2> 1475862 T4992 C836 P63275 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4] 2> 1475862 T4992 C836 P63275 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:63266/smgeb/nodes_used_collection_shard2_replica1/. core=nodes_used_collection_shard2_replica2
[junit4:junit4] 2> 1475863 T4992 C836 P63275 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 1475851 T4915 C837 P63245 oasc.SolrCore.execute [nodes_used_collection_shard1_replica1] webapp=/smgeb path=/get params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=8
[junit4:junit4] 2> 1475875 T4958 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 1475889 T4958 oass.SolrIndexSearcher.<init> Opening Searcher@43a79f2e main
[junit4:junit4] 2> 1475893 T4958 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369431563307\awholynewcollection_0_shard5_replica2\data\tlog
[junit4:junit4] 2> 1475893 T4958 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 1475893 T4958 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 1475902 T4972 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> ASYNC NEW_CORE C838 name=nodes_used_collection_shard2_replica1 org.apache.solr.core.SolrCore@678ef8c1 url=http://127.0.0.1:63266/smgeb/nodes_used_collection_shard2_replica1 node=127.0.0.1:63266_smgeb C838_STATE=coll:nodes_used_collection core:nodes_used_collection_shard2_replica1 props:{shard=shard2, state=active, core=nodes_used_collection_shard2_replica1, collection=nodes_used_collection, node_name=127.0.0.1:63266_smgeb, base_url=http://127.0.0.1:63266/smgeb, leader=true}
[junit4:junit4] 2> 1475909 T4946 C838 P63266 oasc.SolrCore.execute [nodes_used_collection_shard2_replica1] webapp=/smgeb path=/get params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=0
[junit4:junit4] 2> 1475919 T4932 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 1475920 T4912 C837 P63245 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@2406ed74 lockFactory=org.apache.lucene.store.NativeFSLockFactory@a8e1bf9),segFN=segments_1,generation=1}
[junit4:junit4] 2> 1475929 T4914 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 1475930 T4912 C837 P63245 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 1475931 T4912 C837 P63245 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@2406ed74 lockFactory=org.apache.lucene.store.NativeFSLockFactory@a8e1bf9),segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@2406ed74 lockFactory=org.apache.lucene.store.NativeFSLockFactory@a8e1bf9),segFN=segments_2,generation=2}
[junit4:junit4] 2> 1475986 T4912 C837 P63245 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 1475983 T4973 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 1475954 T4957 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 1475989 T4958 oasc.ZkController.publish publishing core=awholynewcollection_0_shard5_replica2 state=down
[junit4:junit4] 2> 1475938 T4947 C838 P63266 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 1475988 T5006 oasc.SolrCore.registerSearcher [awholynewcollection_0_shard5_replica2] Registered new searcher Searcher@43a79f2e main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 1475987 T4912 C837 P63245 oass.SolrIndexSearcher.<init> Opening Searcher@1b9898d4 realtime
[junit4:junit4] 2> 1475997 T4912 C837 P63245 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 1475998 T4912 C837 P63245 oasup.LogUpdateProcessor.finish [nodes_used_collection_shard1_replica1] webapp=/smgeb path=/update params={waitSearcher=true&openSearcher=false&commit=true&wt=javabin&commit_end_point=true&version=2&softCommit=false} {commit=} 0 140
[junit4:junit4] 2> 1475999 T4993 C835 P63284 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 1475999 T4993 C835 P63284 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4] 2> 1476002 T4914 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 1476016 T4973 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 1476014 T4913 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 1476026 T4914 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 1476033 T4915 C837 P63245 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 1476034 T4915 C837 P63245 oasc.SolrCore.execute [nodes_used_collection_shard1_replica1] webapp=/smgeb path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=14
[junit4:junit4] 2> 1476034 T4957 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 1476035 T4993 C835 P63284 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4:junit4] 2> 1476036 T4993 C835 P63284 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4:junit4] 2> 1476036 T4993 C835 P63284 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4] 2> 1476040 T4916 C837 P63245 oasc.SolrCore.execute [nodes_used_collection_shard1_replica1] webapp=/smgeb path=/replication params={command=filelist&qt=/replication&wt=javabin&generation=2&version=2} status=0 QTime=1
[junit4:junit4] 2> 1476042 T4993 C835 P63284 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 1
[junit4:junit4] 2> 1476046 T4993 C835 P63284 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1369431565710\nodes_used_collection_shard1_replica2\data\index.20130524213938073
[junit4:junit4] 2> 1476046 T4993 C835 P63284 oash.SnapPuller.fetchLatestIndex Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory@2a81e607 lockFactory=org.apache.lucene.store.NativeFSLockFactory@7dc81b91) fullCopy=false
[junit4:junit4] 2> 1476058 T4913 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 1476063 T4913 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 1476072 T4973 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 1476084 T4957 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 1476100 T4912 C837 P63245 oasc.SolrCore.execute [nodes_used_collection_shard1_replica1] webapp=/smgeb path=/replication params={file=segments_2&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=1
[junit4:junit4] 2> 1476104 T4993 C835 P63284 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4] 2> 1476108 T4914 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 1476117 T4993 C835 P63284 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4] 2> 1476117 T4993 C835 P63284 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=nodes_used_collection_shard1_replica2
[junit4:junit4] 2> 1476150 T4972 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 1476163 T4932 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 1476171 T4914 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 1476173 T4972 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 1476179 T4972 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 1476179 T4972 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 1476180 T4972 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 1476185 T4972 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 1476186 T4972 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 1476186 T4972 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 1476187 T4972 oasc.SolrCore.<init> [awholynewcollection_0_shard1_replica2] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1369431565710\awholynewcollection_0_shard1_replica2\, dataDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1369431565710\awholynewcollection_0_shard1_replica2\data\
[junit4:junit4] 2> 1476187 T4972 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@5f20a14c
[junit4:junit4] 2> 1476188 T4972 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 1476190 T4913 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 1476191 T4973 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 1476192 T4932 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 1476195 T4972 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1369431565710\awholynewcollection_0_shard1_replica2\data\
[junit4:junit4] 2> 1476195 T4972 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1369431565710\awholynewcollection_0_shard1_replica2\data\index/
[junit4:junit4] 2> 1476196 T4972 oasc.SolrCore.initIndex WARN [awholynewcollection_0_shard1_replica2] Solr index directory 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1369431565710\awholynewcollection_0_shard1_replica2\data\index' doesn't exist. Creating new index...
[junit4:junit4] 2> 1476197 T4957 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 1476197 T4972 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1369431565710\awholynewcollection_0_shard1_replica2\data\index
[junit4:junit4] 2> 1476200 T4932 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 1476201 T4932 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 1476201 T4932 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 1476209 T4932 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 1476210 T4932 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 1476210 T4932 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 1476211 T4932 oasc.SolrCore.<init> [awholynewcollection_0_shard2_replica1] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1369431558608\awholynewcollection_0_shard2_replica1\, dataDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1369431558608\awholynewcollection_0_shard2_replica1\data\
[junit4:junit4] 2> 1476211 T4932 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@5f20a14c
[junit4:junit4] 2> 1476212 T4932 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 1476214 T4914 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 1476217 T4932 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1369431558608\awholynewcollection_0_shard2_replica1\data\
[junit4:junit4] 2> 1476218 T4914 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 1476219 T4914 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 1476219 T4914 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 1476219 T4932 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1369431558608\awholynewcollection_0_shard2_replica1\data\index/
[junit4:junit4] 2> 1476220 T4932 oasc.SolrCore.initIndex WARN [awholynewcollection_0_shard2_replica1] Solr index directory 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1369431558608\awholynewcollection_0_shard2_replica1\data\index' doesn't exist. Creating new index...
[junit4:junit4] 2> 1476221 T4932 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1369431558608\awholynewcollection_0_shard2_replica1\data\index
[junit4:junit4] 2> 1476222 T4973 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 1476219 T4993 C835 P63284 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@4fb57a6a lockFactory=org.apache.lucene.store.NativeFSLockFactory@7d1478c1),segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@4fb57a6a lockFactory=org.apache.lucene.store.NativeFSLockFactory@7d1478c1),segFN=segments_2,generation=2}
[junit4:junit4] 2> 1476219 T4947 C838 P63266 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@2eb982e7 lockFactory=org.apache.lucene.store.NativeFSLockFactory@15a2584e),segFN=segments_1,generation=1}
[junit4:junit4] 2> 1476226 T4993 C835 P63284 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 1476238 T4993 C835 P63284 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4] 2> 1476239 T4993 C835 P63284 oass.SolrIndexSearcher.<init> Opening Searcher@12ca8537 main
[junit4:junit4] 2> 1476240 T4988 oasc.SolrCore.registerSearcher [nodes_used_collection_shard1_replica2] Registered new searcher Searcher@12ca8537 main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 1476243 T4914 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 1476243 T4914 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 1476244 T4914 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 1476244 T4914 oasc.SolrCore.<init> [awholynewcollection_0_shard3_replica2] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369431557356\awholynewcollection_0_shard3_replica2\, dataDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369431557356\awholynewcollection_0_shard3_replica2\data\
[junit4:junit4] 2> 1476245 T4914 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@5f20a14c
[junit4:junit4] 2> 1476245 T4914 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 1476235 T4972 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@4cfd8787 lockFactory=org.apache.lucene.store.NativeFSLockFactory@55a43583),segFN=segments_1,generation=1}
[junit4:junit4] 2> 1476247 T4972 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 1476238 T4957 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 1476252 T4913 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 1476236 T4947 C838 P63266 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 1476253 T4972 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 1476257 T4972 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 1476258 T4972 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 1476259 T4972 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 1476259 T4972 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 1476259 T4972 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 1476260 T4972 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 1476261 T4972 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 1476261 T4972 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 1476248 T4914 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369431557356\awholynewcollection_0_shard3_replica2\data\
[junit4:junit4] 2> 1476263 T4914 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369431557356\awholynewcollection_0_shard3_replica2\data\index/
[junit4:junit4] 2> 1476263 T4914 oasc.SolrCore.initIndex WARN [awholynewcollection_0_shard3_replica2] Solr index directory 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369431557356\awholynewcollection_0_shard3_replica2\data\index' doesn't exist. Creating new index...
[junit4:junit4] 2> 1476248 T4993 C835 P63284 oasc.CachingDirectoryFactory.closeCacheValue looking to close C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1369431565710\nodes_used_collection_shard1_replica2\data\index.20130524213938073 [CachedDir<<refCount=0;path=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1369431565710\nodes_used_collection_shard1_replica2\data\index.20130524213938073;done=true>>]
[junit4:junit4] 2> 1476264 T4993 C835 P63284 oasc.CachingDirectoryFactory.close Closing directory: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1369431565710\nodes_used_collection_shard1_replica2\data\index.20130524213938073
[junit4:junit4] 2> 1476265 T4914 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369431557356\awholynewcollection_0_shard3_replica2\data\index
[junit4:junit4] 2> 1476275 T4947 C838 P63266 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@2eb982e7 lockFactory=org.apache.lucene.store.NativeFSLockFactory@15a2584e),segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@2eb982e7 lockFactory=org.apache.lucene.store.NativeFSLockFactory@15a2584e),segFN=segments_2,generation=2}
[junit4:junit4] 2> 1476276 T4947 C838 P63266 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 1476276 T4932 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@65bb013c lockFactory=org.apache.lucene.store.NativeFSLockFactory@f1a9785),segFN=segments_1,generation=1}
[junit4:junit4] 2> 1476278 T4932 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 1476279 T4947 C838 P63266 oass.SolrIndexSearcher.<init> Opening Searcher@638209b0 realtime
[junit4:junit4] 2> 1476280 T4947 C838 P63266 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 1476280 T4947 C838 P63266 oasup.LogUpdateProcessor.finish [nodes_used_collection_shard2_replica1] webapp=/smgeb path=/update params={waitSearcher=true&openSearcher=false&commit=true&wt=javabin&commit_end_point=true&version=2&softCommit=false} {commit=} 0 343
[junit4:junit4] 2> 1476276 T4993 C835 P63284 oasc.CachingDirectoryFactory.closeCacheValue Removing directory before core close: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1369431565710\nodes_used_collection_shard1_replica2\data\index.20130524213938073
[junit4:junit4] 2> 1476281 T4992 C836 P63275 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 1476282 T4992 C836 P63275 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4] 2> 1476282 T4993 C835 P63284 oasc.RecoveryStrategy.replay No replay needed. core=nodes_used_collection_shard1_replica2
[junit4:junit4] 2> 1476282 T4993 C835 P63284 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=nodes_used_collection_shard1_replica2
[junit4:junit4] 2> 1476283 T4993 C835 P63284 oasc.ZkController.publish publishing core=nodes_used_collection_shard1_replica2 state=active
[junit4:junit4] 2> 1476286 T4973 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 1476296 T4946 C838 P63266 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 1476297 T4946 C838 P63266 oasc.SolrCore.execute [nodes_used_collection_shard2_replica1] webapp=/smgeb path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=2
[junit4:junit4] 2> 1476298 T4992 C836 P63275 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4:junit4] 2> 1476298 T4992 C836 P63275 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4:junit4] 2> 1476298 T4992 C836 P63275 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4] 2> 1476309 T4932 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 1476309 T4932 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 1476309 T4932 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 1476311 T4932 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 1476312 T4932 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 1476312 T4932 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 1476312 T4932 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 1476313 T4932 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 1476314 T4932 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 1476330 T4993 C835 P63284 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=nodes_used_collection_shard1_replica2
[junit4:junit4] 2> 1476330 T4914 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@3eb71843 lockFactory=org.apache.lucene.store.NativeFSLockFactory@54c8e572),segFN=segments_1,generation=1}
[junit4:junit4] 2> 1476331 T4914 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 1476336 T4973 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 1476337 T4973 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 1476337 T4973 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 1476349 T4932 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 1476351 T4973 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 1476351 T4973 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 1476352 T4973 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 1476352 T4973 oasc.SolrCore.<init> [awholynewcollection_0_shard4_replica1] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1369431565710\awholynewcollection_0_shard4_replica1\, dataDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1369431565710\awholynewcollection_0_shard4_replica1\data\
[junit4:junit4] 2> 1476352 T4973 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@5f20a14c
[junit4:junit4] 2> 1476353 T4973 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 1476355 T4932 oass.SolrIndexSearcher.<init> Opening Searcher@21e2b9e7 main
[junit4:junit4] 2> 1476355 T4972 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 1476357 T4932 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1369431558608\awholynewcollection_0_shard2_replica1\data\tlog
[junit4:junit4] 2> 1476363 T4913 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 1476363 T4932 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 1476364 T4932 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 1476367 T4972 oass.SolrIndexSearcher.<init> Opening Searcher@44234deb main
[junit4:junit4] 2> 1476405 T4972 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1369431565710\awholynewcollection_0_shard1_replica2\data\tlog
[junit4:junit4] 2> 1476409 T4914 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 1476410 T4914 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 1476410 T4914 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 1476411 T4914 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 1476415 T4914 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 1476415 T4914 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 1476415 T4914 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 1476415 T4914 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 1476415 T4914 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 1476403 T5008 oasc.SolrCore.registerSearcher [awholynewcollection_0_shard2_replica1] Registered new searcher Searcher@21e2b9e7 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 1476417 T4913 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 1476417 T4913 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 1476418 T4913 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 1476402 T4932 oasc.ZkController.publish publishing core=awholynewcollection_0_shard2_replica1 state=down
[junit4:junit4] 2> 1476428 T4972 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 1476428 T4972 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 1476393 T4973 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1369431565710\awholynewcollection_0_shard4_replica1\data\
[junit4:junit4] 2> 1476603 T4973 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1369431565710\awholynewcollection_0_shard4_replica1\data\index/
[junit4:junit4] 2> 1476604 T4973 oasc.SolrCore.initIndex WARN [awholynewcollection_0_shard4_replica1] Solr index directory 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1369431565710\awholynewcollection_0_shard4_replica1\data\index' doesn't exist. Creating new index...
[junit4:junit4] 2> 1476605 T4973 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1369431565710\awholynewcollection_0_shard4_replica1\data\index
[junit4:junit4] 2> 1476603 T5009 oasc.SolrCore.registerSearcher [awholynewcollection_0_shard1_replica2] Registered new searcher Searcher@44234deb main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 1476602 T4972 oasc.ZkController.publish publishing core=awholynewcollection_0_shard1_replica2 state=down
[junit4:junit4] 2> ASYNC NEW_CORE C839 name=nodes_used_collection_shard2_replica1 org.apache.solr.core.SolrCore@678ef8c1 url=http://127.0.0.1:63266/smgeb/nodes_used_collection_shard2_replica1 node=127.0.0.1:63266_smgeb C839_STATE=coll:nodes_used_collection core:nodes_used_collection_shard2_replica1 props:{shard=shard2, state=active, core=nodes_used_collection_shard2_replica1, collection=nodes_used_collection, node_name=127.0.0.1:63266_smgeb, base_url=http://127.0.0.1:63266/smgeb, leader=true}
[junit4:junit4] 2> 1476597 T4947 C839 P63266 oasc.SolrCore.execute [nodes_used_collection_shard2_replica1] webapp=/smgeb path=/replication params={command=filelist&qt=/replication&wt=javabin&generation=2&version=2} status=0 QTime=75
[junit4:junit4] 2> 1476492 T4933 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> ASYNC NEW_CORE C840 name=nodes_used_collection_shard2_replica2 org.apache.solr.core.SolrCore@51bae1ad url=http://127.0.0.1:63275/smgeb/nodes_used_collection_shard2_replica2 node=127.0.0.1:63275_smgeb C840_STATE=coll:nodes_used_collection core:nodes_used_collection_shard2_replica2 props:{shard=shard2, state=recovering, core=nodes_used_collection_shard2_replica2, collection=nodes_used_collection, node_name=127.0.0.1:63275_smgeb, base_url=http://127.0.0.1:63275/smgeb}
[junit4:junit4] 2> 1476608 T4992 C840 P63275 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 1
[junit4:junit4] 2> 1476436 T4914 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 1476409 T4957 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 1476621 T4945 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 1476620 T4992 C840 P63275 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369431563307\nodes_used_collection_shard2_replica2\data\index.20130524213938639
[junit4:junit4] 2> 1476619 T4913 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 1476625 T4914 oass.SolrIndexSearcher.<init> Opening Searcher@45ac064e main
[junit4:junit4] 2> 1476625 T4992 C840 P63275 oash.SnapPuller.fetchLatestIndex Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory@752bc35c lockFactory=org.apache.lucene.store.NativeFSLockFactory@38a75e4c) fullCopy=false
[junit4:junit4] 2> 1476625 T4913 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 1476627 T4913 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 1476627 T4914 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369431557356\awholynewcollection_0_shard3_replica2\data\tlog
[junit4:junit4] 2> 1476627 T4913 oasc.SolrCore.<init> [awholynewcollection_0_shard1_replica1] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369431557356\awholynewcollection_0_shard1_replica1\, dataDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369431557356\awholynewcollection_0_shard1_replica1\data\
[junit4:junit4] 2> 1476627 T4913 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@5f20a14c
[junit4:junit4] 2> 1476628 T4913 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 1476629 T4914 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 1476630 T4914 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 1476632 T4944 C839 P63266 oasc.SolrCore.execute [nodes_used_collection_shard2_replica1] webapp=/smgeb path=/replication params={file=segments_2&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 1476644 T5010 oasc.SolrCore.registerSearcher [awholynewcollection_0_shard3_replica2] Registered new searcher Searcher@45ac064e main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 1476644 T4914 oasc.ZkController.publish publishing core=awholynewcollection_0_shard3_replica2 state=down
[junit4:junit4] 2> 1476647 T4992 C840 P63275 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4] 2> 1476639 T4913 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369431557356\awholynewcollection_0_shard1_replica1\data\
[junit4:junit4] 2> 1476633 T4933 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 1476653 T4933 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 1476639 T4945 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 1476660 T4945 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 1476664 T4913 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369431557356\awholynewcollection_0_shard1_replica1\data\index/
[junit4:junit4] 2> 1476665 T4913 oasc.SolrCore.initIndex WARN [awholynewcollection_0_shard1_replica1] Solr index directory 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369431557356\awholynewcollection_0_shard1_replica1\data\index' doesn't exist. Creating new index...
[junit4:junit4] 2> 1476665 T4913 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369431557356\awholynewcollection_0_shard1_replica1\data\index
[junit4:junit4] 2> 1476666 T4943 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 1476666 T4957 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 1476667 T4957 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 1476667 T4957 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 1476671 T4992 C840 P63275 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4] 2> 1476672 T4992 C840 P63275 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=nodes_used_collection_shard2_replica2
[junit4:junit4] 2> 1476676 T4992 C840 P63275 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@4620e2fa lockFactory=org.apache.lucene.store.NativeFSLockFactory@4013a9dd),segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@4620e2fa lockFactory=org.apache.lucene.store.NativeFSLockFactory@4013a9dd),segFN=segments_2,generation=2}
[junit4:junit4] 2> 1476677 T4943 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 1476678 T4992 C840 P63275 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 1476684 T4992 C840 P63275 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4] 2> 1476685 T4992 C840 P63275 oass.SolrIndexSearcher.<init> Opening Searcher@b597629 main
[junit4:junit4] 2> 1476678 T4973 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1b5872e lockFactory=org.apache.lucene.store.NativeFSLockFactory@4cdf1736),segFN=segments_1,generation=1}
[junit4:junit4] 2> 1476686 T4973 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 1476685 T4957 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 1476687 T4957 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 1476687 T4957 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 1476688 T4957 oasc.SolrCore.<init> [awholynewcollection_0_shard3_replica1] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369431563307\awholynewcollection_0_shard3_replica1\, dataDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369431563307\awholynewcollection_0_shard3_replica1\data\
[junit4:junit4] 2> 1476688 T4957 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@5f20a14c
[junit4:junit4] 2> 1476688 T4957 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 1476689 T4943 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 1476690 T4973 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 1476690 T4973 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 1476691 T4973 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 1476692 T4973 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 1476693 T4973 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 1476694 T4973 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 1476694 T4973 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 1476695 T4973 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 1476696 T4973 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 1476697 T4987 oasc.SolrCore.registerSearcher [nodes_used_collection_shard2_replica2] Registered new searcher Searcher@b597629 main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 1476699 T4992 C840 P63275 oasc.CachingDirectoryFactory.closeCacheValue looking to close C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369431563307\nodes_used_collection_shard2_replica2\data\index.20130524213938639 [CachedDir<<refCount=0;path=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369431563307\nodes_used_collection_shard2_replica2\data\index.20130524213938639;done=true>>]
[junit4:junit4] 2> 1476699 T4992 C840 P63275 oasc.CachingDirectoryFactory.close Closing directory: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369431563307\nodes_used_collection_shard2_replica2\data\index.20130524213938639
[junit4:junit4] 2> 1476699 T4992 C840 P63275 oasc.Cac
[...truncated too long message...]
unit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:84)
[junit4:junit4] 2> at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
[junit4:junit4] 2> at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:129)
[junit4:junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
[junit4:junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
[junit4:junit4] 2>
[junit4:junit4] 1> /solr/collections/awholynewcollection_1/leader_elect/shard1 (1)
[junit4:junit4] 1> /solr/collections/awholynewcollection_1/leader_elect/shard1/election (2)
[junit4:junit4] 1> /solr/collections/awholynewcollection_1/leader_elect/shard1/election/89747066526760970-127.0.0.1:63275_smgeb_awholynewcollection_1_shard1_replica1-n_0000000000 (0)
[junit4:junit4] 1> /solr/collections/awholynewcollection_1/leader_elect/shard1/election/89747066526760968-127.0.0.1:63266_smgeb_awholynewcollection_1_shard1_replica2-n_0000000001 (0)
[junit4:junit4] 1> /solr/collections/awholynewcollection_1/leader_elect/shard2 (1)
[junit4:junit4] 1> /solr/collections/awholynewcollection_1/leader_elect/shard2/election (2)
[junit4:junit4] 1> /solr/collections/awholynewcollection_1/leader_elect/shard2/election/89747066526760966-127.0.0.1:63257_smgeb_awholynewcollection_1_shard2_replica1-n_0000000001 (0)
[junit4:junit4] 1> /solr/collections/awholynewcollection_1/leader_elect/shard2/election/89747066526760963-127.0.0.1:63245_smgeb_awholynewcollection_1_shard2_replica2-n_0000000000 (0)
[junit4:junit4] 1> /solr/collections/awholynewcollection_1/leaders (2)
[junit4:junit4] 1> /solr/collections/awholynewcollection_1/leaders/shard1 (0)
[junit4:junit4] 1> DATA:
[junit4:junit4] 1> {
[junit4:junit4] 1> "core":"awholynewcollection_1_shard1_replica1",
[junit4:junit4] 1> "node_name":"127.0.0.1:63275_smgeb",
[junit4:junit4] 1> "base_url":"http://127.0.0.1:63275/smgeb"}
[junit4:junit4] 1> /solr/collections/awholynewcollection_1/leaders/shard2 (0)
[junit4:junit4] 1> DATA:
[junit4:junit4] 1> {
[junit4:junit4] 1> "core":"awholynewcollection_1_shard2_replica2",
[junit4:junit4] 1> "node_name":"127.0.0.1:63245_smgeb",
[junit4:junit4] 1> "base_url":"http://127.0.0.1:63245/smgeb"}
[junit4:junit4] 1> /solr/overseer_elect (2)
[junit4:junit4] 1> /solr/overseer_elect/election (5)
[junit4:junit4] 1> /solr/overseer_elect/election/89747066526760963-127.0.0.1:63245_smgeb-n_0000000000 (0)
[junit4:junit4] 1> /solr/overseer_elect/election/89747066526760972-127.0.0.1:63284_smgeb-n_0000000004 (0)
[junit4:junit4] 1> /solr/overseer_elect/election/89747066526760970-127.0.0.1:63275_smgeb-n_0000000003 (0)
[junit4:junit4] 1> /solr/overseer_elect/election/89747066526760968-127.0.0.1:63266_smgeb-n_0000000002 (0)
[junit4:junit4] 1> /solr/overseer_elect/election/89747066526760966-127.0.0.1:63257_smgeb-n_0000000001 (0)
[junit4:junit4] 1> /solr/overseer_elect/leader (0)
[junit4:junit4] 1> DATA:
[junit4:junit4] 1> {"id":"89747066526760963-127.0.0.1:63245_smgeb-n_0000000000"}
[junit4:junit4] 1> /zookeeper (1)
[junit4:junit4] 1> DATA:
[junit4:junit4] 1>
[junit4:junit4] 1>
[junit4:junit4] 2> NOTE: reproduce with: ant test -Dtestcase=CollectionsAPIDistributedZkTest -Dtests.method=testDistribSearch -Dtests.seed=38F1683D98ABC1F1 -Dtests.slow=true -Dtests.locale=sv -Dtests.timezone=Africa/Conakry -Dtests.file.encoding=US-ASCII
[junit4:junit4] FAILURE 311s | CollectionsAPIDistributedZkTest.testDistribSearch <<<
[junit4:junit4] > Throwable #1: java.lang.AssertionError: There are still nodes recoverying - waited for 230 seconds
[junit4:junit4] > at __randomizedtesting.SeedInfo.seed([38F1683D98ABC1F1:B917E625EFF4A1CD]:0)
[junit4:junit4] > at org.apache.solr.cloud.AbstractDistribZkTestBase.waitForRecoveriesToFinish(AbstractDistribZkTestBase.java:173)
[junit4:junit4] > at org.apache.solr.cloud.AbstractDistribZkTestBase.waitForRecoveriesToFinish(AbstractDistribZkTestBase.java:131)
[junit4:junit4] > at org.apache.solr.cloud.AbstractDistribZkTestBase.waitForRecoveriesToFinish(AbstractDistribZkTestBase.java:126)
[junit4:junit4] > at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testCollectionsAPI(CollectionsAPIDistributedZkTest.java:512)
[junit4:junit4] > at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.doTest(CollectionsAPIDistributedZkTest.java:146)
[junit4:junit4] > at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:815)
[junit4:junit4] > at java.lang.Thread.run(Thread.java:722)
[junit4:junit4] 2> 1765648 T4898 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4:junit4] 2> NOTE: test params are: codec=CheapBastard, sim=DefaultSimilarity, locale=sv, timezone=Africa/Conakry
[junit4:junit4] 2> NOTE: Windows 7 6.1 amd64/Oracle Corporation 1.7.0_21 (64-bit)/cpus=2,threads=1,free=192578320,total=344588288
[junit4:junit4] 2> NOTE: All tests run in this JVM: [TestMergePolicyConfig, IndexSchemaTest, RegexBoostProcessorTest, DisMaxRequestHandlerTest, CircularListTest, TestComponentsName, URLClassifyProcessorTest, SimpleFacetsTest, SpellCheckCollatorTest, TestClassNameShortening, TestPhraseSuggestions, SolrRequestParserTest, SolrIndexSplitterTest, ScriptEngineTest, UUIDFieldTest, FieldAnalysisRequestHandlerTest, TestFastOutputStream, MinimalSchemaTest, RAMDirectoryFactoryTest, HighlighterTest, SuggesterTest, SolrCoreTest, SyncSliceTest, TestDocSet, TestHashPartitioner, DOMUtilTest, TestCloudManagedSchemaAddField, SolrCmdDistributorTest, TestMaxScoreQueryParser, TestIndexSearcher, TestFastWriter, ResourceLoaderTest, SolrIndexConfigTest, ChaosMonkeyShardSplitTest, TestReversedWildcardFilterFactory, LoggingHandlerTest, LegacyHTMLStripCharFilterTest, LukeRequestHandlerTest, IndexSchemaRuntimeFieldTest, DistributedQueryElevationComponentTest, TestPostingsSolrHighlighter, TestBinaryResponseWriter, TestRTGBase, OverseerTest, ZkCLITest, CoreAdminHandlerTest, TestStressLucene, StatelessScriptUpdateProcessorFactoryTest, TestPerFieldSimilarity, TestStressReorder, EchoParamsTest, TestDFRSimilarityFactory, TestAnalyzedSuggestions, TestSchemaNameResource, ExternalFileFieldSortTest, ShowFileRequestHandlerTest, TestShardHandlerFactory, TestLMJelinekMercerSimilarityFactory, JSONWriterTest, TestSchemaResource, TestFoldingMultitermQuery, QueryParsingTest, TestDistributedSearch, TestDynamicFieldCollectionResource, TestFieldCollectionResource, TestPHPSerializedResponseWriter, TestSolrQueryParser, TestSolrJ, ZkSolrClientTest, TestDocumentBuilder, DistanceFunctionTest, SliceStateUpdateTest, TestRandomDVFaceting, TestSchemaVersionResource, TestReplicationHandler, IndexReaderFactoryTest, PolyFieldTest, ChaosMonkeyNothingIsSafeTest, ChaosMonkeySafeLeaderTest, FileBasedSpellCheckerTest, SpellCheckComponentTest, SynonymTokenizerTest, DistributedTermsComponentTest, TestFiltering, UniqFieldsUpdateProcessorFactoryTest, TestSchemaSimilarityResource, AliasIntegrationTest, FieldMutatingUpdateProcessorTest, HardAutoCommitTest, TestIndexingPerformance, TestQueryUtils, TestSolrDeletionPolicy2, ShardRoutingTest, TestBadConfig, TestDynamicFieldResource, RequestHandlersTest, OverseerCollectionProcessorTest, TestQueryTypes, TermVectorComponentDistributedTest, PathHierarchyTokenizerFactoryTest, TestStressRecovery, TestSolrDeletionPolicy1, FileUtilsTest, TestIBSimilarityFactory, ZkControllerTest, TestCloudManagedSchema, SortByFunctionTest, TestDistributedGrouping, DirectSolrSpellCheckerTest, SpellPossibilityIteratorTest, QueryEqualityTest, ReturnFieldsTest, BadIndexSchemaTest, TestSolrIndexConfig, SpatialFilterTest, TestLRUCache, TestPropInjectDefaults, UnloadDistributedZkTest, TestSystemIdResolver, SchemaVersionSpecificBehaviorTest, TimeZoneUtilsTest, FastVectorHighlighterTest, TestReload, PingRequestHandlerTest, SliceStateTest, UpdateParamsTest, TestDefaultSimilarityFactory, TestRealTimeGet, DocumentAnalysisRequestHandlerTest, TestSolrQueryParserResource, TestFastLRUCache, SuggesterFSTTest, TestDefaultSearchFieldResource, TestConfig, NoCacheHeaderTest, TestRangeQuery, BasicDistributedZk2Test, SimplePostToolTest, TestWriterPerf, QueryResultKeyTest, CacheHeaderTest, ZkNodePropsTest, TestJmxIntegration, BasicDistributedZkTest, CollectionsAPIDistributedZkTest]
[junit4:junit4] Completed in 310.64s, 1 test, 1 failure <<< FAILURES!
[...truncated 461 lines...]
BUILD FAILED
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\build.xml:380: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\build.xml:360: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\build.xml:39: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build.xml:181: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\common-build.xml:437: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\common-build.xml:1240: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\common-build.xml:884: There were test failures: 295 suites, 1231 tests, 1 failure, 18 ignored (12 assumptions)
Total time: 67 minutes 40 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 64bit/jdk1.7.0_21 -XX:+UseCompressedOops -XX:+UseParallelGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure