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 2015/04/24 21:00:26 UTC

[JENKINS] Lucene-Solr-trunk-Windows (32bit/jdk1.8.0_40) - Build # 4723 - Failure!

Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Windows/4723/
Java: 32bit/jdk1.8.0_40 -server -XX:+UseSerialGC

1 tests failed.
FAILED:  org.apache.solr.client.solrj.impl.CloudSolrClientTest.test

Error Message:
There should be 3 documents because there should be two id=1 docs due to overwrite=false expected:<3> but was:<1>

Stack Trace:
java.lang.AssertionError: There should be 3 documents because there should be two id=1 docs due to overwrite=false expected:<3> but was:<1>
	at __randomizedtesting.SeedInfo.seed([B991998ABE83A57F:31C5A650107FC887]:0)
	at org.junit.Assert.fail(Assert.java:93)
	at org.junit.Assert.failNotEquals(Assert.java:647)
	at org.junit.Assert.assertEquals(Assert.java:128)
	at org.junit.Assert.assertEquals(Assert.java:472)
	at org.apache.solr.client.solrj.impl.CloudSolrClientTest.testOverwriteOption(CloudSolrClientTest.java:171)
	at org.apache.solr.client.solrj.impl.CloudSolrClientTest.test(CloudSolrClientTest.java:129)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:497)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1627)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:836)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:872)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:886)
	at org.junit.rules.ExpectedException$ExpectedExceptionStatement.evaluate(ExpectedException.java:110)
	at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsFixedStatement.callStatement(BaseDistributedSearchTestCase.java:960)
	at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsStatement.evaluate(BaseDistributedSearchTestCase.java:935)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
	at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
	at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:798)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:458)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:845)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:747)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:781)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:792)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:54)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
	at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365)
	at java.lang.Thread.run(Thread.java:745)




Build Log:
[...truncated 11383 lines...]
   [junit4] Suite: org.apache.solr.client.solrj.impl.CloudSolrClientTest
   [junit4]   2> Creating dataDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\temp\solr.client.solrj.impl.CloudSolrClientTest B991998ABE83A57F-001\init-core-data-001
   [junit4]   2> 79859 T412 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (false) and clientAuth (true)
   [junit4]   2> 79859 T412 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
   [junit4]   2> 79863 T412 oasc.AbstractZkTestCase.<clinit> WARN TEST_HOME() does not exist - solrj test?
   [junit4]   2> 79874 T412 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   2> 79876 T413 oasc.ZkTestServer$2$1.setClientPort client port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 79876 T413 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 79991 T412 oasc.ZkTestServer.run start zk server on port:53770
   [junit4]   2> 79991 T412 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider
   [junit4]   2> 79993 T412 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 80001 T420 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@15a422a name:ZooKeeperConnection Watcher:127.0.0.1:53770 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 80001 T412 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 80002 T412 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider
   [junit4]   2> 80002 T412 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 80009 T412 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider
   [junit4]   2> 80011 T412 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 80014 T423 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@deb71b name:ZooKeeperConnection Watcher:127.0.0.1:53770/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 80015 T412 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 80017 T412 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider
   [junit4]   2> 80017 T412 oascc.SolrZkClient.makePath makePath: /collections/collection1
   [junit4]   2> 80023 T412 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
   [junit4]   2> 80029 T412 oascc.SolrZkClient.makePath makePath: /collections/control_collection
   [junit4]   2> 80032 T412 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
   [junit4]   2> 80040 T412 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\solrj\src\test-files\solrj\solr\collection1\conf\solrconfig.xml to /configs/conf1/solrconfig.xml
   [junit4]   2> 80041 T412 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
   [junit4]   2> 80048 T412 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\solrj\src\test-files\solrj\solr\collection1\conf\schema.xml to /configs/conf1/schema.xml
   [junit4]   2> 80049 T412 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
   [junit4]   2> 80053 T412 oasc.AbstractZkTestCase.putConfig skipping C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\solrj\src\test-files\solrj\solr\collection1\conf\solrconfig.snippet.randomindexconfig.xml because it doesn't exist
   [junit4]   2> 80054 T412 oasc.AbstractZkTestCase.putConfig skipping C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\solrj\src\test-files\solrj\solr\collection1\conf\stopwords.txt because it doesn't exist
   [junit4]   2> 80054 T412 oasc.AbstractZkTestCase.putConfig skipping C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\solrj\src\test-files\solrj\solr\collection1\conf\protwords.txt because it doesn't exist
   [junit4]   2> 80054 T412 oasc.AbstractZkTestCase.putConfig skipping C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\solrj\src\test-files\solrj\solr\collection1\conf\currency.xml because it doesn't exist
   [junit4]   2> 80054 T412 oasc.AbstractZkTestCase.putConfig skipping C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\solrj\src\test-files\solrj\solr\collection1\conf\enumsConfig.xml because it doesn't exist
   [junit4]   2> 80056 T412 oasc.AbstractZkTestCase.putConfig skipping C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\solrj\src\test-files\solrj\solr\collection1\conf\open-exchange-rates.json because it doesn't exist
   [junit4]   2> 80056 T412 oasc.AbstractZkTestCase.putConfig skipping C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\solrj\src\test-files\solrj\solr\collection1\conf\mapping-ISOLatin1Accent.txt because it doesn't exist
   [junit4]   2> 80057 T412 oasc.AbstractZkTestCase.putConfig skipping C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\solrj\src\test-files\solrj\solr\collection1\conf\old_synonyms.txt because it doesn't exist
   [junit4]   2> 80057 T412 oasc.AbstractZkTestCase.putConfig skipping C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\solrj\src\test-files\solrj\solr\collection1\conf\synonyms.txt because it doesn't exist
   [junit4]   2> 80140 T412 oas.SolrTestCaseJ4.writeCoreProperties Writing core.properties file to C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\temp\solr.client.solrj.impl.CloudSolrClientTest B991998ABE83A57F-001\control-001\cores\collection1
   [junit4]   2> 80146 T412 oejs.Server.doStart jetty-9.2.10.v20150310
   [junit4]   2> 80151 T412 oejsh.ContextHandler.doStart Started o.e.j.s.ServletContextHandler@473f3d{/,null,AVAILABLE}
   [junit4]   2> 80162 T412 oejs.AbstractConnector.doStart Started ServerConnector@7fe054{HTTP/1.1}{127.0.0.1:53777}
   [junit4]   2> 80163 T412 oejs.Server.doStart Started @94547ms
   [junit4]   2> 80163 T412 oascse.JettySolrRunner$1.lifeCycleStarted Jetty properties: {solr.data.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\temp\solr.client.solrj.impl.CloudSolrClientTest B991998ABE83A57F-001\tempDir-001/control/data, hostContext=/, hostPort=53777, coreRootDirectory=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\temp\solr.client.solrj.impl.CloudSolrClientTest B991998ABE83A57F-001\control-001\cores}
   [junit4]   2> 80164 T412 oass.SolrDispatchFilter.init SolrDispatchFilter.init()sun.misc.Launcher$AppClassLoader@19e0bfd
   [junit4]   2> 80164 T412 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\temp\solr.client.solrj.impl.CloudSolrClientTest B991998ABE83A57F-001\control-001\'
   [junit4]   2> 80189 T412 oasc.SolrXmlConfig.fromFile Loading container configuration from C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\temp\solr.client.solrj.impl.CloudSolrClientTest B991998ABE83A57F-001\control-001\solr.xml
   [junit4]   2> 80199 T412 oasc.CorePropertiesLocator.<init> Config-defined core root directory: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\temp\solr.client.solrj.impl.CloudSolrClientTest B991998ABE83A57F-001\control-001\cores
   [junit4]   2> 80199 T412 oasc.CoreContainer.<init> New CoreContainer 31717897
   [junit4]   2> 80199 T412 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\temp\solr.client.solrj.impl.CloudSolrClientTest B991998ABE83A57F-001\control-001\]
   [junit4]   2> 80200 T412 oasc.CoreContainer.load loading shared library: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\temp\solr.client.solrj.impl.CloudSolrClientTest B991998ABE83A57F-001\control-001\lib
   [junit4]   2> 80200 T412 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: lib (resolved as: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\temp\solr.client.solrj.impl.CloudSolrClientTest B991998ABE83A57F-001\control-001\lib).
   [junit4]   2> 80208 T412 oashc.HttpShardHandlerFactory.init created with socketTimeout : 90000,urlScheme : ,connTimeout : 15000,maxConnectionsPerHost : 20,maxConnections : 10000,corePoolSize : 0,maximumPoolSize : 2147483647,maxThreadIdleTime : 5,sizeOfQueue : -1,fairnessPolicy : false,useRetries : false,
   [junit4]   2> 80211 T412 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
   [junit4]   2> 80212 T412 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 80212 T412 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 80212 T412 oasc.CoreContainer.load Node Name: 127.0.0.1
   [junit4]   2> 80212 T412 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:53770/solr
   [junit4]   2> 80212 T412 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 80212 T412 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider
   [junit4]   2> 80215 T412 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 80218 T437 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@119e33e name:ZooKeeperConnection Watcher:127.0.0.1:53770 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 80218 T412 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 80219 T412 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider
   [junit4]   2> 80223 T412 N:127.0.0.1:53777_ oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 80228 T440 N:127.0.0.1:53777_ oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@9c164 name:ZooKeeperConnection Watcher:127.0.0.1:53770/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 80229 T412 N:127.0.0.1:53777_ oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 80231 T412 N:127.0.0.1:53777_ oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 80236 T412 N:127.0.0.1:53777_ oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 80245 T412 N:127.0.0.1:53777_ oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
   [junit4]   2> 80258 T412 N:127.0.0.1:53777_ oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
   [junit4]   2> 80262 T412 N:127.0.0.1:53777_ oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
   [junit4]   2> 80266 T412 N:127.0.0.1:53777_ oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 80269 T412 N:127.0.0.1:53777_ oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 80271 T412 N:127.0.0.1:53777_ oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 80273 T412 N:127.0.0.1:53777_ oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:53777_
   [junit4]   2> 80275 T412 N:127.0.0.1:53777_ oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:53777_
   [junit4]   2> 80278 T412 N:127.0.0.1:53777_ oascc.SolrZkClient.makePath makePath: /overseer_elect
   [junit4]   2> 80279 T412 N:127.0.0.1:53777_ oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 80281 T412 N:127.0.0.1:53777_ oasc.Overseer.close Overseer (id=null) closing
   [junit4]   2> 80283 T412 N:127.0.0.1:53777_ oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:53777_
   [junit4]   2> 80283 T412 N:127.0.0.1:53777_ oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 80286 T412 N:127.0.0.1:53777_ oasc.Overseer.start Overseer (id=93710052573904899-127.0.0.1:53777_-n_0000000000) starting
   [junit4]   2> 80288 T412 N:127.0.0.1:53777_ oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 80296 T412 N:127.0.0.1:53777_ oasc.OverseerAutoReplicaFailoverThread.<init> Starting OverseerAutoReplicaFailoverThread autoReplicaFailoverWorkLoopDelay=10000 autoReplicaFailoverWaitAfterExpiration=30000 autoReplicaFailoverBadNodeExpiration=60000
   [junit4]   2> 80299 T412 N:127.0.0.1:53777_ oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 80299 T442 N:127.0.0.1:53777_ oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 80302 T441 N:127.0.0.1:53777_ oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 80310 T412 N:127.0.0.1:53777_ oasc.CorePropertiesLocator.discover Looking for core definitions underneath C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\temp\solr.client.solrj.impl.CloudSolrClientTest B991998ABE83A57F-001\control-001\cores
   [junit4]   2> 80320 T412 N:127.0.0.1:53777_ oasc.CoreDescriptor.<init> CORE DESCRIPTOR: {name=collection1, config=solrconfig.xml, transient=false, schema=schema.xml, loadOnStartup=true, instanceDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\temp\solr.client.solrj.impl.CloudSolrClientTest B991998ABE83A57F-001\control-001\cores\collection1, collection=control_collection, absoluteInstDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\temp\solr.client.solrj.impl.CloudSolrClientTest B991998ABE83A57F-001\control-001\cores\collection1\, coreNodeName=, dataDir=data\, shard=}
   [junit4]   2> 80321 T412 N:127.0.0.1:53777_ oasc.CorePropertiesLocator.discoverUnder Found core collection1 in C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\temp\solr.client.solrj.impl.CloudSolrClientTest B991998ABE83A57F-001\control-001\cores\collection1\
   [junit4]   2> 80321 T412 N:127.0.0.1:53777_ oasc.CorePropertiesLocator.discover Found 1 core definitions
   [junit4]   2> 80324 T444 N:127.0.0.1:53777_ C:control_collection c:collection1 oasc.ZkController.publish publishing core=collection1 state=down collection=control_collection
   [junit4]   2> 80324 T444 N:127.0.0.1:53777_ C:control_collection c:collection1 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 80329 T444 N:127.0.0.1:53777_ oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 80329 T440 N:127.0.0.1:53777_ oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected
   [junit4]   2> 80334 T441 N:127.0.0.1:53777_ oasc.Overseer$ClusterStateUpdater.run processMessage: queueSize: 1, message = {
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "base_url":"http://127.0.0.1:53777",
   [junit4]   2> 	  "node_name":"127.0.0.1:53777_",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"control_collection",
   [junit4]   2> 	  "operation":"state"} current state version: 0
   [junit4]   2> 80354 T441 N:127.0.0.1:53777_ oasco.ReplicaMutator.updateState Update state numShards=1 message={
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "base_url":"http://127.0.0.1:53777",
   [junit4]   2> 	  "node_name":"127.0.0.1:53777_",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"control_collection",
   [junit4]   2> 	  "operation":"state"}
   [junit4]   2> 80358 T441 N:127.0.0.1:53777_ oasco.ClusterStateMutator.createCollection building a new cName: control_collection
   [junit4]   2> 80379 T441 N:127.0.0.1:53777_ oasco.ReplicaMutator.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 80389 T440 N:127.0.0.1:53777_ oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
   [junit4]   2> 81561 T444 N:127.0.0.1:53777_ oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 81561 T444 N:127.0.0.1:53777_ oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
   [junit4]   2> 81562 T444 N:127.0.0.1:53777_ oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 81562 T444 N:127.0.0.1:53777_ oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
   [junit4]   2> 81564 T444 N:127.0.0.1:53777_ oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 81564 T444 N:127.0.0.1:53777_ oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\temp\solr.client.solrj.impl.CloudSolrClientTest B991998ABE83A57F-001\control-001\cores\collection1\'
   [junit4]   2> 81615 T444 N:127.0.0.1:53777_ oasc.Config.<init> loaded config solrconfig.xml with version 0 
   [junit4]   2> 81627 T444 N:127.0.0.1:53777_ oasc.SolrConfig.refreshRequestParams current version of requestparams : -1
   [junit4]   2> 81630 T444 N:127.0.0.1:53777_ oasc.SolrConfig.<init> Using Lucene MatchVersion: 6.0.0
   [junit4]   2> 81645 T444 N:127.0.0.1:53777_ oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 81648 T444 N:127.0.0.1:53777_ oass.IndexSchema.readSchema Reading Solr Schema from /configs/conf1/schema.xml
   [junit4]   2> 81656 T444 N:127.0.0.1:53777_ oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 81848 T444 N:127.0.0.1:53777_ oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 81849 T444 N:127.0.0.1:53777_ oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 81851 T444 N:127.0.0.1:53777_ oass.IndexSchema.loadCopyFields WARN Field lowerfilt1and2 is not multivalued and destination for multiple copyFields (2)
   [junit4]   2> 81851 T444 N:127.0.0.1:53777_ oass.IndexSchema.loadCopyFields WARN Field text is not multivalued and destination for multiple copyFields (3)
   [junit4]   2> 81859 T444 N:127.0.0.1:53777_ oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection control_collection
   [junit4]   2> 81859 T444 N:127.0.0.1:53777_ c:collection1 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 81859 T444 N:127.0.0.1:53777_ c:collection1 oasc.SolrCore.<init> [[collection1] ] Opening new SolrCore at [C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\temp\solr.client.solrj.impl.CloudSolrClientTest B991998ABE83A57F-001\control-001\cores\collection1\], dataDir=[null]
   [junit4]   2> 81859 T444 N:127.0.0.1:53777_ c:collection1 oasc.SolrCore.initInfoRegistry JMX monitoring not detected for core: collection1
   [junit4]   2> 81860 T444 N:127.0.0.1:53777_ c:collection1 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\temp\solr.client.solrj.impl.CloudSolrClientTest B991998ABE83A57F-001\control-001\cores\collection1\data\
   [junit4]   2> 81860 T444 N:127.0.0.1:53777_ c:collection1 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\temp\solr.client.solrj.impl.CloudSolrClientTest B991998ABE83A57F-001\control-001\cores\collection1\data\index/
   [junit4]   2> 81860 T444 N:127.0.0.1:53777_ c:collection1 oasc.SolrCore.initIndex WARN [collection1] Solr index directory 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\temp\solr.client.solrj.impl.CloudSolrClientTest B991998ABE83A57F-001\control-001\cores\collection1\data\index' doesn't exist. Creating new index...
   [junit4]   2> 81862 T444 N:127.0.0.1:53777_ c:collection1 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\temp\solr.client.solrj.impl.CloudSolrClientTest B991998ABE83A57F-001\control-001\cores\collection1\data\index
   [junit4]   2> 81862 T444 N:127.0.0.1:53777_ c:collection1 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@1df80d1 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2a9272),segFN=segments_1,generation=1}
   [junit4]   2> 81862 T444 N:127.0.0.1:53777_ c:collection1 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 81864 T444 N:127.0.0.1:53777_ c:collection1 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 81869 T444 N:127.0.0.1:53777_ c:collection1 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 81870 T444 N:127.0.0.1:53777_ c:collection1 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 81873 T444 N:127.0.0.1:53777_ c:collection1 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 81873 T444 N:127.0.0.1:53777_ c:collection1 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 81874 T444 N:127.0.0.1:53777_ c:collection1 oasc.PluginBag.createPlugin requestHandler : '/replication' created with startup=lazy 
   [junit4]   2> 81904 T444 N:127.0.0.1:53777_ c:collection1 oasc.SolrResourceLoader.findClass WARN Solr loaded a deprecated plugin/analysis class [org.apache.solr.handler.admin.AdminHandlers]. Please consult documentation how to replace it accordingly.
   [junit4]   2> 81904 T444 N:127.0.0.1:53777_ c:collection1 oasc.SolrResourceLoader.findClass WARN Solr loaded a deprecated plugin/analysis class [org.apache.solr.handler.admin.AdminHandlers]. Please consult documentation how to replace it accordingly.
   [junit4]   2> 81906 T444 N:127.0.0.1:53777_ c:collection1 oasc.RequestHandlers.initHandlersFromConfig Registered paths: /admin/mbeans,standard,,/update/csv,/update/json/docs,/admin/luke,/admin/segments,/get,/admin/system,/replication,/admin/properties,/config,/schema,/admin/plugins,/admin/logging,/update/json,/admin,/admin/threads,/admin/ping,/update,/admin/file
   [junit4]   2> 81906 T444 N:127.0.0.1:53777_ c:collection1 oasc.RequestHandlers.initHandlersFromConfig WARN no default request handler is registered (either '/select' or 'standard')
   [junit4]   2> 81906 T444 N:127.0.0.1:53777_ c:collection1 oasc.SolrCore.initStatsCache Using default statsCache cache: org.apache.solr.search.stats.LocalStatsCache
   [junit4]   2> 81908 T444 N:127.0.0.1:53777_ c:collection1 oasu.UpdateHandler.<init> Using UpdateLog implementation: org.apache.solr.update.UpdateLog
   [junit4]   2> 81908 T444 N:127.0.0.1:53777_ c:collection1 oasu.UpdateLog.init Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10
   [junit4]   2> 81909 T444 N:127.0.0.1:53777_ c:collection1 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 81909 T444 N:127.0.0.1:53777_ c:collection1 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 81911 T444 N:127.0.0.1:53777_ c:collection1 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@1df80d1 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2a9272),segFN=segments_1,generation=1}
   [junit4]   2> 81911 T444 N:127.0.0.1:53777_ c:collection1 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 81912 T444 N:127.0.0.1:53777_ c:collection1 oass.SolrIndexSearcher.<init> Opening Searcher@2759f6[collection1] main
   [junit4]   2> 81912 T444 N:127.0.0.1:53777_ c:collection1 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
   [junit4]   2> 81914 T444 N:127.0.0.1:53777_ c:collection1 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 81914 T444 N:127.0.0.1:53777_ c:collection1 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
   [junit4]   2> 81923 T444 N:127.0.0.1:53777_ c:collection1 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
   [junit4]   2> 81923 T444 N:127.0.0.1:53777_ c:collection1 oasr.RestManager.init Initializing RestManager with initArgs: {}
   [junit4]   2> 81923 T444 N:127.0.0.1:53777_ c:collection1 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 81924 T444 N:127.0.0.1:53777_ c:collection1 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
   [junit4]   2> 81924 T444 N:127.0.0.1:53777_ c:collection1 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 81924 T444 N:127.0.0.1:53777_ c:collection1 oasr.RestManager.init Initializing 0 registered ManagedResources
   [junit4]   2> 81926 T444 N:127.0.0.1:53777_ c:collection1 oasha.AdminHandlers.inform WARN <requestHandler name="/admin/" 
   [junit4]   2> 	 class="solr.admin.AdminHandlers" /> is deprecated . It is not required anymore
   [junit4]   2> 81926 T445 N:127.0.0.1:53777_ c:collection1 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@2759f6[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 81931 T444 N:127.0.0.1:53777_ c:collection1 oasc.ZkController.getConfDirListeners watch zkdir /configs/conf1
   [junit4]   2> 81935 T444 N:127.0.0.1:53777_ c:collection1 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 81936 T448 N:127.0.0.1:53777_ C:control_collection S:shard1 c:collection1 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:53777 collection:control_collection shard:shard1
   [junit4]   2> 81937 T412 N:127.0.0.1:53777_ oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0
   [junit4]   2> 81937 T412 N:127.0.0.1:53777_ oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 81942 T412 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider
   [junit4]   2> 81944 T412 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 81956 T451 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2b1651 name:ZooKeeperConnection Watcher:127.0.0.1:53770/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 81957 T412 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 81957 T412 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider
   [junit4]   2> 81957 T412 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 81963 T448 N:127.0.0.1:53777_ C:control_collection S:shard1 c:collection1 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
   [junit4]   2> 81974 T448 N:127.0.0.1:53777_ C:control_collection S:shard1 c:collection1 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 81975 T412 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:false
   [junit4]   2> 81975 T412 oasc.AbstractFullDistribZkTestBase.createJettys Creating collection1 with stateFormat=2
   [junit4]   2> 81975 T412 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider
   [junit4]   2> 81978 T412 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 81983 T448 N:127.0.0.1:53777_ C:control_collection S:shard1 c:collection1 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 81983 T448 N:127.0.0.1:53777_ C:control_collection S:shard1 c:collection1 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> ASYNC  NEW_CORE C99 name=collection1 org.apache.solr.core.SolrCore@1eae662 url=http://127.0.0.1:53777/collection1 node=127.0.0.1:53777_ C99_STATE=coll:control_collection core:collection1 props:{core=collection1, base_url=http://127.0.0.1:53777, node_name=127.0.0.1:53777_, state=down}
   [junit4]   2> 81986 T448 N:127.0.0.1:53777_ C:control_collection S:shard1 c:collection1 C99 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:53777/collection1/
   [junit4]   2> 81988 T448 N:127.0.0.1:53777_ C:control_collection S:shard1 c:collection1 C99 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 81988 T448 N:127.0.0.1:53777_ C:control_collection S:shard1 c:collection1 C99 oasc.SyncStrategy.syncToMe http://127.0.0.1:53777/collection1/ has no replicas
   [junit4]   2> 81986 T440 N:127.0.0.1:53777_ oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected
   [junit4]   2> 81988 T448 N:127.0.0.1:53777_ C:control_collection S:shard1 c:collection1 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:53777/collection1/ shard1
   [junit4]   2> 81994 T448 N:127.0.0.1:53777_ C:control_collection S:shard1 c:collection1 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
   [junit4]   2> 82007 T454 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1e9ddc5 name:ZooKeeperConnection Watcher:127.0.0.1:53770/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 82007 T412 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 82008 T412 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider
   [junit4]   2> 82013 T441 N:127.0.0.1:53777_ oasc.Overseer$ClusterStateUpdater.run processMessage: queueSize: 1, message = {
   [junit4]   2> 	  "operation":"leader",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "collection":"control_collection"} current state version: 1
   [junit4]   2> 82049 T441 N:127.0.0.1:53777_ oasc.Overseer$ClusterStateUpdater.run processMessage: queueSize: 2, message = {
   [junit4]   2> 	  "operation":"create",
   [junit4]   2> 	  "name":"collection1",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "stateFormat":"2"} current state version: 1
   [junit4]   2> 82049 T441 N:127.0.0.1:53777_ oasco.ClusterStateMutator.createCollection building a new cName: collection1
   [junit4]   2> 82052 T451 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
   [junit4]   2> 82057 T440 N:127.0.0.1:53777_ oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
   [junit4]   2> 82068 T440 N:127.0.0.1:53777_ oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected
   [junit4]   2> 82070 T441 N:127.0.0.1:53777_ oasc.Overseer$ClusterStateUpdater.run processMessage: queueSize: 2, message = {
   [junit4]   2> 	  "operation":"leader",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "collection":"control_collection",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:53777",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "state":"active"} current state version: 2
   [junit4]   2> 82072 T441 N:127.0.0.1:53777_ oasco.ZkStateWriter.writePendingUpdates going to create_collection /collections/collection1/state.json
   [junit4]   2> 82077 T451 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
   [junit4]   2> 82081 T440 N:127.0.0.1:53777_ oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
   [junit4]   2> 82111 T412 oas.SolrTestCaseJ4.writeCoreProperties Writing core.properties file to C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\temp\solr.client.solrj.impl.CloudSolrClientTest B991998ABE83A57F-001\shard-1-001\cores\collection1
   [junit4]   2> 82114 T412 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 1 in directory C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\temp\solr.client.solrj.impl.CloudSolrClientTest B991998ABE83A57F-001\shard-1-001
   [junit4]   2> 82116 T412 oejs.Server.doStart jetty-9.2.10.v20150310
   [junit4]   2> 82122 T412 oejsh.ContextHandler.doStart Started o.e.j.s.ServletContextHandler@c5c1f2{/,null,AVAILABLE}
   [junit4]   2> 82126 T412 oejs.AbstractConnector.doStart Started ServerConnector@15bb833{HTTP/1.1}{127.0.0.1:53792}
   [junit4]   2> 82126 T412 oejs.Server.doStart Started @96159ms
   [junit4]   2> 82126 T412 oascse.JettySolrRunner$1.lifeCycleStarted Jetty properties: {solr.data.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\temp\solr.client.solrj.impl.CloudSolrClientTest B991998ABE83A57F-001\tempDir-001/jetty1, solrconfig=solrconfig.xml, hostContext=/, hostPort=53792, coreRootDirectory=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\temp\solr.client.solrj.impl.CloudSolrClientTest B991998ABE83A57F-001\shard-1-001\cores}
   [junit4]   2> 82127 T412 oass.SolrDispatchFilter.init SolrDispatchFilter.init()sun.misc.Launcher$AppClassLoader@19e0bfd
   [junit4]   2> 82127 T412 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\temp\solr.client.solrj.impl.CloudSolrClientTest B991998ABE83A57F-001\shard-1-001\'
   [junit4]   2> 82165 T412 oasc.SolrXmlConfig.fromFile Loading container configuration from C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\temp\solr.client.solrj.impl.CloudSolrClientTest B991998ABE83A57F-001\shard-1-001\solr.xml
   [junit4]   2> 82178 T412 oasc.CorePropertiesLocator.<init> Config-defined core root directory: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\temp\solr.client.solrj.impl.CloudSolrClientTest B991998ABE83A57F-001\shard-1-001\cores
   [junit4]   2> 82180 T412 oasc.CoreContainer.<init> New CoreContainer 31475457
   [junit4]   2> 82180 T412 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\temp\solr.client.solrj.impl.CloudSolrClientTest B991998ABE83A57F-001\shard-1-001\]
   [junit4]   2> 82180 T412 oasc.CoreContainer.load loading shared library: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\temp\solr.client.solrj.impl.CloudSolrClientTest B991998ABE83A57F-001\shard-1-001\lib
   [junit4]   2> 82181 T412 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: lib (resolved as: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\temp\solr.client.solrj.impl.CloudSolrClientTest B991998ABE83A57F-001\shard-1-001\lib).
   [junit4]   2> 82192 T412 oashc.HttpShardHandlerFactory.init created with socketTimeout : 90000,urlScheme : ,connTimeout : 15000,maxConnectionsPerHost : 20,maxConnections : 10000,corePoolSize : 0,maximumPoolSize : 2147483647,maxThreadIdleTime : 5,sizeOfQueue : -1,fairnessPolicy : false,useRetries : false,
   [junit4]   2> 82194 T412 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
   [junit4]   2> 82196 T412 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 82197 T412 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 82197 T412 oasc.CoreContainer.load Node Name: 127.0.0.1
   [junit4]   2> 82197 T412 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:53770/solr
   [junit4]   2> 82197 T412 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 82198 T412 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider
   [junit4]   2> 82199 T412 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 82204 T471 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@12a0dcd name:ZooKeeperConnection Watcher:127.0.0.1:53770 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 82204 T412 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 82204 T412 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider
   [junit4]   2> 82210 T414 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x14ceccbdb8d0006, likely client has closed socket
   [junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
   [junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
   [junit4]   2> 	at java.lang.Thread.run(Thread.java:745)
   [junit4]   2> 
   [junit4]   2> 82213 T412 N:127.0.0.1:53792_ oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 82220 T474 N:127.0.0.1:53792_ oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1e59a72 name:ZooKeeperConnection Watcher:127.0.0.1:53770/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 82221 T412 N:127.0.0.1:53792_ oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 82231 T451 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
   [junit4]   2> 82232 T440 N:127.0.0.1:53777_ oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
   [junit4]   2> 82242 T412 N:127.0.0.1:53792_ oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 82306 T448 N:127.0.0.1:53777_ C:control_collection S:shard1 c:collection1 oasc.ZkController.register We are http://127.0.0.1:53777/collection1/ and leader is http://127.0.0.1:53777/collection1/
   [junit4]   2> 82306 T448 N:127.0.0.1:53777_ C:control_collection S:shard1 c:collection1 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:53777
   [junit4]   2> 82306 T448 N:127.0.0.1:53777_ C:control_collection S:shard1 c:collection1 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 82306 T448 N:127.0.0.1:53777_ C:control_collection S:shard1 c:collection1 oasc.ZkController.publish publishing core=collection1 state=active collection=control_collection
   [junit4]   2> 82306 T448 N:127.0.0.1:53777_ C:control_collection S:shard1 c:collection1 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 82308 T440 N:127.0.0.1:53777_ oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected
   [junit4]   2> 82309 T441 N:127.0.0.1:53777_ oasc.Overseer$ClusterStateUpdater.run processMessage: queueSize: 1, message = {
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "core_node_name":"core_node1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "base_url":"http://127.0.0.1:53777",
   [junit4]   2> 	  "node_name":"127.0.0.1:53777_",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "collection":"control_collection",
   [junit4]   2> 	  "operation":"state"} current state version: 4
   [junit4]   2> 82311 T441 N:127.0.0.1:53777_ oasco.ReplicaMutator.updateState Update state numShards=2 message={
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "core_node_name":"core_node1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "base_url":"http://127.0.0.1:53777",
   [junit4]   2> 	  "node_name":"127.0.0.1:53777_",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "collection":"control_collection",
   [junit4]   2> 	  "operation":"state"}
   [junit4]   2> 82441 T440 N:127.0.0.1:53777_ oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
   [junit4]   2> 82441 T474 N:127.0.0.1:53792_ oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
   [junit4]   2> 82441 T451 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
   [junit4]   2> 83507 T412 N:127.0.0.1:53792_ oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:53792_
   [junit4]   2> 83509 T412 N:127.0.0.1:53792_ oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:53792_
   [junit4]   2> 83516 T412 N:127.0.0.1:53792_ oasc.Overseer.close Overseer (id=null) closing
   [junit4]   2> 83527 T412 N:127.0.0.1:53792_ oasc.CorePropertiesLocator.discover Looking for core definitions underneath C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\temp\solr.client.solrj.impl.CloudSolrClientTest B991998ABE83A57F-001\shard-1-001\cores
   [junit4]   2> 83531 T412 N:127.0.0.1:53792_ oasc.CoreDescriptor.<init> CORE DESCRIPTOR: {name=collection1, config=solrconfig.xml, transient=false, schema=schema.xml, loadOnStartup=true, instanceDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\temp\solr.client.solrj.impl.CloudSolrClientTest B991998ABE83A57F-001\shard-1-001\cores\collection1, collection=collection1, absoluteInstDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\temp\solr.client.solrj.impl.CloudSolrClientTest B991998ABE83A57F-001\shard-1-001\cores\collection1\, coreNodeName=, dataDir=data\, shard=}
   [junit4]   2> 83533 T412 N:127.0.0.1:53792_ oasc.CorePropertiesLocator.discoverUnder Found core collection1 in C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\temp\solr.client.solrj.impl.CloudSolrClientTest B991998ABE83A57F-001\shard-1-001\cores\collection1\
   [junit4]   2> 83533 T412 N:127.0.0.1:53792_ oasc.CorePropertiesLocator.discover Found 1 core definitions
   [junit4]   2> 83536 T475 N:127.0.0.1:53792_ C:collection1 c:collection1 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
   [junit4]   2> 83536 T475 N:127.0.0.1:53792_ C:collection1 c:collection1 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 83539 T440 N:127.0.0.1:53777_ oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected
   [junit4]   2> 83541 T475 N:127.0.0.1:53792_ oasc.ZkController.preRegister Registering watch for external collection collection1
   [junit4]   2> 83541 T475 N:127.0.0.1:53792_ oascc.ZkStateReader.addZkWatch addZkWatch collection1
   [junit4]   2> 83541 T441 N:127.0.0.1:53777_ oasc.Overseer$ClusterStateUpdater.run processMessage: queueSize: 1, message = {
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "base_url":"http://127.0.0.1:53792",
   [junit4]   2> 	  "node_name":"127.0.0.1:53792_",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "operation":"state"} current state version: 5
   [junit4]   2> 83542 T475 N:127.0.0.1:53792_ oascc.ZkStateReader.addZkWatch Updating collection state at /collections/collection1/state.json from ZooKeeper... 
   [junit4]   2> 83542 T441 N:127.0.0.1:53777_ oasco.ReplicaMutator.updateState Update state numShards=2 message={
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "base_url":"http://127.0.0.1:53792",
   [junit4]   2> 	  "node_name":"127.0.0.1:53792_",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "operation":"state"}
   [junit4]   2> 83544 T441 N:127.0.0.1:53777_ oasco.ReplicaMutator.updateState Collection already exists with numShards=2
   [junit4]   2> 83544 T441 N:127.0.0.1:53777_ oasco.ReplicaMutator.updateState Assigning new node to shard shard=shard2
   [junit4]   2> 83549 T475 N:127.0.0.1:53792_ oascc.ZkStateReader.updateWatchedCollection Updating data for collection1 to ver 0 
   [junit4]   2> 83549 T475 N:127.0.0.1:53792_ oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 83676 T441 N:127.0.0.1:53777_ oasco.ZkStateWriter.writePendingUpdates going to update_collection /collections/collection1/state.json version: 0
   [junit4]   2> 83677 T474 N:127.0.0.1:53792_ oascc.ZkStateReader$7.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json for collection collection1 has occurred - updating... (live nodes size: 2)
   [junit4]   2> 83679 T474 N:127.0.0.1:53792_ oascc.ZkStateReader.updateWatchedCollection Updating data for collection1 to ver 1 
   [junit4]   2> 84801 T475 N:127.0.0.1:53792_ oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 84801 T475 N:127.0.0.1:53792_ oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 84802 T475 N:127.0.0.1:53792_ oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 84802 T475 N:127.0.0.1:53792_ oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 84804 T475 N:127.0.0.1:53792_ oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 84804 T475 N:127.0.0.1:53792_ oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\temp\solr.client.solrj.impl.CloudSolrClientTest B991998ABE83A57F-001\shard-1-001\cores\collection1\'
   [junit4]   2> 84827 T475 N:127.0.0.1:53792_ oasc.Config.<init> loaded config solrconfig.xml with version 0 
   [junit4]   2> 84834 T475 N:127.0.0.1:53792_ oasc.SolrConfig.refreshRequestParams current version of requestparams : -1
   [junit4]   2> 84837 T475 N:127.0.0.1:53792_ oasc.SolrConfig.<init> Using Lucene MatchVersion: 6.0.0
   [junit4]   2> 84849 T475 N:127.0.0.1:53792_ oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 84851 T475 N:127.0.0.1:53792_ oass.IndexSchema.readSchema Reading Solr Schema from /configs/conf1/schema.xml
   [junit4]   2> 84859 T475 N:127.0.0.1:53792_ oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 84955 T475 N:127.0.0.1:53792_ oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 84957 T475 N:127.0.0.1:53792_ oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 84958 T475 N:127.0.0.1:53792_ oass.IndexSchema.loadCopyFields WARN Field lowerfilt1and2 is not multivalued and destination for multiple copyFields (2)
   [junit4]   2> 84959 T475 N:127.0.0.1:53792_ oass.IndexSchema.loadCopyFields WARN Field text is not multivalued and destination for multiple copyFields (3)
   [junit4]   2> 84959 T475 N:127.0.0.1:53792_ oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection collection1
   [junit4]   2> 84959 T475 N:127.0.0.1:53792_ c:collection1 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 84960 T475 N:127.0.0.1:53792_ c:collection1 oasc.SolrCore.<init> [[collection1] ] Opening new SolrCore at [C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\temp\solr.client.solrj.impl.CloudSolrClientTest B991998ABE83A57F-001\shard-1-001\cores\collection1\], dataDir=[null]
   [junit4]   2> 84960 T475 N:127.0.0.1:53792_ c:collection1 oasc.SolrCore.initInfoRegistry JMX monitoring not detected for core: collection1
   [junit4]   2> 84960 T475 N:127.0.0.1:53792_ c:collection1 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\temp\solr.client.solrj.impl.CloudSolrClientTest B991998ABE83A57F-001\shard-1-001\cores\collection1\data\
   [junit4]   2> 84960 T475 N:127.0.0.1:53792_ c:collection1 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\temp\solr.client.solrj.impl.CloudSolrClientTest B991998ABE83A57F-001\shard-1-001\cores\collection1\data\index/
   [junit4]   2> 84960 T475 N:127.0.0.1:53792_ c:collection1 oasc.SolrCore.initIndex WARN [collection1] Solr index directory 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\temp\solr.client.solrj.impl.CloudSolrClientTest B991998ABE83A57F-001\shard-1-001\cores\collection1\data\index' doesn't exist. Creating new index...
   [junit4]   2> 84961 T475 N:127.0.0.1:53792_ c:collection1 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\temp\solr.client.solrj.impl.CloudSolrClientTest B991998ABE83A57F-001\shard-1-001\cores\collection1\data\index
   [junit4]   2> 84961 T475 N:127.0.0.1:53792_ c:collection1 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@4c3ba lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@11076c9),segFN=segments_1,generation=1}
   [junit4]   2> 84961 T475 N:127.0.0.1:53792_ c:collection1 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 84964 T475 N:127.0.0.1:53792_ c:collection1 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 84970 T475 N:127.0.0.1:53792_ c:collection1 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 84971 T475 N:127.0.0.1:53792_ c:collection1 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 84973 T475 N:127.0.0.1:53792_ c:collection1 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 84974 T475 N:127.0.0.1:53792_ c:collection1 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 84974 T475 N:127.0.0.1:53792_ c:collection1 oasc.PluginBag.createPlugin requestHandler : '/replication' created with startup=lazy 
   [junit4]   2> 84976 T475 N:127.0.0.1:53792_ c:collection1 oasc.SolrResourceLoader.findClass WARN Solr loaded a deprecated plugin/analysis class [org.apache.solr.handler.admin.AdminHandlers]. Please consult documentation how to replace it accordingly.
   [junit4]   2> 84976 T475 N:127.0.0.1:53792_ c:collection1 oasc.SolrResourceLoader.findClass WARN Solr loaded a deprecated plugin/analysis class [org.apache.solr.handler.admin.AdminHandlers]. Please consult documentation how to replace it accordingly.
   [junit4]   2> 84976 T475 N:127.0.0.1:53792_ c:collection1 oasc.RequestHandlers.initHandlersFromConfig Registered paths: /admin/mbeans,standard,,/update/csv,/update/json/docs,/admin/luke,/admin/segments,/get,/admin/system,/replication,/admin/properties,/config,/schema,/admin/plugins,/admin/logging,/update/json,/admin,/admin/threads,/admin/ping,/update,/admin/file
   [junit4]   2> 84976 T475 N:127.0.0.1:53792_ c:collection1 oasc.RequestHandlers.initHandlersFromConfig WARN no default request handler is registered (either '/select' or 'standard')
   [junit4]   2> 84976 T475 N:127.0.0.1:53792_ c:collection1 oasc.SolrCore.initStatsCache Using default statsCache cache: org.apache.solr.search.stats.LocalStatsCache
   [junit4]   2> 84979 T475 N:127.0.0.1:53792_ c:collection1 oasu.UpdateHandler.<init> Using UpdateLog implementation: org.apache.solr.update.UpdateLog
   [junit4]   2> 84979 T475 N:127.0.0.1:53792_ c:collection1 oasu.UpdateLog.init Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10
   [junit4]   2> 84981 T475 N:127.0.0.1:53792_ c:collection1 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 84981 T475 N:127.0.0.1:53792_ c:collection1 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 84981 T475 N:127.0.0.1:53792_ c:collection1 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@4c3ba lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@11076c9),segFN=segments_1,generation=1}
   [junit4]   2> 84981 T475 N:127.0.0.1:53792_ c:collection1 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 84982 T475 N:127.0.0.1:53792_ c:collection1 oass.SolrIndexSearcher.<init> Opening Searcher@12fe494[collection1] main
   [junit4]   2> 84982 T475 N:127.0.0.1:53792_ c:collection1 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 84984 T475 N:127.0.0.1:53792_ c:collection1 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 84984 T475 N:127.0.0.1:53792_ c:collection1 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
   [junit4]   2> 84985 T475 N:127.0.0.1:53792_ c:collection1 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
   [junit4]   2> 84985 T475 N:127.0.0.1:53792_ c:collection1 oasr.RestManager.init Initializing RestManager with initArgs: {}
   [junit4]   2> 84985 T475 N:127.0.0.1:53792_ c:collection1 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 84986 T475 N:127.0.0.1:53792_ c:collection1 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
   [junit4]   2> 84986 T475 N:127.0.0.1:53792_ c:collection1 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 84986 T475 N:127.0.0.1:53792_ c:collection1 oasr.RestManager.init Initializing 0 registered ManagedResources
   [junit4]   2> 84987 T475 N:127.0.0.1:53792_ c:collection1 oasha.AdminHandlers.inform WARN <requestHandler name="/admin/" 
   [junit4]   2> 	 class="solr.admin.AdminHandlers" /> is deprecated . It is not required anymore
   [junit4]   2> 84987 T476 N:127.0.0.1:53792_ c:collection1 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@12fe494[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 84987 T475 N:127.0.0.1:53792_ c:collection1 oasc.ZkController.getConfDirListeners watch zkdir /configs/conf1
   [junit4]   2> 84990 T475 N:127.0.0.1:53792_ c:collection1 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 84991 T479 N:127.0.0.1:53792_ C:collection1 S:shard2 c:collection1 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:53792 collection:collection1 shard:shard2
   [junit4]   2> 84991 T412 N:127.0.0.1:53792_ oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0
   [junit4]   2> 84992 T412 N:127.0.0.1:53792_ oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 84992 T479 N:127.0.0.1:53792_ C:collection1 S:shard2 c:collection1 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
   [junit4]   2> 85002 T479 N:127.0.0.1:53792_ C:collection1 S:shard2 c:collection1 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
   [junit4]   2> 85004 T479 N:127.0.0.1:53792_ C:collection1 S:shard2 c:collection1 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 85004 T479 N:127.0.0.1:53792_ C:collection1 S:shard2 c:collection1 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> ASYNC  NEW_CORE C100 name=collection1 org.apache.solr.core.SolrCore@14e4862 url=http://127.0.0.1:53792/collection1 node=127.0.0.1:53792_ C100_STATE=coll:collection1 core:collection1 props:{core=collection1, base_url=http://127.0.0.1:53792, node_name=127.0.0.1:53792_, state=down}
   [junit4]   2> 85004 T479 N:127.0.0.1:53792_ C:collection1 S:shard2 c:collection1 C100 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:53792/collection1/
   [junit4]   2> 85006 T479 N:127.0.0.1:53792_ C:collection1 S:shard2 c:collection1 C100 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 85006 T479 N:127.0.0.1:53792_ C:collection1 S:shard2 c:collection1 C100 oasc.SyncStrategy.syncToMe http://127.0.0.1:53792/collection1/ has no replicas
   [junit4]   2> 85006 T479 N:127.0.0.1:53792_ C:collection1 S:shard2 c:collection1 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:53792/collection1/ shard2
   [junit4]   2> 85006 T479 N:127.0.0.1:53792_ C:collection1 S:shard2 c:collection1 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
   [junit4]   2> 85012 T440 N:127.0.0.1:53777_ oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected
   [junit4]   2> 85013 T441 N:127.0.0.1:53777_ oasc.Overseer$ClusterStateUpdater.run processMessage: queueSize: 2, message = {
   [junit4]   2> 	  "operation":"leader",
   [junit4]   2> 	  "shard":"shard2",
   [junit4]   2> 	  "collection":"collection1"} current state version: 5
   [junit4]   2> 85015 T441 N:127.0.0.1:53777_ oasco.ZkStateWriter.writePendingUpdates going to update_collection /collections/collection1/state.json version: 1
   [junit4]   2> 85015 T474 N:127.0.0.1:53792_ oascc.ZkStateReader$7.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json for collection collection1 has occurred - updating... (live nodes size: 2)
   [junit4]   2> 85018 T474 N:127.0.0.1:53792_ oascc.ZkStateReader.updateWatchedCollection Updating data for collection1 to ver 2 
   [junit4]   2> 85023 T441 N:127.0.0.1:53777_ oasc.Overseer$ClusterStateUpdater.run processMessage: queueSize: 1, message = {
   [junit4]   2> 	  "operation":"leader",
   [junit4]   2> 	  "shard":"shard2",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:53792",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "state":"active"} current state version: 5
   [junit4]   2> 85024 T441 N:127.0.0.1:53777_ oasco.ZkStateWriter.writePendingUpdates going to update_collection /collections/collection1/state.json version: 2
   [junit4]   2> 85036 T474 N:127.0.0.1:53792_ oascc.ZkStateReader$7.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json for collection collection1 has occurred - updating... (live nodes size: 2)
   [junit4]   2> 85037 T474 N:127.0.0.1:53792_ oascc.ZkStateReader.updateWatchedCollection Updating data for collection1 to ver 3 
   [junit4]   2> 85041 T440 N:127.0.0.1:53777_ oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected
   [junit4]   2> 85054 T412 oas.SolrTestCaseJ4.writeCoreProperties Writing core.properties file to C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\temp\solr.client.solrj.impl.CloudSolrClientTest B991998ABE83A57F-001\shard-2-001\cores\collection1
   [junit4]   2> 85057 T412 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 2 in directory C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\temp\solr.client.solrj.impl.CloudSolrClientTest B991998ABE83A57F-001\shard-2-001
   [junit4]   2> 85058 T412 oejs.Server.doStart jetty-9.2.10.v20150310
   [junit4]   2> 85063 T412 oejsh.ContextHandler.doStart Started o.e.j.s.ServletContextHandler@fd056e{/,null,AVAILABLE}
   [junit4]   2> 85065 T412 oejs.AbstractConnector.doStart Started ServerConnector@77058c{HTTP/1.1}{127.0.0.1:53803}
   [junit4]   2> 85065 T412 oejs.Server.doStart Started @98532ms
   [junit4]   2> 85065 T412 oascse.JettySolrRunner$1.lifeCycleStarted Jetty properties: {solr.data.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\temp\solr.client.solrj.impl.CloudSolrClientTest B991998ABE83A57F-001\tempDir-001/jetty2, solrconfig=solrconfig.xml, hostContext=/, hostPort=53803, coreRootDirectory=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\temp\solr.client.solrj.impl.CloudSolrClientTest B991998ABE83A57F-001\shard-2-001\cores}
   [junit4]   2> 85065 T412 oass.SolrDispatchFilter.init SolrDispatchFilter.init()sun.misc.Launcher$AppClassLoader@19e0bfd
   [junit4]   2> 85067 T412 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\temp\solr.client.solrj.impl.CloudSolrClientTest B991998ABE83A57F-001\shard-2-001\'
   [junit4]   2> 85075 T479 N:127.0.0.1:53792_ C:collection1 S:shard2 c:collection1 oasc.ZkController.register We are http://127.0.0.1:53792/collection1/ and leader is http://127.0.0.1:53792/collection1/
   [junit4]   2> 85075 T479 N:127.0.0.1:53792_ C:collection1 S:shard2 c:collection1 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:53792
   [junit4]   2> 85075 T479 N:127.0.0.1:53792_ C:collection1 S:shard2 c:collection1 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 85075 T479 N:127.0.0.1:53792_ C:collection1 S:shard2 c:collection1 oasc.ZkController.publish publishing core=collection1 state=active collection=collection1
   [junit4]   2> 85075 T479 N:127.0.0.1:53792_ C:collection1 S:shard2 c:collection1 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 85080 T440 N:127.0.0.1:53777_ oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected
   [junit4]   2> 85085 T441 N:127.0.0.1:53777_ oasc.Overseer$ClusterStateUpdater.run processMessage: queueSize: 1, message = {
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "core_node_name":"core_node1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "base_url":"http://127.0.0.1:53792",
   [junit4]   2> 	  "node_name":"127.0.0.1:53792_",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "shard":"shard2",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "operation":"state"} current state version: 5
   [junit4]   2> 85087 T441 N:127.0.0.1:53777_ oasco.ReplicaMutator.updateState Update state numShards=2 message={
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "core_node_name":"core_node1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "base_url":"http://127.0.0.1:53792",
   [junit4]   2> 	  "node_name":"127.0.0.1:53792_",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "shard":"shard2",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "operation":"state"}
   [junit4]   2> 85090 T441 N:127.0.0.1:53777_ oasco.ZkStateWriter.writePendingUpdates going to update_collection /collections/collection1/state.json version: 3
   [junit4]   2> 85091 T474 N:127.0.0.1:53792_ oascc.ZkStateReader$7.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json for collection collection1 has occurred - updating... (live nodes size: 2)
   [junit4]   2> 85092 T479 N:127.0.0.1:53792_ C:collection1 S:shard2 c:collection1 oascc.ZkStateReader.updateWatchedCollection Updating data for collection1 to ver 4 
   [junit4]   2> 85092 T474 N:127.0.0.1:53792_ oascc.ZkStateReader.updateWatchedCollection Updating data for collection1 to ver 4 
   [junit4]   2> 85105 T412 oasc.SolrXmlConfig.fromFile Loading container configuration from C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\temp\solr.client.solrj.impl.CloudSolrClientTest B991998ABE83A57F-001\shard-2-001\solr.xml
   [junit4]   2> 85121 T412 oasc.CorePropertiesLocator.<init> Config-defined core root directory: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\temp\solr.client.solrj.impl.CloudSolrClientTest B991998ABE83A57F-001\shard-2-001\cores
   [junit4]   2> 85121 T412 oasc.CoreContainer.<init> New CoreContainer 24480568
   [junit4]   2> 85122 T412 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\temp\solr.client.solrj.impl.CloudSolrClientTest B991998ABE83A57F-001\shard-2-001\]
   [junit4]   2> 85122 T412 oasc.CoreContainer.load loading shared library: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\temp\solr.client.solrj.impl.CloudSolrClientTest B991998ABE83A57F-001\shard-2-001\lib
   [junit4]   2> 85123 T412 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: lib (resolved as: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\temp\solr.client.solrj.impl.CloudSolrClientTest B991998ABE83A57F-001\shard-2-001\lib).
   [junit4]   2> 85132 T412 oashc.HttpShardHandlerFactory.init created with socketTimeout : 90000,urlScheme : ,connTimeout : 15000,maxConnectionsPerHost : 20,maxConnections : 10000,corePoolSize : 0,maximumPoolSize : 2147483647,maxThreadIdleTime : 5,sizeOfQueue : -1,fairnessPolicy : false,useRetries : false,
   [junit4]   2> 85134 T412 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
   [junit4]   2> 85134 T412 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 85135 T412 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 85135 T412 oasc.CoreContainer.load Node Name: 127.0.0.1
   [junit4]   2> 85135 T412 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:53770/solr
   [junit4]   2> 85135 T412 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 85135 T412 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider
   [junit4]   2> 85138 T412 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 85141 T493 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2f4a4c name:ZooKeeperConnection Watcher:127.0.0.1:53770 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 85143 T412 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 85143 T412 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider
   [junit4]   2> 85150 T412 N:127.0.0.1:53803_ oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 85152 T496 N:127.0.0.1:53803_ oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1634e51 name:ZooKeeperConnection Watcher:127.0.0.1:53770/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 85154 T412 N:127.0.0.1:53803_ oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 85162 T412 N:127.0.0.1:53803_ oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 86425 T412 N:127.0.0.1:53803_ oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:53803_
   [junit4]   2> 86426 T412 N:127.0.0.1:53803_ oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:53803_
   [junit4]   2> 86432 T412 N:127.0.0.1:53803_ oasc.Overseer.close Overseer (id=null) closing
   [junit4]   2> 86436 T412 N:127.0.0.1:53803_ oasc.CorePropertiesLocator.discover Looking for core definitions underneath C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\temp\solr.client.solrj.impl.CloudSolrClientTest B991998ABE83A57F-001\shard-2-001\cores
   [junit4]   2> 86439 T412 N:127.0.0.1:53803_ oasc.CoreDescriptor.<init> CORE DESCRIPTOR: {name=collection1, config=solrconfig.xml, transient=false, schema=schema.xml, loadOnStartup=true, instanceDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\temp\solr.client.solrj.impl.CloudSolrClientTest B991998ABE83A57F-001\shard-2-001\cores\collection1, collection=collection1, absoluteInstDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\temp\solr.client.solrj.impl.CloudSolrClientTest B991998ABE83A57F-001\shard-2-001\cores\collection1\, coreNodeName=, dataDir=data\, shard=}
   [junit4]   2> 86439 T412 N:127.0.0.1:53803_ oasc.CorePropertiesLocator.discoverUnder Found core collection1 in C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\temp\solr.client.solrj.impl.CloudSolrClientTest B991998ABE83A57F-001\shard-2-001\cores\collection1\
   [junit4]   2> 86440 T412 N:127.0.0.1:53803_ oasc.CorePropertiesLocator.discover Found 1 core definitions
   [junit4]   2> 86445 T497 N:127.0.0.1:53803_ C:collection1 c:collection1 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
   [junit4]   2> 86445 T497 N:127.0.0.1:53803_ C:collection1 c:collection1 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 86448 T440 N:127.0.0.1:53777_ oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected
   [junit4]   2> 86449 T497 N:127.0.0.1:53803_ oasc.ZkController.preRegister Registering watch for external collection collection1
   [junit4]   2> 86449 T497 N:127.0.0.1:53803_ oascc.ZkStateReader.addZkWatch addZkWatch collection1
   [junit4]   2> 86449 T441 N:127.0.0.1:53777_ oasc.Overseer$ClusterStateUpdater.run processMessage: queueSize: 1, message = {
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "base_url":"http://127.0.0.1:53803",
   [junit4]   2> 	  "node_name":"127.0.0.1:53803_",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "operation":"state"} current state version: 5
   [junit4]   2> 86450 T497 N:127.0.0.1:53803_ oascc.ZkStateReader.addZkWatch Updating collection state at /collections/collection1/state.json from ZooKeeper... 
   [junit4]   2> 86450 T441 N:127.0.0.1:53777_ oasco.ReplicaMutator.updateState Update state numShards=2 message={
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "base_url":"http://127.0.0.1:53803",
   [junit4]   2> 	  "node_name":"127.0.0.1:53803_",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "operation":"state"}
   [junit4]   2> 86450 T441 N:127.0.0.1:53777_ oasco.ReplicaMutator.updateState Collection already exists with numShards=2
   [junit4]   2> 86450 T441 N:127.0.0.1:53777_ oasco.ReplicaMutator.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 86451 T497 N:127.0.0.1:53803_ oascc.ZkStateReader.updateWatchedCollection Updating data for collection1 to ver 4 
   [junit4]   2> 86451 T497 N:127.0.0.1:53803_ oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 86453 T441 N:127.0.0.1:53777_ oasco.ZkStateWriter.writePendingUpdates going to update_collection /collections/collection1/state.json version: 4
   [junit4]   2> 86454 T496 N:127.0.0.1:53803_ oascc.ZkStateReader$7.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json for collection collection1 has occurred - updating... (live nodes size: 3)
   [junit4]   2> 86454 T474 N:127.0.0.1:53792_ oascc.ZkStateReader$7.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json for collection collection1 has occurred - updating... (live nodes size: 3)
   [junit4]   2> 86455 T496 N:127.0.0.1:53803_ oascc.ZkStateReader.updateWatchedCollection Updating data for collection1 to ver 5 
   [junit4]   2> 86455 T474 N:127.0.0.1:53792_ oascc.ZkStateReader.updateWatchedCollection Updating data for collection1 to ver 5 
   [junit4]   2> 87705 T497 N:127.0.0.1:53803_ oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 87705 T497 N:127.0.0.1:53803_ oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 87707 T497 N:127.0.0.1:53803_ oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 87707 T497 N:127.0.0.1:53803_ oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 87708 T497 N:127.0.0.1:53803_ oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 87708 T497 N:127.0.0.1:53803_ oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\temp\solr.client.solrj.impl.CloudSolrClientTest B991998ABE83A57F-001\shard-2-001\cores\collection1\'
   [junit4]   2> 87726 T497 N:127.0.0.1:53803_ oasc.Config.<init> loaded config solrconfig.xml with version 0 
   [junit4]   2> 87733 T497 N:127.0.0.1:53803_ oasc.SolrConfig.refreshRequestParams current version of requestparams : -1
   [junit4]   2> 87736 T497 N:127.0.0.1:53803_ oasc.SolrConfig.<init> Using Lucene MatchVersion: 6.0.0
   [junit4]   2> 87749 T497 N:127.0.0.1:53803_ oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 87752 T497 N:127.0.0.1:53803_ oass.IndexSchema.readSchema Reading Solr Schema from /configs/conf1/schema.xml
   [junit4]   2> 87757 T497 N:127.0.0.1:53803_ oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 87961 T497 N:127.0.0.1:53803_ oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 87962 T497 N:127.0.0.1:53803_ oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 87963 T497 N:127.0.0.1:53803_ oass.IndexSchema.loadCopyFields WARN Field lowerfilt1and2 is not multivalued and destination for multiple copyFields (2)
   [junit4]   2> 87963 T497 N:127.0.0.1:53803_ oass.IndexSchema.loadCopyFields WARN Field text is not multivalued and destination for multiple copyFields (3)
   [junit4]   2> 87965 T497 N:127.0.0.1:53803_ oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection collection1
   [junit4]   2> 87965 T497 N:127.0.0.1:53803_ c:collection1 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 87965 T497 N:127.0.0.1:53803_ c:collection1 oasc.SolrCore.<init> [[collection1] ] Opening new SolrCore at [C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\temp\solr.client.solrj.impl.CloudSolrClientTest B991998ABE83A57F-001\shard-2-001\cores\collection1\], dataDir=[null]
   [junit4]   2> 87965 T497 N:127.0.0.1:53803_ c:collection1 oasc.SolrCore.initInfoRegistry JMX monitoring not detected for core: collection1
   [junit4]   2> 87966 T497 N:127.0.0.1:53803_ c:collection1 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\..\..\..\..\..\..\..\

[...truncated too long message...]

loudSolrClientTest B991998ABE83A57F-001\shard-3-003\cores\collection1\data\
   [junit4]   2> 168051 T931 N:127.0.0.1:54261_ oasc.CachingDirectoryFactory.closeCacheValue looking to close C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\temp\solr.client.solrj.impl.CloudSolrClientTest B991998ABE83A57F-001\shard-3-003\cores\collection1\data\index [CachedDir<<refCount=0;path=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\temp\solr.client.solrj.impl.CloudSolrClientTest B991998ABE83A57F-001\shard-3-003\cores\collection1\data\index;done=false>>]
   [junit4]   2> 168051 T931 N:127.0.0.1:54261_ oasc.CachingDirectoryFactory.close Closing directory: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\temp\solr.client.solrj.impl.CloudSolrClientTest B991998ABE83A57F-001\shard-3-003\cores\collection1\data\index
   [junit4]   2> 168052 T931 N:127.0.0.1:54261_ oasc.LeaderElector$ElectionWatcher.process WARN  org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer/queue/qn-
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
   [junit4]   2> 	at org.apache.zookeeper.ZooKeeper.create(ZooKeeper.java:783)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$9.execute(SolrZkClient.java:380)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$9.execute(SolrZkClient.java:377)
   [junit4]   2> 	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:61)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient.create(SolrZkClient.java:377)
   [junit4]   2> 	at org.apache.solr.cloud.DistributedQueue.createData(DistributedQueue.java:380)
   [junit4]   2> 	at org.apache.solr.cloud.DistributedQueue.offer(DistributedQueue.java:364)
   [junit4]   2> 	at org.apache.solr.cloud.ShardLeaderElectionContext.runLeaderProcess(ElectionContext.java:230)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:198)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:159)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:348)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:256)
   [junit4]   2> 	at org.apache.solr.cloud.ShardLeaderElectionContext.rejoinLeaderElection(ElectionContext.java:492)
   [junit4]   2> 	at org.apache.solr.cloud.ShardLeaderElectionContext.runLeaderProcess(ElectionContext.java:248)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:198)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:159)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.access$200(LeaderElector.java:56)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector$ElectionWatcher.process(LeaderElector.java:390)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$3$1.run(SolrZkClient.java:264)
   [junit4]   2> 	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
   [junit4]   2> 	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
   [junit4]   2> 	at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor$1.run(ExecutorUtil.java:148)
   [junit4]   2> 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
   [junit4]   2> 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
   [junit4]   2> 	at java.lang.Thread.run(Thread.java:745)
   [junit4]   2> 
   [junit4]   2> 168052 T412 oejs.AbstractConnector.doStop Stopped ServerConnector@17f4fc0{HTTP/1.1}{127.0.0.1:0}
   [junit4]   2> 168053 T412 oejsh.ContextHandler.doStop Stopped o.e.j.s.ServletContextHandler@18d4fde{/,null,UNAVAILABLE}
   [junit4]   2> 168055 T412 C:control_collection S:shard1 c:collection1 oasc.ChaosMonkey.monkeyLog monkey: stop shard! 54228
   [junit4]   2> 168056 T412 C:control_collection S:shard1 c:collection1 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:54221 54221
   [junit4]   2> 169870 T814 C:control_collection S:shard1 c:collection1 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:54221 54221
   [junit4]   2> 169871 T814 C:control_collection S:shard1 c:collection1 oasc.ZkTestServer$ZKServerMain.runFromConfig WARN Watch limit violations: 
   [junit4]   2> 	Maximum concurrent create/delete watches above limit:
   [junit4]   2> 	
   [junit4]   2> 		5	/solr/aliases.json
   [junit4]   2> 		5	/solr/clusterstate.json
   [junit4]   2> 		4	/solr/configs/conf1
   [junit4]   2> 		3	/solr/collections/collection1/state.json
   [junit4]   2> 	
   [junit4]   2> 	Maximum concurrent children watches above limit:
   [junit4]   2> 	
   [junit4]   2> 		5	/solr/live_nodes
   [junit4]   2> 		3	/solr/overseer/collection-queue-work
   [junit4]   2> 	
   [junit4]   2> 169872 T412 C:control_collection S:shard1 c:collection1 oas.SolrTestCaseJ4.deleteCore ###deleteCore
   [junit4]   2> NOTE: leaving temporary files on disk at: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\test\J0\temp\solr.client.solrj.impl.CloudSolrClientTest B991998ABE83A57F-001
   [junit4]   2> NOTE: test params are: codec=Asserting(Lucene50), sim=RandomSimilarityProvider(queryNorm=true,coord=crazy): {}, locale=el_GR, timezone=SystemV/AST4ADT
   [junit4]   2> NOTE: Windows 7 6.1 x86/Oracle Corporation 1.8.0_40 (32-bit)/cpus=3,threads=1,free=24160432,total=79192064
   [junit4]   2> NOTE: All tests run in this JVM: [TestXMLEscaping, FieldAnalysisResponseTest, TestCloudSolrClientConnections, TermsResponseTest, GetByIdTest, SolrDocumentTest, TestEmbeddedSolrServer, TestJsonRecordReader, TestJavaBinCodec, TestHash, JettyWebappTest, TestSolrProperties, NamedListTest, DocumentAnalysisResponseTest, ConcurrentUpdateSolrClientTest, SolrExampleStreamingTest, SolrExampleBinaryTest, SolrExampleXMLTest, SolrExampleEmbeddedTest, LargeVolumeBinaryJettyTest, TestBatchUpdate, TestSpellCheckResponse, MergeIndexesEmbeddedTest, QueryResponseTest, TestCoreAdmin, TestDocumentObjectBinder, SolrQueryTest, ContentStreamTest, ModifiableSolrParamsTest, TestFastInputStream, SolrExceptionTest, TestUpdateRequestCodec, AnlysisResponseBaseTest, FacetFieldTest, BasicHttpSolrClientTest, CloudSolrClientTest]
   [junit4] Completed [57/57] on J0 in 90.05s, 3 tests, 1 failure <<< FAILURES!

[...truncated 10 lines...]
BUILD FAILED
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\build.xml:526: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\build.xml:474: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\build.xml:61: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\extra-targets.xml:39: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build.xml:242: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\common-build.xml:512: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\common-build.xml:1415: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\common-build.xml:973: There were test failures: 57 suites, 381 tests, 1 failure

Total time: 59 minutes 15 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
ERROR: Failed to archive artifacts: **/*.events,heapdumps/**,**/hs_err_pid*
java.io.IOException: Failed to extract C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows/transfer of 2 files
	at hudson.FilePath.readFromTar(FilePath.java:2299)
	at hudson.FilePath.copyRecursiveTo(FilePath.java:2208)
	at jenkins.model.StandardArtifactManager.archive(StandardArtifactManager.java:61)
	at hudson.tasks.ArtifactArchiver.perform(ArtifactArchiver.java:219)
	at hudson.tasks.BuildStepCompatibilityLayer.perform(BuildStepCompatibilityLayer.java:74)
	at hudson.tasks.BuildStepMonitor$1.perform(BuildStepMonitor.java:20)
	at hudson.model.AbstractBuild$AbstractBuildExecution.perform(AbstractBuild.java:761)
	at hudson.model.AbstractBuild$AbstractBuildExecution.performAllBuildSteps(AbstractBuild.java:721)
	at hudson.model.Build$BuildExecution.post2(Build.java:183)
	at hudson.model.AbstractBuild$AbstractBuildExecution.post(AbstractBuild.java:670)
	at hudson.model.Run.execute(Run.java:1766)
	at hudson.model.FreeStyleBuild.run(FreeStyleBuild.java:43)
	at hudson.model.ResourceController.execute(ResourceController.java:98)
	at hudson.model.Executor.run(Executor.java:374)
Caused by: java.io.IOException: Truncated TAR archive
	at org.apache.commons.compress.archivers.tar.TarArchiveInputStream.read(TarArchiveInputStream.java:614)
	at java.io.InputStream.read(InputStream.java:101)
	at org.apache.commons.io.IOUtils.copyLarge(IOUtils.java:1792)
	at org.apache.commons.io.IOUtils.copyLarge(IOUtils.java:1769)
	at org.apache.commons.io.IOUtils.copy(IOUtils.java:1744)
	at hudson.util.IOUtils.copy(IOUtils.java:40)
	at hudson.FilePath.readFromTar(FilePath.java:2289)
	... 13 more
Recording test results
Email was triggered for: Failure - Any
Sending email for trigger: Failure - Any



[JENKINS] Lucene-Solr-trunk-Windows (64bit/jdk1.8.0_40) - Build # 4725 - Still Failing!

Posted by Policeman Jenkins Server <je...@thetaphi.de>.
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Windows/4725/
Java: 64bit/jdk1.8.0_40 -XX:+UseCompressedOops -XX:+UseConcMarkSweepGC

1 tests failed.
FAILED:  org.apache.lucene.search.postingshighlight.TestPostingsHighlighter.testFieldSometimesMissingFromSegment

Error Message:


Stack Trace:
java.lang.AssertionError
	at __randomizedtesting.SeedInfo.seed([1FDFF344FEFA8793:E7510981EC4BE40]:0)
	at org.junit.Assert.fail(Assert.java:92)
	at org.junit.Assert.assertTrue(Assert.java:43)
	at org.junit.Assert.assertNull(Assert.java:551)
	at org.junit.Assert.assertNull(Assert.java:562)
	at org.apache.lucene.search.postingshighlight.TestPostingsHighlighter.testFieldSometimesMissingFromSegment(TestPostingsHighlighter.java:1154)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:497)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1627)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:836)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:872)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:886)
	at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
	at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:798)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:458)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:845)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:747)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:781)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:792)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:54)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
	at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365)
	at java.lang.Thread.run(Thread.java:745)




Build Log:
[...truncated 6783 lines...]
   [junit4] Suite: org.apache.lucene.search.postingshighlight.TestPostingsHighlighter
   [junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=TestPostingsHighlighter -Dtests.method=testFieldSometimesMissingFromSegment -Dtests.seed=1FDFF344FEFA8793 -Dtests.slow=true -Dtests.locale=no_NO_NY -Dtests.timezone=Asia/Riyadh -Dtests.asserts=true -Dtests.file.encoding=ISO-8859-1
   [junit4] FAILURE 0.08s J0 | TestPostingsHighlighter.testFieldSometimesMissingFromSegment <<<
   [junit4]    > Throwable #1: java.lang.AssertionError
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([1FDFF344FEFA8793:E7510981EC4BE40]:0)
   [junit4]    > 	at org.apache.lucene.search.postingshighlight.TestPostingsHighlighter.testFieldSometimesMissingFromSegment(TestPostingsHighlighter.java:1154)
   [junit4]    > 	at java.lang.Thread.run(Thread.java:745)
   [junit4]   2> NOTE: leaving temporary files on disk at: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\build\highlighter\test\J0\temp\lucene.search.postingshighlight.TestPostingsHighlighter 1FDFF344FEFA8793-001
   [junit4]   2> NOTE: test params are: codec=Asserting(Lucene50): {id=PostingsFormat(name=Memory doPackFST= true), body=FST50, title=PostingsFormat(name=MockRandom)}, docValues:{}, sim=RandomSimilarityProvider(queryNorm=true,coord=yes): {id=IB LL-L2, body=IB SPL-LZ(0.3), title=IB LL-D3(800.0)}, locale=no_NO_NY, timezone=Asia/Riyadh
   [junit4]   2> NOTE: Windows 7 6.1 amd64/Oracle Corporation 1.8.0_40 (64-bit)/cpus=3,threads=1,free=47041352,total=64880640
   [junit4]   2> NOTE: All tests run in this JVM: [TestPostingsHighlighterRanking, SimpleFragmentsBuilderTest, TokenSourcesTest, TestPostingsHighlighter]
   [junit4] Completed [21/22] on J0 in 0.74s, 31 tests, 1 failure <<< FAILURES!

[...truncated 13 lines...]
BUILD FAILED
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\build.xml:526: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\build.xml:474: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\build.xml:61: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\extra-targets.xml:39: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\build.xml:466: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\common-build.xml:2145: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\module-build.xml:58: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\common-build.xml:1415: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\common-build.xml:973: There were test failures: 22 suites, 251 tests, 1 failure

Total time: 14 minutes 56 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
Recording test results
Email was triggered for: Failure - Any
Sending email for trigger: Failure - Any



[JENKINS] Lucene-Solr-trunk-Windows (32bit/jdk1.8.0_40) - Build # 4724 - Still Failing!

Posted by Policeman Jenkins Server <je...@thetaphi.de>.
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Windows/4724/
Java: 32bit/jdk1.8.0_40 -server -XX:+UseConcMarkSweepGC

1 tests failed.
FAILED:  org.apache.solr.update.AutoCommitTest.testMaxTime

Error Message:
Exception during query

Stack Trace:
java.lang.RuntimeException: Exception during query
	at __randomizedtesting.SeedInfo.seed([709987D71C07735C:EA6DFA35829DEF60]:0)
	at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:794)
	at org.apache.solr.update.AutoCommitTest.testMaxTime(AutoCommitTest.java:237)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:497)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1627)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:836)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:872)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:886)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
	at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
	at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:798)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:458)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:845)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:747)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:781)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:792)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:54)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
	at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365)
	at java.lang.Thread.run(Thread.java:745)
Caused by: java.lang.RuntimeException: REQUEST FAILED: xpath=//result[@numFound=1]
	xml response was: <?xml version="1.0" encoding="UTF-8"?>
<response>
<lst name="responseHeader"><int name="status">0</int><int name="QTime">0</int></lst><result name="response" numFound="0" start="0"></result>
</response>

	request was:q=id:529&qt=standard&start=0&rows=20&version=2.2
	at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:787)
	... 40 more




Build Log:
[...truncated 9550 lines...]
   [junit4] Suite: org.apache.solr.update.AutoCommitTest
   [junit4]   2> Creating dataDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J1\temp\solr.update.AutoCommitTest 709987D71C07735C-001\init-core-data-001
   [junit4]   2> 455400 T2198 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (false) and clientAuth (false)
   [junit4]   2> 455401 T2198 oas.SolrTestCaseJ4.initCore ####initCore
   [junit4]   2> 455401 T2198 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\core\src\test-files\solr\collection1\'
   [junit4]   2> 455402 T2198 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/core/src/test-files/solr/collection1/lib/classes/' to classloader
   [junit4]   2> 455402 T2198 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/core/src/test-files/solr/collection1/lib/README' to classloader
   [junit4]   2> 455442 T2198 oasc.SolrConfig.refreshRequestParams current version of requestparams : -1
   [junit4]   2> 455452 T2198 oasc.SolrConfig.<init> Using Lucene MatchVersion: 6.0.0
   [junit4]   2> 455478 T2198 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 455479 T2198 oass.IndexSchema.readSchema Reading Solr Schema from C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\core\src\test-files\solr\collection1\conf\schema.xml
   [junit4]   2> 455484 T2198 oass.IndexSchema.readSchema [null] Schema name=test
   [junit4]   2> 455573 T2198 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 455579 T2198 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 455580 T2198 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 455587 T2198 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 455589 T2198 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 455590 T2198 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 455591 T2198 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 455591 T2198 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 455591 T2198 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 455591 T2198 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 455591 T2198 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 455591 T2198 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 455591 T2198 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\core\src\test-files\solr
   [junit4]   2> 455592 T2198 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\core\src\test-files\solr\'
   [junit4]   2> 455609 T2198 oasc.CoreContainer.<init> New CoreContainer 17608848
   [junit4]   2> 455609 T2198 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\core\src\test-files\solr\]
   [junit4]   2> 455610 T2198 oasc.CoreContainer.load loading shared library: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\core\src\test-files\solr\lib
   [junit4]   2> 455610 T2198 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: lib (resolved as: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\core\src\test-files\solr\lib).
   [junit4]   2> 455616 T2198 oashc.HttpShardHandlerFactory.init created with socketTimeout : 600000,connTimeout : 60000,maxConnectionsPerHost : 20,maxConnections : 10000,corePoolSize : 0,maximumPoolSize : 2147483647,maxThreadIdleTime : 5,sizeOfQueue : -1,fairnessPolicy : false,useRetries : false,
   [junit4]   2> 455627 T2198 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: socketTimeout=30000&connTimeout=30000&retry=true
   [junit4]   2> 455629 T2198 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 455629 T2198 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 455629 T2198 oasc.CoreContainer.load Node Name: testNode
   [junit4]   2> 455630 T2198 oasc.CoreDescriptor.<init> CORE DESCRIPTOR: {name=collection1, config=solrconfig.xml, transient=false, schema=schema.xml, loadOnStartup=true, instanceDir=collection1, collection=collection1, absoluteInstDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\core\src\test-files\solr\collection1\, dataDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J1\temp\solr.update.AutoCommitTest 709987D71C07735C-001\init-core-data-001, shard=shard1}
   [junit4]   2> 455631 T2199 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\core\src\test-files\solr\collection1\'
   [junit4]   2> 455631 T2199 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/core/src/test-files/solr/collection1/lib/classes/' to classloader
   [junit4]   2> 455632 T2199 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/core/src/test-files/solr/collection1/lib/README' to classloader
   [junit4]   2> 455650 T2199 oasc.SolrConfig.refreshRequestParams current version of requestparams : -1
   [junit4]   2> 455672 T2199 oasc.SolrConfig.<init> Using Lucene MatchVersion: 6.0.0
   [junit4]   2> 455696 T2199 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 455697 T2199 oass.IndexSchema.readSchema Reading Solr Schema from C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\core\src\test-files\solr\collection1\conf\schema.xml
   [junit4]   2> 455701 T2199 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 455912 T2199 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 455917 T2199 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 455918 T2199 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 455923 T2199 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 455925 T2199 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 455929 T2199 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 455929 T2199 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 455930 T2199 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 455930 T2199 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 455930 T2199 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 455930 T2199 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 455930 T2199 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from instancedir C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\core\src\test-files\solr\collection1\
   [junit4]   2> 455931 T2199 c:collection1 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 455931 T2199 c:collection1 oasc.SolrCore.<init> [[collection1] ] Opening new SolrCore at [C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\core\src\test-files\solr\collection1\], dataDir=[null]
   [junit4]   2> 455931 T2199 c:collection1 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1987ed3
   [junit4]   2> 455932 T2199 c:collection1 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J1\temp\solr.update.AutoCommitTest 709987D71C07735C-001\init-core-data-001\
   [junit4]   2> 455932 T2199 c:collection1 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J1\temp\solr.update.AutoCommitTest 709987D71C07735C-001\init-core-data-001\index/
   [junit4]   2> 455932 T2199 c:collection1 oasc.SolrCore.initIndex WARN [collection1] Solr index directory 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J1\temp\solr.update.AutoCommitTest 709987D71C07735C-001\init-core-data-001\index' doesn't exist. Creating new index...
   [junit4]   2> 455932 T2199 c:collection1 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J1\temp\solr.update.AutoCommitTest 709987D71C07735C-001\init-core-data-001\index
   [junit4]   2> 455932 T2199 c:collection1 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=42, maxMergeAtOnceExplicit=10, maxMergedSegmentMB=69.91015625, floorSegmentMB=1.736328125, forceMergeDeletesPctAllowed=21.847986478264836, segmentsPerTier=13.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
   [junit4]   2> 455933 T2199 c:collection1 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@1ccc2f3 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6d6f68),segFN=segments_1,generation=1}
   [junit4]   2> 455933 T2199 c:collection1 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 455936 T2199 c:collection1 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 455936 T2199 c:collection1 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 455937 T2199 c:collection1 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe-allfields"
   [junit4]   2> 455937 T2199 c:collection1 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
   [junit4]   2> 455937 T2199 c:collection1 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 455937 T2199 c:collection1 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 455937 T2199 c:collection1 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "uniq-fields"
   [junit4]   2> 455937 T2199 c:collection1 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
   [junit4]   2> 455937 T2199 c:collection1 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 455938 T2199 c:collection1 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 455938 T2199 c:collection1 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 455938 T2199 c:collection1 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 455942 T2199 c:collection1 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 455944 T2199 c:collection1 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 455945 T2199 c:collection1 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 455947 T2199 c:collection1 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 455950 T2199 c:collection1 oasc.PluginBag.createPlugin requestHandler : 'lazy' created with startup=lazy 
   [junit4]   2> 455951 T2199 c:collection1 oasc.RequestHandlers.initHandlersFromConfig Registered paths: /admin/mbeans,standard,spellCheckCompRH,lazy,/update/json/docs,/admin/luke,spellCheckWithWordbreak_Direct,tvrh,/get,/admin/properties,/update/json,mltrh,/admin/threads,/search-facet-def,/update/csv,/search-facet-invariants,/admin/segments,spellCheckCompRH1,/mlt,/admin/system,/replication,dismax,defaults,/config,/schema,/admin/plugins,/admin/logging,spellCheckWithWordbreak,mock,/admin/ping,/update,/admin/file,/terms,spellCheckCompRH_Direct,/debug/dump
   [junit4]   2> 455952 T2199 c:collection1 oasc.SolrCore.initDeprecatedSupport WARN solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
   [junit4]   2> 455952 T2199 c:collection1 oasc.SolrCore.initStatsCache Using default statsCache cache: org.apache.solr.search.stats.LocalStatsCache
   [junit4]   2> 455953 T2199 c:collection1 oasu.UpdateHandler.<init> Using UpdateLog implementation: org.apache.solr.update.UpdateLog
   [junit4]   2> 455953 T2199 c:collection1 oasu.UpdateLog.init Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10
   [junit4]   2> 455954 T2199 c:collection1 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 455954 T2199 c:collection1 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 455955 T2199 c:collection1 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=15, maxMergeAtOnceExplicit=50, maxMergedSegmentMB=87.796875, floorSegmentMB=1.8701171875, forceMergeDeletesPctAllowed=13.647175345651432, segmentsPerTier=49.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.3462000847861548
   [junit4]   2> 455955 T2199 c:collection1 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@1ccc2f3 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6d6f68),segFN=segments_1,generation=1}
   [junit4]   2> 455955 T2199 c:collection1 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 455955 T2199 c:collection1 oass.SolrIndexSearcher.<init> Opening Searcher@138d9b3[collection1] main
   [junit4]   2> 455956 T2199 c:collection1 oasr.RestManager.init Initializing RestManager with initArgs: {storageIO=org.apache.solr.rest.ManagedResourceStorage$InMemoryStorageIO}
   [junit4]   2> 455956 T2199 c:collection1 oasr.ManagedResourceStorage.load Reading _rest_managed.json using InMemoryStorage
   [junit4]   2> 455956 T2199 c:collection1 oasr.RestManager.init Initializing 0 registered ManagedResources
   [junit4]   2> 455956 T2199 c:collection1 oashc.SpellCheckComponent.inform Initializing spell checkers
   [junit4]   2> 455964 T2199 c:collection1 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
   [junit4]   2> 456018 T2199 c:collection1 oash.ReplicationHandler.inform Commits will be reserved for  10000
   [junit4]   2> 456018 T2200 c:collection1 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: default
   [junit4]   2> 456019 T2200 c:collection1 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: direct
   [junit4]   2> 456019 T2200 c:collection1 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: wordbreak
   [junit4]   2> 456019 T2200 c:collection1 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: multipleFields
   [junit4]   2> 456019 T2200 c:collection1 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: jarowinkler
   [junit4]   2> 456019 T2200 c:collection1 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: external
   [junit4]   2> 456020 T2200 c:collection1 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: freq
   [junit4]   2> 456020 T2200 c:collection1 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: fqcn
   [junit4]   2> 456020 T2200 c:collection1 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: perDict
   [junit4]   2> 456021 T2200 c:collection1 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@138d9b3[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 456021 T2199 c:collection1 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 456024 T2198 oas.SolrTestCaseJ4.initCore ####initCore end
   [junit4]   2> 456030 T2198 oas.SolrTestCaseJ4.setUp ###Starting testMaxTime
   [junit4]   2> ASYNC  NEW_CORE C857 name=collection1 org.apache.solr.core.SolrCore@563d5d
   [junit4]   2> 456034 T2198 C857 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {deleteByQuery=*:* (-1499380830034722816)} 0 4
   [junit4]   2> 456036 T2198 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\core\src\test-files\solr\collection1\'
   [junit4]   2> 456037 T2198 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/core/src/test-files/solr/collection1/lib/classes/' to classloader
   [junit4]   2> 456037 T2198 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/core/src/test-files/solr/collection1/lib/README' to classloader
   [junit4]   2> 456075 T2198 oasc.SolrConfig.refreshRequestParams current version of requestparams : -1
   [junit4]   2> 456094 T2198 oasc.SolrConfig.<init> Using Lucene MatchVersion: 6.0.0
   [junit4]   2> 456114 T2198 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 456114 T2198 oass.IndexSchema.readSchema Reading Solr Schema from C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\core\src\test-files\solr\collection1\conf\schema.xml
   [junit4]   2> 456118 T2198 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 456246 T2198 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 456256 T2198 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 456258 T2198 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 456263 T2198 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 456265 T2198 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 456267 T2198 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 456267 T2198 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 456268 T2198 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 456268 T2198 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 456269 T2198 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 456269 T2198 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 456269 T2198 oasc.CoreContainer.reload Reloading SolrCore 'collection1' using configuration from instancedir C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\core\src\test-files\solr\collection1\
   [junit4]   2> 456269 T2198 c:collection1 oasc.SolrCore.<init> [[collection1] ] Opening new SolrCore at [C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\core\src\test-files\solr\collection1\], dataDir=[C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J1\temp\solr.update.AutoCommitTest 709987D71C07735C-001\init-core-data-001\]
   [junit4]   2> 456270 T2198 c:collection1 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1987ed3
   [junit4]   2> 456270 T2198 c:collection1 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J1\temp\solr.update.AutoCommitTest 709987D71C07735C-001\init-core-data-001\index/
   [junit4]   2> 456276 T2198 c:collection1 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 456277 T2198 c:collection1 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 456277 T2198 c:collection1 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe-allfields"
   [junit4]   2> 456277 T2198 c:collection1 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
   [junit4]   2> 456277 T2198 c:collection1 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 456277 T2198 c:collection1 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 456278 T2198 c:collection1 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "uniq-fields"
   [junit4]   2> 456278 T2198 c:collection1 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
   [junit4]   2> 456278 T2198 c:collection1 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 456278 T2198 c:collection1 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 456279 T2198 c:collection1 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 456279 T2198 c:collection1 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 456280 T2198 c:collection1 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 456281 T2198 c:collection1 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 456283 T2198 c:collection1 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 456284 T2198 c:collection1 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 456288 T2198 c:collection1 oasc.PluginBag.createPlugin requestHandler : 'lazy' created with startup=lazy 
   [junit4]   2> 456291 T2198 c:collection1 oasc.RequestHandlers.initHandlersFromConfig Registered paths: /admin/mbeans,standard,spellCheckCompRH,lazy,/update/json/docs,/admin/luke,spellCheckWithWordbreak_Direct,tvrh,/get,/admin/properties,/update/json,mltrh,/admin/threads,/search-facet-def,/update/csv,/search-facet-invariants,/admin/segments,spellCheckCompRH1,/mlt,/admin/system,/replication,dismax,defaults,/config,/schema,/admin/plugins,/admin/logging,spellCheckWithWordbreak,mock,/admin/ping,/update,/admin/file,/terms,spellCheckCompRH_Direct,/debug/dump
   [junit4]   2> 456292 T2198 c:collection1 oasc.SolrCore.initDeprecatedSupport WARN solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
   [junit4]   2> 456292 T2198 c:collection1 oasc.SolrCore.initStatsCache Using default statsCache cache: org.apache.solr.search.stats.LocalStatsCache
   [junit4]   2> 456294 T2198 c:collection1 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 456294 T2198 c:collection1 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 456295 T2198 c:collection1 oass.SolrIndexSearcher.<init> Opening Searcher@11723b4[collection1] main
   [junit4]   2> 456298 T2198 c:collection1 oasr.RestManager.init Initializing RestManager with initArgs: {storageIO=org.apache.solr.rest.ManagedResourceStorage$InMemoryStorageIO}
   [junit4]   2> 456298 T2198 c:collection1 oasr.ManagedResourceStorage.load Reading _rest_managed.json using InMemoryStorage
   [junit4]   2> 456298 T2198 c:collection1 oasr.RestManager.init Initializing 0 registered ManagedResources
   [junit4]   2> 456298 T2198 c:collection1 oashc.SpellCheckComponent.inform Initializing spell checkers
   [junit4]   2> 456300 T2198 c:collection1 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
   [junit4]   2> 456305 T2198 c:collection1 oash.ReplicationHandler.inform Commits will be reserved for  10000
   [junit4]   2> 456306 T2202 c:collection1 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: default
   [junit4]   2> 456307 T2202 c:collection1 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: direct
   [junit4]   2> 456307 T2202 c:collection1 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: wordbreak
   [junit4]   2> 456307 T2202 c:collection1 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: multipleFields
   [junit4]   2> 456307 T2202 c:collection1 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: jarowinkler
   [junit4]   2> 456308 T2202 c:collection1 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: external
   [junit4]   2> 456308 T2202 c:collection1 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: freq
   [junit4]   2> 456308 T2202 c:collection1 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: fqcn
   [junit4]   2> 456309 T2202 c:collection1 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: perDict
   [junit4]   2> 456317 T2202 c:collection1 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@11723b4[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 456318 T2198 c:collection1 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
   [junit4]   2> 456318 T2198 c:collection1 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
   [junit4]   2> 456318 T2198 c:collection1 oasu.DefaultSolrCoreState.newIndexWriter Closing old IndexWriter... core=collection1
   [junit4]   2> 456319 T2198 c:collection1 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=22, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.37259925831552565]
   [junit4]   2> 456319 T2198 c:collection1 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@1ccc2f3 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6d6f68),segFN=segments_1,generation=1}
   [junit4]   2> 456325 T2198 c:collection1 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 456325 T2198 c:collection1 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
   [junit4]   2> 456326 T2198 c:collection1 oass.SolrIndexSearcher.<init> Opening Searcher@a42e0e[collection1] main
   [junit4]   2> 456326 T2198 c:collection1 oasc.CoreContainer.registerCore replacing core: collection1
   [junit4]   2> 456326 T2198 c:collection1 oasc.SolrCore.close [collection1]  CLOSING SolrCore org.apache.solr.core.SolrCore@563d5d
   [junit4]   2> 456327 T2198 c:collection1 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=0,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=1,errors=0,cumulative_adds=0,cumulative_deletesById=0,cumulative_deletesByQuery=1,cumulative_errors=0,transaction_logs_total_size=0,transaction_logs_total_number=0}
   [junit4]   2> 456330 T2198 c:collection1 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
   [junit4]   2> 456343 T2198 c:collection1 oasup.LogUpdateProcessor.finish [collection1] {add=[529 (1499380830361878528)]} 0 1
   [junit4]   2> ASYNC  NEW_CORE C858 name=collection1 org.apache.solr.core.SolrCore@118b3fd
   [junit4]   2> 456344 T2198 c:collection1 C858 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=id:529&qt=standard&start=0&rows=20&version=2.2} hits=0 status=0 QTime=0 
   [junit4]   2> 456346 T2202 c:collection1 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@a42e0e[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 456603 T2198 c:collection1 oasup.LogUpdateProcessor.finish [collection1] {add=[530 (1499380830635556864)]} 0 261
   [junit4]   2> 456604 T2198 c:collection1 C858 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=id:529&qt=standard&start=0&rows=20&version=2.2} hits=0 status=0 QTime=0 
   [junit4]   2> 456606 T2198 c:collection1 oas.SolrTestCaseJ4.assertQ ERROR REQUEST FAILED: xpath=//result[@numFound=1]
   [junit4]   2> 		xml response was: <?xml version="1.0" encoding="UTF-8"?>
   [junit4]   2> 	<response>
   [junit4]   2> 	<lst name="responseHeader"><int name="status">0</int><int name="QTime">0</int></lst><result name="response" numFound="0" start="0"></result>
   [junit4]   2> 	</response>
   [junit4]   2> 	
   [junit4]   2> 		request was:q=id:529&qt=standard&start=0&rows=20&version=2.2
   [junit4]   2> 456607 T2198 c:collection1 oasc.SolrException.log ERROR REQUEST FAILED: q=id:529&qt=standard&start=0&rows=20&version=2.2:java.lang.RuntimeException: REQUEST FAILED: xpath=//result[@numFound=1]
   [junit4]   2> 		xml response was: <?xml version="1.0" encoding="UTF-8"?>
   [junit4]   2> 	<response>
   [junit4]   2> 	<lst name="responseHeader"><int name="status">0</int><int name="QTime">0</int></lst><result name="response" numFound="0" start="0"></result>
   [junit4]   2> 	</response>
   [junit4]   2> 	
   [junit4]   2> 		request was:q=id:529&qt=standard&start=0&rows=20&version=2.2
   [junit4]   2> 		at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:787)
   [junit4]   2> 		at org.apache.solr.update.AutoCommitTest.testMaxTime(AutoCommitTest.java:237)
   [junit4]   2> 		at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
   [junit4]   2> 		at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
   [junit4]   2> 		at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
   [junit4]   2> 		at java.lang.reflect.Method.invoke(Method.java:497)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1627)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:836)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:872)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:886)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
   [junit4]   2> 		at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
   [junit4]   2> 		at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
   [junit4]   2> 		at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
   [junit4]   2> 		at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
   [junit4]   2> 		at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:798)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:458)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:845)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:747)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:781)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:792)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
   [junit4]   2> 		at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
   [junit4]   2> 		at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
   [junit4]   2> 		at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:54)
   [junit4]   2> 		at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
   [junit4]   2> 		at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
   [junit4]   2> 		at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365)
   [junit4]   2> 		at java.lang.Thread.run(Thread.java:745)
   [junit4]   2> 	
   [junit4]   2> 456608 T2198 c:collection1 oas.SolrTestCaseJ4.tearDown ###Ending testMaxTime
   [junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=AutoCommitTest -Dtests.method=testMaxTime -Dtests.seed=709987D71C07735C -Dtests.slow=true -Dtests.locale=sk_SK -Dtests.timezone=SystemV/MST7MDT -Dtests.asserts=true -Dtests.file.encoding=Cp1252
   [junit4] ERROR   0.59s J1 | AutoCommitTest.testMaxTime <<<
   [junit4]    > Throwable #1: java.lang.RuntimeException: Exception during query
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([709987D71C07735C:EA6DFA35829DEF60]:0)
   [junit4]    > 	at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:794)
   [junit4]    > 	at org.apache.solr.update.AutoCommitTest.testMaxTime(AutoCommitTest.java:237)
   [junit4]    > 	at java.lang.Thread.run(Thread.java:745)
   [junit4]    > Caused by: java.lang.RuntimeException: REQUEST FAILED: xpath=//result[@numFound=1]
   [junit4]    > 	xml response was: <?xml version="1.0" encoding="UTF-8"?>
   [junit4]    > <response>
   [junit4]    > <lst name="responseHeader"><int name="status">0</int><int name="QTime">0</int></lst><result name="response" numFound="0" start="0"></result>
   [junit4]    > </response>
   [junit4]    > 	request was:q=id:529&qt=standard&start=0&rows=20&version=2.2
   [junit4]    > 	at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:787)
   [junit4]    > 	... 40 more
   [junit4]   2> 456616 T2198 c:collection1 oas.SolrTestCaseJ4.setUp ###Starting testCommitWithin
   [junit4]   2> 456626 T2198 c:collection1 C858 oass.SolrIndexSearcher.<init> Opening Searcher@1014d1d[collection1] realtime
   [junit4]   2> 456627 T2198 c:collection1 C858 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {deleteByQuery=*:* (-1499380830652334080)} 0 11
   [junit4]   2> 456627 T2198 c:collection1 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\core\src\test-files\solr\collection1\'
   [junit4]   2> 456628 T2198 c:collection1 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/core/src/test-files/solr/collection1/lib/classes/' to classloader
   [junit4]   2> 456628 T2198 c:collection1 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/core/src/test-files/solr/collection1/lib/README' to classloader
   [junit4]   2> 456671 T2198 c:collection1 oasc.SolrConfig.refreshRequestParams current version of requestparams : -1
   [junit4]   2> 456677 T2198 c:collection1 oasc.SolrConfig.<init> Using Lucene MatchVersion: 6.0.0
   [junit4]   2> 456696 T2198 c:collection1 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 456697 T2198 c:collection1 oass.IndexSchema.readSchema Reading Solr Schema from C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\core\src\test-files\solr\collection1\conf\schema.xml
   [junit4]   2> 456701 T2198 c:collection1 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 456814 T2198 c:collection1 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 456819 T2198 c:collection1 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 456820 T2198 c:collection1 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 456824 T2198 c:collection1 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 456827 T2198 c:collection1 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 456829 T2198 c:collection1 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 456829 T2198 c:collection1 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 456829 T2198 c:collection1 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 456830 T2198 c:collection1 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 456830 T2198 c:collection1 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 456830 T2198 c:collection1 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 456830 T2198 c:collection1 oasc.CoreContainer.reload Reloading SolrCore 'collection1' using configuration from instancedir C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\core\src\test-files\solr\collection1\
   [junit4]   2> 456830 T2198 c:collection1 oasc.SolrCore.<init> [[collection1] ] Opening new SolrCore at [C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\core\src\test-files\solr\collection1\], dataDir=[C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J1\temp\solr.update.AutoCommitTest 709987D71C07735C-001\init-core-data-001\]
   [junit4]   2> 456831 T2198 c:collection1 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1987ed3
   [junit4]   2> 456831 T2198 c:collection1 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J1\temp\solr.update.AutoCommitTest 709987D71C07735C-001\init-core-data-001\index/
   [junit4]   2> 456835 T2198 c:collection1 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 456835 T2198 c:collection1 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 456835 T2198 c:collection1 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe-allfields"
   [junit4]   2> 456836 T2198 c:collection1 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
   [junit4]   2> 456836 T2198 c:collection1 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 456836 T2198 c:collection1 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 456836 T2198 c:collection1 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "uniq-fields"
   [junit4]   2> 456836 T2198 c:collection1 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
   [junit4]   2> 456837 T2198 c:collection1 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 456837 T2198 c:collection1 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 456837 T2198 c:collection1 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 456837 T2198 c:collection1 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 456840 T2198 c:collection1 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 456841 T2198 c:collection1 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 456843 T2198 c:collection1 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 456844 T2198 c:collection1 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 456848 T2198 c:collection1 oasc.PluginBag.createPlugin requestHandler : 'lazy' created with startup=lazy 
   [junit4]   2> 456852 T2198 c:collection1 oasc.RequestHandlers.initHandlersFromConfig Registered paths: /admin/mbeans,standard,spellCheckCompRH,lazy,/update/json/docs,/admin/luke,spellCheckWithWordbreak_Direct,tvrh,/get,/admin/properties,/update/json,mltrh,/admin/threads,/search-facet-def,/update/csv,/search-facet-invariants,/admin/segments,spellCheckCompRH1,/mlt,/admin/system,/replication,dismax,defaults,/config,/schema,/admin/plugins,/admin/logging,spellCheckWithWordbreak,mock,/admin/ping,/update,/admin/file,/terms,spellCheckCompRH_Direct,/debug/dump
   [junit4]   2> 456853 T2198 c:collection1 oasc.SolrCore.initDeprecatedSupport WARN solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
   [junit4]   2> 456854 T2198 c:collection1 oasc.SolrCore.initStatsCache Using default statsCache cache: org.apache.solr.search.stats.LocalStatsCache
   [junit4]   2> 456855 T2198 c:collection1 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 456855 T2198 c:collection1 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 456855 T2198 c:collection1 oass.SolrIndexSearcher.<init> Opening Searcher@136028f[collection1] main
   [junit4]   2> 456856 T2198 c:collection1 oasr.RestManager.init Initializing RestManager with initArgs: {storageIO=org.apache.solr.rest.ManagedResourceStorage$InMemoryStorageIO}
   [junit4]   2> 456856 T2198 c:collection1 oasr.ManagedResourceStorage.load Reading _rest_managed.json using InMemoryStorage
   [junit4]   2> 456856 T2198 c:collection1 oasr.RestManager.init Initializing 0 registered ManagedResources
   [junit4]   2> 456856 T2198 c:collection1 oashc.SpellCheckComponent.inform Initializing spell checkers
   [junit4]   2> 456857 T2198 c:collection1 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
   [junit4]   2> 456863 T2198 c:collection1 oash.ReplicationHandler.inform Commits will be reserved for  10000
   [junit4]   2> 456863 T2198 c:collection1 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
   [junit4]   2> 456864 T2198 c:collection1 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
   [junit4]   2> 456864 T2198 c:collection1 oasu.DefaultSolrCoreState.newIndexWriter Closing old IndexWriter... core=collection1
   [junit4]   2> 456864 T2204 c:collection1 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: default
   [junit4]   2> 456865 T2204 c:collection1 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: direct
   [junit4]   2> 456865 T2204 c:collection1 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: wordbreak
   [junit4]   2> 456865 T2204 c:collection1 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: multipleFields
   [junit4]   2> 456865 T2204 c:collection1 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: jarowinkler
   [junit4]   2> 456866 T2204 c:collection1 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: external
   [junit4]   2> 456866 T2204 c:collection1 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: freq
   [junit4]   2> 456866 T2204 c:collection1 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: fqcn
   [junit4]   2> 456867 T2204 c:collection1 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: perDict
   [junit4]   2> 456867 T2198 c:collection1 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@1ccc2f3 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6d6f68),segFN=segments_1,generation=1}
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@1ccc2f3 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6d6f68),segFN=segments_2,generation=2}
   [junit4]   2> 456867 T2198 c:collection1 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
   [junit4]   2> 456868 T2204 c:collection1 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@136028f[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 456869 T2198 c:collection1 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=35, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.7715990416153077]
   [junit4]   2> 456869 T2198 c:collection1 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@1ccc2f3 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6d6f68),segFN=segments_2,generation=2}
   [junit4]   2> 456869 T2198 c:collection1 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
   [junit4]   2> 456870 T2198 c:collection1 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
   [junit4]   2> 456870 T2198 c:collection1 oass.SolrIndexSearcher.<init> Opening Searcher@990b77[collection1] main
   [junit4]   2> 456871 T2204 c:collection1 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@990b77[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 456871 T2198 c:collection1 oasc.CoreContainer.registerCore replacing core: collection1
   [junit4]   2> 456871 T2198 c:collection1 oasc.SolrCore.close [collection1]  CLOSING SolrCore org.apache.solr.core.SolrCore@118b3fd
   [junit4]   2> 456871 T2198 c:collection1 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=0,autocommits=0,soft autocommit maxTime=1000ms,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=2,adds=2,deletesById=0,deletesByQuery=1,errors=0,cumulative_adds=2,cumulative_deletesById=0,cumulative_deletesByQuery=1,cumulative_errors=0,transaction_logs_total_size=0,transaction_logs_total_number=0}
   [junit4]   2> 456876 T2198 c:collection1 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
   [junit4]   2> 456885 T2198 c:collection1 oasup.LogUpdateProcessor.finish [collection1] {add=[529 (1499380830930206720)]} 0 1
   [junit4]   2> ASYNC  NEW_CORE C859 name=collection1 org.apache.solr.core.SolrCore@6ca1a3
   [junit4]   2> 456886 T2198 c:collection1 C859 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=id:529&qt=standard&start=0&rows=20&version=2.2} hits=0 status=0 QTime=1 
   [junit4]   2> 461026 T2205 c:collection1 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
   [junit4]   2> 461034 T2205 c:collection1 oass.SolrIndexSearcher.<init> Opening Searcher@df6baf[collection1] main
   [junit4]   2> 461035 T2205 c:collection1 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 461037 T2204 c:collection1 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@df6baf[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_1(6.0.0):c1)))}
   [junit4]   2> 461205 T2198 c:collection1 oasup.LogUpdateProcessor.finish [collection1] {add=[530 (1499380835460055040)]} 0 4321
   [junit4]   2> 461207 T2198 c:collection1 C859 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=id:530&qt=standard&start=0&rows=20&version=2.2} hits=0 status=0 QTime=0 
   [junit4]   2> 461209 T2198 c:collection1 oasup.LogUpdateProcessor.finish [collection1] {delete=[529 (-1499380835465297920)]} 0 4325
   [junit4]   2> 461209 T2198 c:collection1 C859 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=id:529&qt=standard&start=0&rows=20&version=2.2} hits=1 status=0 QTime=0 
   [junit4]   2> 462324 T2205 c:collection1 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
   [junit4]   2> 462334 T2205 c:collection1 oass.SolrIndexSearcher.<init> Opening Searcher@17876fb[collection1] main
   [junit4]   2> 462335 T2205 c:collection1 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 462336 T2204 c:collection1 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@17876fb[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_2(6.0.0):c1)))}
   [junit4]   2> ASYNC  NEW_CORE C860 name=collection1 org.apache.solr.core.SolrCore@6ca1a3
   [junit4]   2> 462617 T2198 c:collection1 C860 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=id:529&qt=standard&start=0&rows=20&version=2.2} hits=0 status=0 QTime=0 
   [junit4]   2> 462619 T2198 c:collection1 C860 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=id:530&qt=standard&start=0&rows=20&version=2.2} hits=1 status=0 QTime=0 
   [junit4]   2> 462620 T2198 c:collection1 oasup.LogUpdateProcessor.finish [collection1] {add=[500 (1499380836943790080)]} 0 5736
   [junit4]   2> 462620 T2198 c:collection1 oasup.LogUpdateProcessor.finish [collection1] {add=[500 (1499380836944838656)]} 0 5736
   [junit4]   2> 462621 T2198 c:collection1 oasup.LogUpdateProcessor.finish [collection1] {add=[500 (1499380836945887232)]} 0 5737
   [junit4]   2> 462621 T2198 c:collection1 oasup.LogUpdateProcessor.finish [collection1] {add=[500 (1499380836945887233)]} 0 5737
   [junit4]   2> 462621 T2198 c:collection1 oasup.LogUpdateProcessor.finish [collection1] {add=[500 (1499380836945887234)]} 0 5737
   [junit4]   2> 462622 T2198 c:collection1 oasup.LogUpdateProcessor.finish [collection1] {add=[500 (1499380836946935808)]} 0 5738
   [junit4]   2> 462622 T2198 c:collection1 oasup.LogUpdateProcessor.finish [collection1] {add=[500 (1499380836946935809)]} 0 5738
   [junit4]   2> 462622 T2198 c:collection1 oasup.LogUpdateProcessor.finish [collection1] {add=[500 (1499380836946935810)]} 0 5738
   [junit4]   2> 462623 T2198 c:collection1 oasup.LogUpdateProcessor.finish [collection1] {add=[500 (1499380836947984384)]} 0 5739
   [junit4]   2> 462623 T2198 c:collection1 oasup.LogUpdateProcessor.finish [collection1] {add=[500 (1499380836947984385)]} 0 5739
   [junit4]   2> 462623 T2198 c:collection1 C860 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=id:500&qt=standard&start=0&rows=20&version=2.2} hits=0 status=0 QTime=0 
   [junit4]   2> 462625 T2198 c:collection1 oasup.LogUpdateProcessor.finish [collection1] {delete=[530 (-1499380836950081536)]} 0 5741
   [junit4]   2> 462625 T2198 c:collection1 oasup.LogUpdateProcessor.finish [collection1] {delete=[530 (-1499380836950081537)]} 0 5741
   [junit4]   2> 462625 T2198 c:collection1 oasup.LogUpdateProcessor.finish [collection1] {delete=[530 (-1499380836950081538)]} 0 5741
   [junit4]   2> 462626 T2198 c:collection1 oasup.LogUpdateProcessor.finish [collection1] {delete=[530 (-1499380836951130112)]} 0 5742
   [junit4]   2> 462626 T2198 c:collection1 oasup.LogUpdateProcessor.finish [collection1] {delete=[530 (-1499380836951130113)]} 0 5742
   [junit4]   2> 462627 T2198 c:collection1 oasup.LogUpdateProcessor.finish [collection1] {delete=[530 (-1499380836952178688)]} 0 5743
   [junit4]   2> 462627 T2198 c:collection1 oasup.LogUpdateProcessor.finish [collection1] {delete=[530 (-1499380836952178689)]} 0 5743
   [junit4]   2> 462628 T2198 c:collection1 oasup.LogUpdateProcessor.finish [collection1] {delete=[530 (-1499380836953227264)]} 0 5744
   [junit4]   2> 462628 T2198 c:collection1 oasup.LogUpdateProcessor.finish [collection1] {delete=[530 (-1499380836953227265)]} 0 5744
   [junit4]   2> 462628 T2198 c:collection1 oasup.LogUpdateProcessor.finish [collection1] {delete=[530 (-1499380836953227266)]} 0 5744
   [junit4]   2> 462628 T2198 c:collection1 C860 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=id:530&qt=standard&start=0&rows=20&version=2.2} hits=1 status=0 QTime=0 
   [junit4]   2> 463764 T2205 c:collection1 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
   [junit4]   2> 463768 T2205 c:collection1 oass.SolrIndexSearcher.<init> Opening Searcher@8907d8[collection1] main
   [junit4]   2> 463768 T2205 c:collection1 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 463769 T2204 c:collection1 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@8907d8[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_3(6.0.0):c10/9:delGen=1)))}
   [junit4]   2> 463773 T2198 c:collection1 C860 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=id:500&qt=standard&start=0&rows=20&version=2.2} hits=1 status=0 QTime=0 
   [junit4]   2> 463775 T2198 c:collection1 C860 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=id:530&qt=standard&start=0&rows=20&version=2.2} hits=0 status=0 QTime=1 
   [junit4]   2> 463775 T2198 c:collection1 oas.SolrTestCaseJ4.tearDown ###Ending testCommitWithin
   [junit4]   2> 463780 T2198 c:collection1 oas.SolrTestCaseJ4.setUp ###Starting testMaxDocs
   [junit4]   2> 463785 T2198 c:collection1 C860 oass.SolrIndexSearcher.<init> Opening Searcher@15334c0[collection1] realtime
   [junit4]   2> 463785 T2198 c:collection1 C860 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {deleteByQuery=*:* (-1499380838163283968)} 0 5
   [junit4]   2> 463785 T2198 c:collection1 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\core\src\test-files\solr\collection1\'
   [junit4]   2> 463786 T2198 c:collection1 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/core/src/test-files/solr/collection1/lib/classes/' to classloader
   [junit4]   2> 463786 T2198 c:collection1 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/core/src/test-files/solr/collection1/lib/README' to classloader
   [junit4]   2> 463810 T2198 c:collection1 oasc.SolrConfig.refreshRequestParams current version of requestparams : -1
   [junit4]   2> 463823 T2198 c:collection1 oasc.SolrConfig.<init> Using Lucene MatchVersion: 6.0.0
   [junit4]   2> 463844 T2198 c:collection1 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 463845 T2198 c:collection1 oass.IndexSchema.readSchema Reading Solr Schema from C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\core\src\test-files\solr\collection1\conf\schema.xml
   [junit4]   2> 463849 T2198 c:collection1 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 463967 T2198 c:collection1 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 463976 T2198 c:collection1 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 463976 T2198 c:collection1 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 463982 T2198 c:collection1 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 463985 T2198 c:collection1 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 463986 T2198 c:collection1 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 463987 T2198 c:collection1 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 463987 T2198 c:collection1 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 463987 T2198 c:collection1 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 463988 T2198 c:collection1 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 463988 T2198 c:collection1 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 463988 T2198 c:collection1 oasc.CoreContainer.reload Reloading SolrCore 'collection1' using configuration from instancedir C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\core\src\test-files\solr\collection1\
   [junit4]   2> 463988 T2198 c:collection1 oasc.SolrCore.<init> [[collection1] ] Opening new SolrCore at [C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\core\src\test-files\solr\collection1\], dataDir=[C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J1\temp\solr.update.AutoCommitTest 709987D71C07735C-001\init-core-data-001\]
   [junit4]   2> 463988 T2198 c:collection1 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1987ed3
   [junit4]   2> 463990 T2198 c:collection1 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J1\temp\solr.update.AutoCommitTest 709987D71C07735C-001\init-core-data-001\index/
   [junit4]   2> 463993 T2198 c:collection1 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 463994 T2198 c:collection1 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 463994 T2198 c:collection1 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe-allfields"
   [junit4]   2> 463994 T2198 c:collection1 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
   [junit4]   2> 463994 T2198 c:collection1 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 463995 T2198 c:collection1 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 463995 T2198 c:collection1 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "uniq-fields"
   [junit4]   2> 463995 T2198 c:collection1 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
   [junit4]   2> 463996 T2198 c:collection1 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 463996 T2198 c:collection1 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 463996 T2198 c:collection1 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 463996 T2198 c:collection1 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 463998 T2198 c:collection1 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 464000 T2198 c:collection1 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 464001 T2198 c:collection1 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 464002 T2198 c:collection1 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 464007 T2198 c:collection1 oasc.PluginBag.createPlugin requestHandler : 'lazy' created with startup=lazy 
   [junit4]   2> 464011 T2198 c:collection1 oasc.RequestHandlers.initHandlersFromConfig Registered paths: /admin/mbeans,standard,spellCheckCompRH,lazy,/update/json/docs,/admin/luke,spellCheckWithWordbreak_Direct,tvrh,/get,/admin/properties,/update/json,mltrh,/admin/threads,/search-facet-def,/update/csv,/search-facet-invariants,/admin/segments,spellCheckCompRH1,/mlt,/admin/system,/replication,dismax,defaults,/config,/schema,/admin/plugins,/admin/logging,spellCheckWithWordbreak,mock,/admin/ping,/update,/admin/file,/terms,spellCheckCompRH_Direct,/debug/dump
   [junit4]   2> 464011 T2198 c:collection1 oasc.SolrCore.initDeprecatedSupport WARN solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
   [junit4]   2> 464012 T2198 c:collection1 oasc.SolrCore.initStatsCache Using default statsCache cache: org.apache.solr.search.stats.LocalStatsCache
   [junit4]   2> 464012 T2198 c:collection1 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 464013 T2198 c:collection1 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 464013 T2198 c:collection1 oass.SolrIndexSearcher.<init> Opening Searcher@555da2[collection1] main
   [junit4]   2> 464013 T2198 c:collection1 oasr.RestManager.init Initializing RestManager with initArgs: {storageIO=org.apache.solr.rest.ManagedResourceStorage$InMemoryStorageIO}
   [junit4]   2> 464013 T2198 c:collection1 oasr.ManagedResourceStorage.load Reading _rest_managed.json using InMemoryStorage
   [junit4]   2> 464013 T2198 c:collection1 oasr.RestManager.init Initializing 0 registered ManagedResources
   [junit4]   2> 464015 T2198 c:collection1 oashc.SpellCheckComponent.inform Initializing spell checkers
   [junit4]   2> 464016 T2198 c:collection1 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
   [junit4]   2> 464021 T2198 c:collection1 oash.ReplicationHandler.inform Commits will be reserved for  10000
   [junit4]   2> 464021 T2206 c:collection1 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: default
   [junit4]   2> 464022 T2206 c:collection1 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: direct
   [junit4]   2> 464022 T2198 c:collection1 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
   [junit4]   2> 464022 T2198 c:collection1 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
   [junit4]   2> 464022 T2198 c:collection1 oasu.DefaultSolrCoreState.newIndexWriter Closing old IndexWriter... core=collection1
   [junit4]   2> 464022 T2206 c:collection1 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: wordbreak
   [junit4]   2> 464022 T2206 c:collection1 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: multipleFields
   [junit4]   2> 464022 T2198 c:collection1 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@1ccc2f3 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6d6f68),segFN=segments_2,generation=2}
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@1ccc2f3 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6d6f68),segFN=segments_3,generation=3}
   [junit4]   2> 464023 T2206 c:collection1 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: jarowinkler
   [junit4]   2> 464023 T2206 c:collection1 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: external
   [junit4]   2> 464024 T2206 c:collection1 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: freq
   [junit4]   2> 464024 T2206 c:collection1 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: fqcn
   [junit4]   2> 464025 T2206 c:collection1 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: perDict
   [junit4]   2> 464025 T2206 c:collection1 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@555da2[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 464023 T2198 c:collection1 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
   [junit4]   2> 464026 T2198 c:collection1 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=34, maxMergeAtOnceExplicit=42, maxMergedSegmentMB=97.654296875, floorSegmentMB=0.4736328125, forceMergeDeletesPctAllowed=3.704067440971076, segmentsPerTier=16.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
   [junit4]   2> 464029 T2198 c:collection1 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@1ccc2f3 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6d6f68),segFN=segments_3,generation=3}
   [junit4]   2> 464029 T2198 c:collection1 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
   [junit4]   2> 464030 T2198 c:collection1 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
   [junit4]   2> 464030 T2198 c:collection1 oass.SolrIndexSearcher.<init> Opening Searcher@1862d00[collection1] main
   [junit4]   2> 464031 T2198 c:collection1 oasc.CoreContainer.registerCore replacing core: collection1
   [junit4]   2> 464031 T2198 c:collection1 oasc.SolrCore.close [collection1]  CLOSING SolrCore org.apache.solr.core.SolrCore@6ca1a3
   [junit4]   2> 464031 T2206 c:collection1 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1862d00[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 464031 T2198 c:collection1 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=3,autocommits=0,soft autocommits=3,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=12,adds=0,deletesById=0,deletesByQuery=1,errors=0,cumulative_adds=12,cumulative_deletesById=11,cumulative_deletesByQuery=1,cumulative_errors=0,transaction_logs_total_size=0,transaction_logs_total_number=0}
   [junit4]   2> 464032 T2198 c:collection1 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
   [junit4]   2> 464047 T2198 c:collection1 oasup.LogUpdateProcessor.finish [collection1] {add=[0 (1499380838441156608)]} 0 0
   [junit4]   2> 464049 T2198 c:collection1 oasup.LogUpdateProcessor.finish [collection1] {add=[1 (1499380838443253760)]} 0 2
   [junit4]   2> 464049 T2198 c:collection1 oasup.LogUpdateProcessor.finish [collection1] {add=[2 (1499380838443253761)]} 0 2
   [junit4]   2> 464050 T2198 c:collection1 oasup.LogUpdateProcessor.finish [collection1] {add=[3 (1499380838443253762)]} 0 3
   [junit4]   2> 464050 T2198 c:collection1 oasup.LogUpdateProcessor.finish [collection1] {add=[4 (1499380838444302336)]} 0 3
   [junit4]   2> 464050 T2198 c:collection1 oasup.LogUpdateProcessor.finish [collection1] {add=[5 (1499380838444302337)]} 0 3
   [junit4]   2> 464051 T2198 c:collection1 oasup.LogUpdateProcessor.finish [collection1] {add=[6 (1499380838445350912)]} 0 4
   [junit4]   2> 464051 T2198 c:collection1 oasup.LogUpdateProcessor.finish [collection1] {add=[7 (1499380838445350913)]} 0 4
   [junit4]   2> 464052 T2198 c:collection1 oasup.LogUpdateProcessor.finish [collection1] {add=[8 (1499380838446399488)]} 0 5
   [junit4]   2> 464052 T2198 c:collection1 oasup.LogUpdateProcessor.finish [collection1] {add=[9 (1499380838446399489)]} 0 5
   [junit4]   2> 464053 T2198 c:collection1 oasup.LogUpdateProcessor.finish [collection1] {add=[10 (1499380838447448064)]} 0 6
   [junit4]   2> 464053 T2198 c:collection1 oasup.LogUpdateProcessor.finish [collection1] {add=[11 (1499380838447448065)]} 0 6
   [junit4]   2> 464054 T2198 c:collection1 oasup.LogUpdateProcessor.finish [collection1] {add=[12 (1499380838448496640)]} 0 7
   [junit4]   2> 464054 T2198 c:collection1 oasup.LogUpdateProcessor.finish [collection1] {add=[13 (1499380838448496641)]} 0 7
   [junit4]   2> ASYNC  NEW_CORE C861 name=collection1 org.apache.solr.core.SolrCore@1ea098b
   [junit4]   2> 464054 T2198 c:collection1 C861 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=id:1&qt=standard&start=0&rows=20&version=2.2} hits=0 status=0 QTime=0 
   [junit4]   2> 464055 T2198 c:collection1 oasup.LogUpdateProcessor.finish [collection1] {add=[14 (1499380838449545216)]} 0 8
   [junit4]   2> 464057 T2207 c:collection1 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
   [junit4]   2> 464067 T2207 c:collection1 oass.SolrIndexSearcher.<init> Opening Searcher@1426627[collection1] main
   [junit4]   2> 464067 T2207 c:collection1 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 464069 T2206 c:collection1 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1426627[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_4(6.0.0):c15)))}
   [junit4]   2> 464340 T2198 c:collection1 oasup.LogUpdateProcessor.finish [collection1] {add=[15 (1499380838748389376)]} 0 293
   [junit4]   2> 464341 T2198 c:collection1 C861 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=id:14&qt=standard&start=0&rows=20&version=2.2} hits=1 status=0 QTime=0 
   [junit4]   2> 464342 T2198 c:collection1 C861 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=id:15&qt=standard&start=0&rows=20&version=2.2} hits=0 status=0 QTime=0 
   [junit4]   2> 464342 T2198 c:collection1 oas.SolrTestCaseJ4.tearDown ###Ending testMaxDocs
   [junit4]   2> 464343 T2198 c:collection1 oas.SolrTestCaseJ4.deleteCore ###deleteCore
   [junit4]   2> 464344 T2198 c:collection1 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=17608848
   [junit4]   2> 464344 T2198 c:collection1 oasc.SolrCore.close [collection1]  CLOSING SolrCore org.apache.solr.core.SolrCore@1ea098b
   [junit4]   2> 464344 T2198 c:collection1 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=1,autocommits=0,soft autocommit maxDocs=14,soft autocommits=1,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=16,adds=1,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=16,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0,transaction_logs_total_size=0,transaction_logs_total_number=0}
   [junit4]   2> 464346 T2198 c:collection1 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
   [junit4]   2> 464346 T2198 c:collection1 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
   [junit4]   2> 464346 T2198 c:collection1 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
   [junit4]   2> 464346 T2198 c:collection1 C861 oasu.DirectUpdateHandler2.closeWriter Committing on IndexWriter close.
   [junit4]   2> 464351 T2198 c:collection1 C861 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@1ccc2f3 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6d6f68),segFN=segments_3,generation=3}
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@1ccc2f3 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6d6f68),segFN=segments_4,generation=4}
   [junit4]   2> 464351 T2198 c:collection1 C861 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 4
   [junit4]   2> 464352 T2198 c:collection1 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
   [junit4]   2> 464368 T2198 c:collection1 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
   [junit4]   2> 464368 T2198 c:collection1 oasc.CachingDirectoryFactory.closeCacheValue looking to close C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J1\temp\solr.update.AutoCommitTest 709987D71C07735C-001\init-core-data-001\index [CachedDir<<refCount=0;path=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J1\temp\solr.update.AutoCommitTest 709987D71C07735C-001\init-core-data-001\index;done=false>>]
   [junit4]   2> 464369 T2198 c:collection1 oasc.CachingDirectoryFactory.close Closing directory: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J1\temp\solr.update.AutoCommitTest 709987D71C07735C-001\init-core-data-001\index
   [junit4]   2> 464369 T2198 c:collection1 oasc.CachingDirectoryFactory.closeCacheValue looking to close C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J1\temp\solr.update.AutoCommitTest 709987D71C07735C-001\init-core-data-001\ [CachedDir<<refCount=0;path=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J1\temp\solr.update.AutoCommitTest 709987D71C07735C-001\init-core-data-001\;done=false>>]
   [junit4]   2> 464369 T2198 c:collection1 oasc.CachingDirectoryFactory.close Closing directory: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J1\temp\solr.update.AutoCommitTest 709987D71C07735C-001\init-core-data-001\
   [junit4]   2> NOTE: leaving temporary files on disk at: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J1\temp\solr.update.AutoCommitTest 709987D71C07735C-001
   [junit4]   2> NOTE: test params are: codec=Asserting(Lucene50): {range_facet_l_dv=PostingsFormat(name=LuceneVarGapFixedInterval), _version_=BlockTreeOrds(blocksize=128), field_t=PostingsFormat(name=LuceneVarGapFixedInterval), multiDefault=PostingsFormat(name=Memory doPackFST= true), subject=PostingsFormat(name=Memory doPackFST= true), intDefault=BlockTreeOrds(blocksize=128), id=PostingsFormat(name=LuceneVarGapFixedInterval), range_facet_i_dv=PostingsFormat(name=Memory doPackFST= true), text=FSTOrd50, range_facet_l=PostingsFormat(name=Memory doPackFST= true), timestamp=PostingsFormat(name=Memory doPackFST= true)}, docValues:{range_facet_l_dv=DocValuesFormat(name=Memory), range_facet_i_dv=DocValuesFormat(name=Lucene50), timestamp=DocValuesFormat(name=Lucene50)}, sim=DefaultSimilarity, locale=sk_SK, timezone=SystemV/MST7MDT
   [junit4]   2> NOTE: Windows 7 6.1 x86/Oracle Corporation 1.8.0_40 (32-bit)/cpus=3,threads=1,free=65279984,total=108138496
   [junit4]   2> NOTE: All tests run in this JVM: [TestCollapseQParserPlugin, ResourceLoaderTest, BasicZkTest, IndexSchemaTest, BufferStoreTest, UpdateRequestProcessorFactoryTest, TestCursorMarkWithoutUniqueKey, DebugComponentTest, TestSolrDeletionPolicy1, QueryParsingTest, PreAnalyzedUpdateProcessorTest, TestMergePolicyConfig, ConnectionManagerTest, TestSimpleQParserPlugin, TestRangeQuery, TestLMJelinekMercerSimilarityFactory, BinaryUpdateRequestHandlerTest, OverseerStatusTest, BasicDistributedZk2Test, TestDocSet, ShardSplitTest, XsltUpdateRequestHandlerTest, AddBlockUpdateTest, TestMissingGroups, TestEmbeddedSolrServerConstructors, TestSchemaSimilarityResource, TestCodecSupport, DistributedTermsComponentTest, TestSystemIdResolver, TestRecovery, CollectionsAPIDistributedZkTest, TestJsonFacets, SuggesterTSTTest, TestRequestStatusCollectionAPI, TestManagedStopFilterFactory, DirectSolrSpellCheckerTest, AutoCommitTest]
   [junit4] Completed [98/484] on J1 in 9.00s, 3 tests, 1 error <<< FAILURES!

[...truncated 1215 lines...]
BUILD FAILED
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\build.xml:526: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\build.xml:474: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\build.xml:61: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\extra-targets.xml:39: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build.xml:229: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\common-build.xml:512: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\common-build.xml:1415: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\common-build.xml:973: There were test failures: 484 suites, 1944 tests, 1 error, 63 ignored (34 assumptions)

Total time: 60 minutes 37 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
Recording test results
Email was triggered for: Failure - Any
Sending email for trigger: Failure - Any