You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2013/10/08 22:57:21 UTC
[JENKINS] Lucene-Solr-4.x-Windows (32bit/jdk1.6.0_45) - Build #
3262 - Failure!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-Windows/3262/
Java: 32bit/jdk1.6.0_45 -client -XX:+UseConcMarkSweepGC
1 tests failed.
REGRESSION: org.apache.solr.cloud.ShardSplitTest.testDistribSearch
Error Message:
Wrong doc count on shard1_1 expected:<51> but was:<33>
Stack Trace:
java.lang.AssertionError: Wrong doc count on shard1_1 expected:<51> but was:<33>
at __randomizedtesting.SeedInfo.seed([363EABD33CDF2EA2:B7D825CB4B804E9E]: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.cloud.ShardSplitTest.checkDocCountsAndShardStates(ShardSplitTest.java:327)
at org.apache.solr.cloud.ShardSplitTest.splitByUniqueKeyTest(ShardSplitTest.java:201)
at org.apache.solr.cloud.ShardSplitTest.doTest(ShardSplitTest.java:111)
at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:835)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at java.lang.Thread.run(Thread.java:662)
Build Log:
[...truncated 9138 lines...]
[junit4] Suite: org.apache.solr.cloud.ShardSplitTest
[junit4] 2> 39871 T104 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /exx/
[junit4] 2> 39879 T104 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4] 2> Creating dataDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solrtest-ShardSplitTest-1381262196450
[junit4] 2> 39889 T104 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 39895 T105 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 40110 T104 oasc.ZkTestServer.run start zk server on port:57779
[junit4] 2> 40428 T104 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 40519 T111 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1cd1d94 name:ZooKeeperConnection Watcher:127.0.0.1:57779 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 40520 T104 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 40525 T104 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 40619 T104 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 40624 T113 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@79f5eb name:ZooKeeperConnection Watcher:127.0.0.1:57779/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 40625 T104 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 40643 T104 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4] 2> 40654 T104 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4] 2> 40663 T104 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4] 2> 40670 T104 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4] 2> 40681 T104 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\collection1\conf\solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4] 2> 40682 T104 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4] 2> 40697 T104 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\collection1\conf\schema15.xml to /configs/conf1/schema.xml
[junit4] 2> 40699 T104 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4] 2> 40708 T104 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\collection1\conf\solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 40709 T104 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 40722 T104 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\collection1\conf\stopwords.txt to /configs/conf1/stopwords.txt
[junit4] 2> 40722 T104 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4] 2> 40732 T104 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\collection1\conf\protwords.txt to /configs/conf1/protwords.txt
[junit4] 2> 40733 T104 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4] 2> 40741 T104 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\collection1\conf\currency.xml to /configs/conf1/currency.xml
[junit4] 2> 40742 T104 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4] 2> 40753 T104 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\collection1\conf\open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4] 2> 40754 T104 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4] 2> 40764 T104 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\collection1\conf\mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 40764 T104 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 40773 T104 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\collection1\conf\old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4] 2> 40775 T104 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4] 2> 40783 T104 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\collection1\conf\synonyms.txt to /configs/conf1/synonyms.txt
[junit4] 2> 40784 T104 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4] 2> 41743 T104 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 42021 T104 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:57786
[junit4] 2> 42070 T104 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 42070 T104 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 42071 T104 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-controljetty-1381262197366
[junit4] 2> 42071 T104 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-controljetty-1381262197366\'
[junit4] 2> 42108 T104 oasc.ConfigSolr.fromFile Loading container configuration from C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-controljetty-1381262197366\solr.xml
[junit4] 2> 42215 T104 oasc.CoreContainer.<init> New CoreContainer 17807910
[junit4] 2> 42215 T104 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-controljetty-1381262197366\]
[junit4] 2> 42277 T104 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 42277 T104 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 42278 T104 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 42278 T104 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 42278 T104 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 42279 T104 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 42279 T104 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 42280 T104 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 42280 T104 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 42280 T104 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4] 2> 42286 T104 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 42287 T104 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 42287 T104 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:57779/solr
[junit4] 2> 42309 T104 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 42311 T104 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 42321 T125 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@99e017 name:ZooKeeperConnection Watcher:127.0.0.1:57779 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 42323 T104 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 42333 T104 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4] 2> 42339 T104 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 42344 T127 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1acdfc3 name:ZooKeeperConnection Watcher:127.0.0.1:57779/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 42344 T104 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 42357 T104 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 42383 T104 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 42406 T104 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 42413 T104 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:57786_exx
[junit4] 2> 42420 T104 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:57786_exx
[junit4] 2> 42434 T104 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 42471 T104 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 42479 T104 oasc.Overseer.start Overseer (id=90522399330664451-127.0.0.1:57786_exx-n_0000000000) starting
[junit4] 2> 42506 T104 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 42535 T129 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 42536 T104 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 42555 T104 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 42564 T104 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 42591 T128 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 42609 T130 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 42610 T130 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 42614 T130 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 44214 T128 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 44225 T128 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:57786/exx",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:57786_exx",
[junit4] 2> "shard":null,
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "collection":"control_collection",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 44226 T128 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1]
[junit4] 2> 44256 T128 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 44287 T127 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> 44749 T130 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 44749 T130 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-controljetty-1381262197366\collection1
[junit4] 2> 44750 T130 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4] 2> 44753 T130 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 44753 T130 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4] 2> 44758 T130 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-controljetty-1381262197366\collection1\'
[junit4] 2> 44766 T130 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-controljetty-1381262197366/collection1/lib/classes/' to classloader
[junit4] 2> 44767 T130 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-controljetty-1381262197366/collection1/lib/README' to classloader
[junit4] 2> 44906 T130 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_46
[junit4] 2> 45002 T130 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 45007 T130 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 45023 T130 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 45921 T130 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 45927 T130 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 45930 T130 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 45945 T130 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 46044 T130 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 46045 T130 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-controljetty-1381262197366\collection1\, dataDir=.\org.apache.solr.cloud.ShardSplitTest-1381262196449/control/data\
[junit4] 2> 46046 T130 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@857066
[junit4] 2> 46050 T130 oasc.CachingDirectoryFactory.get return new directory for .\org.apache.solr.cloud.ShardSplitTest-1381262196449/control/data\
[junit4] 2> 46050 T130 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.ShardSplitTest-1381262196449/control/data\index/
[junit4] 2> 46050 T130 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '.\org.apache.solr.cloud.ShardSplitTest-1381262196449\control\data\index' doesn't exist. Creating new index...
[junit4] 2> 46050 T130 oasc.CachingDirectoryFactory.get return new directory for .\org.apache.solr.cloud.ShardSplitTest-1381262196449/control/data\index
[junit4] 2> 46051 T130 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=30, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
[junit4] 2> 46052 T130 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@1bed674 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@123fab3),segFN=segments_1,generation=1}
[junit4] 2> 46052 T130 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 46057 T130 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 46119 T130 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 46120 T130 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 46120 T130 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 46120 T130 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 46121 T130 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 46121 T130 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 46122 T130 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 46122 T130 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 46123 T130 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 46124 T130 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 46124 T130 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 46124 T130 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 46125 T130 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 46125 T130 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 46133 T130 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 46144 T130 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 46145 T130 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 46146 T130 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=10, maxMergeAtOnceExplicit=12, maxMergedSegmentMB=87.94140625, floorSegmentMB=0.33984375, forceMergeDeletesPctAllowed=8.442630454142778, segmentsPerTier=17.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.24392947557826317
[junit4] 2> 46146 T130 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@1bed674 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@123fab3),segFN=segments_1,generation=1}
[junit4] 2> 46147 T130 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 46147 T130 oass.SolrIndexSearcher.<init> Opening Searcher@727896 main
[junit4] 2> 46159 T130 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 46159 T130 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:57786/exx collection:control_collection shard:shard1
[junit4] 2> 46163 T131 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@727896 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 46174 T130 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=15000&socketTimeout=30000&retry=false
[junit4] 2> 46180 T130 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4] 2> 46214 T130 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 46223 T130 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 46224 T130 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 46224 T130 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:57786/exx/collection1/
[junit4] 2> 46225 T130 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 46225 T130 oasc.SyncStrategy.syncToMe http://127.0.0.1:57786/exx/collection1/ has no replicas
[junit4] 2> 46225 T130 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:57786/exx/collection1/ shard1
[junit4] 2> 46225 T130 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4] 2> 47517 T128 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 47543 T127 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> 47606 T130 oasc.ZkController.register We are http://127.0.0.1:57786/exx/collection1/ and leader is http://127.0.0.1:57786/exx/collection1/
[junit4] 2> 47606 T130 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:57786/exx
[junit4] 2> 47606 T130 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 47607 T130 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 47607 T130 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 47612 T130 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 47614 T104 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0
[junit4] 2> 47615 T104 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 47685 T104 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 47710 T104 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4] 2> 47717 T104 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 47722 T134 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@123cf50 name:ZooKeeperConnection Watcher:127.0.0.1:57779/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 47723 T104 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 47728 T104 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 47739 T104 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4] 2> 48222 T104 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 48226 T104 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:57798
[junit4] 2> 48227 T104 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 48227 T104 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 48228 T104 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: .\org.apache.solr.cloud.ShardSplitTest-jetty1-1381262204309
[junit4] 2> 48228 T104 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '.\org.apache.solr.cloud.ShardSplitTest-jetty1-1381262204309\'
[junit4] 2> 48260 T104 oasc.ConfigSolr.fromFile Loading container configuration from C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-jetty1-1381262204309\solr.xml
[junit4] 2> 48368 T104 oasc.CoreContainer.<init> New CoreContainer 9043557
[junit4] 2> 48369 T104 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=.\org.apache.solr.cloud.ShardSplitTest-jetty1-1381262204309\]
[junit4] 2> 48371 T104 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 48372 T104 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 48372 T104 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 48372 T104 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 48373 T104 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 48373 T104 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 48373 T104 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 48374 T104 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 48374 T104 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 48375 T104 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4] 2> 48379 T104 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 48380 T104 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 48380 T104 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:57779/solr
[junit4] 2> 48380 T104 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 48382 T104 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 48391 T145 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@19cd6b6 name:ZooKeeperConnection Watcher:127.0.0.1:57779 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 48391 T104 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 48396 T104 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4] 2> 48396 T106 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x14199a480520005, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:220)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:662)
[junit4] 2>
[junit4] 2> 48400 T104 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 48404 T147 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6d3ca2 name:ZooKeeperConnection Watcher:127.0.0.1:57779/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 48404 T104 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 48416 T104 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 49163 T128 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 49164 T128 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:57786/exx",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:57786_exx",
[junit4] 2> "shard":"shard1",
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "collection":"control_collection",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 49179 T127 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> 49180 T147 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> 49181 T134 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> 49491 T104 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:57798_exx
[junit4] 2> 49495 T104 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:57798_exx
[junit4] 2> 49502 T147 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 49504 T127 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 49505 T134 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 49524 T148 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 49524 T148 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 49527 T148 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 50710 T128 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 50711 T128 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:57798/exx",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:57798_exx",
[junit4] 2> "shard":null,
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 50712 T128 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2]
[junit4] 2> 50712 T128 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 50723 T127 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 50724 T147 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 50725 T134 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 51489 T148 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 51489 T148 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: .\org.apache.solr.cloud.ShardSplitTest-jetty1-1381262204309\collection1
[junit4] 2> 51489 T148 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 51491 T148 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 51491 T148 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 51494 T148 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '.\org.apache.solr.cloud.ShardSplitTest-jetty1-1381262204309\collection1\'
[junit4] 2> 51496 T148 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-jetty1-1381262204309/collection1/lib/classes/' to classloader
[junit4] 2> 51497 T148 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-jetty1-1381262204309/collection1/lib/README' to classloader
[junit4] 2> 51576 T148 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_46
[junit4] 2> 51656 T148 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 51661 T148 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 51671 T148 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 52433 T148 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 52437 T148 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 52440 T148 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 52447 T148 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 52512 T148 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 52513 T148 oasc.SolrCore.<init> [collection1] Opening new SolrCore at .\org.apache.solr.cloud.ShardSplitTest-jetty1-1381262204309\collection1\, dataDir=.\org.apache.solr.cloud.ShardSplitTest-1381262196449/jetty1\
[junit4] 2> 52513 T148 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@857066
[junit4] 2> 52514 T148 oasc.CachingDirectoryFactory.get return new directory for .\org.apache.solr.cloud.ShardSplitTest-1381262196449/jetty1\
[junit4] 2> 52514 T148 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.ShardSplitTest-1381262196449/jetty1\index/
[junit4] 2> 52514 T148 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '.\org.apache.solr.cloud.ShardSplitTest-1381262196449\jetty1\index' doesn't exist. Creating new index...
[junit4] 2> 52515 T148 oasc.CachingDirectoryFactory.get return new directory for .\org.apache.solr.cloud.ShardSplitTest-1381262196449/jetty1\index
[junit4] 2> 52515 T148 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=30, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
[junit4] 2> 52516 T148 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@101751 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@13cc05f),segFN=segments_1,generation=1}
[junit4] 2> 52516 T148 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 52521 T148 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 52521 T148 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 52522 T148 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 52522 T148 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 52522 T148 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 52522 T148 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 52524 T148 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 52524 T148 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 52524 T148 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 52525 T148 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 52526 T148 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 52526 T148 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 52526 T148 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 52527 T148 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 52528 T148 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 52533 T148 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 52540 T148 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 52540 T148 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 52541 T148 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=10, maxMergeAtOnceExplicit=12, maxMergedSegmentMB=87.94140625, floorSegmentMB=0.33984375, forceMergeDeletesPctAllowed=8.442630454142778, segmentsPerTier=17.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.24392947557826317
[junit4] 2> 52542 T148 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@101751 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@13cc05f),segFN=segments_1,generation=1}
[junit4] 2> 52542 T148 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 52543 T148 oass.SolrIndexSearcher.<init> Opening Searcher@80f252 main
[junit4] 2> 52555 T148 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 52555 T148 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:57798/exx collection:collection1 shard:shard1
[junit4] 2> 52556 T148 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=15000&socketTimeout=30000&retry=false
[junit4] 2> 52556 T149 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@80f252 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 52558 T148 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 52575 T148 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 52582 T148 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 52582 T148 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 52582 T148 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:57798/exx/collection1/
[junit4] 2> 52582 T148 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 52582 T148 oasc.SyncStrategy.syncToMe http://127.0.0.1:57798/exx/collection1/ has no replicas
[junit4] 2> 52582 T148 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:57798/exx/collection1/ shard1
[junit4] 2> 52582 T148 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 53623 T128 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 53645 T127 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 53645 T147 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 53646 T134 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 53672 T148 oasc.ZkController.register We are http://127.0.0.1:57798/exx/collection1/ and leader is http://127.0.0.1:57798/exx/collection1/
[junit4] 2> 53672 T148 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:57798/exx
[junit4] 2> 53672 T148 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 53673 T148 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 53673 T148 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 53676 T148 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 53678 T104 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0
[junit4] 2> 53678 T104 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 53679 T104 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 54098 T104 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 54102 T104 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:57807
[junit4] 2> 54102 T104 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 54103 T104 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 54103 T104 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-jetty2-1381262210250
[junit4] 2> 54104 T104 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-jetty2-1381262210250\'
[junit4] 2> 54135 T104 oasc.ConfigSolr.fromFile Loading container configuration from C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-jetty2-1381262210250\solr.xml
[junit4] 2> 54229 T104 oasc.CoreContainer.<init> New CoreContainer 27204524
[junit4] 2> 54230 T104 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-jetty2-1381262210250\]
[junit4] 2> 54232 T104 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 54232 T104 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 54233 T104 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 54233 T104 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 54234 T104 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 54234 T104 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 54234 T104 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 54234 T104 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 54234 T104 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 54235 T104 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4] 2> 54240 T104 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 54240 T104 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 54241 T104 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:57779/solr
[junit4] 2> 54241 T104 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 54242 T104 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 54256 T161 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@d1e832 name:ZooKeeperConnection Watcher:127.0.0.1:57779 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 54256 T104 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 54260 T104 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4] 2> 54263 T104 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 54267 T163 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@19c123d name:ZooKeeperConnection Watcher:127.0.0.1:57779/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 54267 T104 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 54277 T104 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 55104 T128 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 55105 T128 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:57798/exx",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:57798_exx",
[junit4] 2> "shard":"shard1",
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 55117 T127 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 55117 T163 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 55119 T134 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 55120 T147 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 55246 T104 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:57807_exx
[junit4] 2> 55249 T104 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:57807_exx
[junit4] 2> 55259 T147 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 55260 T127 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 55260 T163 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 55261 T134 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 55280 T164 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 55280 T164 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 55283 T164 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 56582 T128 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 56585 T128 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:57807/exx",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:57807_exx",
[junit4] 2> "shard":null,
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":"core_node2"}
[junit4] 2> 56586 T128 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4] 2> 56586 T128 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 56601 T127 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 56602 T163 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 56602 T147 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 56603 T134 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 57204 T164 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 57204 T164 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-jetty2-1381262210250\collection1
[junit4] 2> 57204 T164 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 57210 T164 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 57210 T164 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 57213 T164 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-jetty2-1381262210250\collection1\'
[junit4] 2> 57216 T164 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-jetty2-1381262210250/collection1/lib/classes/' to classloader
[junit4] 2> 57218 T164 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-jetty2-1381262210250/collection1/lib/README' to classloader
[junit4] 2> 57339 T164 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_46
[junit4] 2> 57438 T164 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 57442 T164 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 57454 T164 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 58254 T164 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 58258 T164 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 58262 T164 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 58271 T164 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 58352 T164 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 58353 T164 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-jetty2-1381262210250\collection1\, dataDir=.\org.apache.solr.cloud.ShardSplitTest-1381262196449/jetty2\
[junit4] 2> 58353 T164 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@857066
[junit4] 2> 58355 T164 oasc.CachingDirectoryFactory.get return new directory for .\org.apache.solr.cloud.ShardSplitTest-1381262196449/jetty2\
[junit4] 2> 58355 T164 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.ShardSplitTest-1381262196449/jetty2\index/
[junit4] 2> 58355 T164 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '.\org.apache.solr.cloud.ShardSplitTest-1381262196449\jetty2\index' doesn't exist. Creating new index...
[junit4] 2> 58355 T164 oasc.CachingDirectoryFactory.get return new directory for .\org.apache.solr.cloud.ShardSplitTest-1381262196449/jetty2\index
[junit4] 2> 58356 T164 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=30, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
[junit4] 2> 58356 T164 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@1aba72e lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@3da1dc),segFN=segments_1,generation=1}
[junit4] 2> 58356 T164 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 58363 T164 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 58364 T164 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 58364 T164 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 58365 T164 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 58365 T164 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 58366 T164 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 58367 T164 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 58368 T164 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 58368 T164 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 58369 T164 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 58370 T164 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 58370 T164 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 58370 T164 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 58372 T164 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 58373 T164 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 58378 T164 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 58387 T164 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 58387 T164 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 58388 T164 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=10, maxMergeAtOnceExplicit=12, maxMergedSegmentMB=87.94140625, floorSegmentMB=0.33984375, forceMergeDeletesPctAllowed=8.442630454142778, segmentsPerTier=17.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.24392947557826317
[junit4] 2> 58389 T164 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@1aba72e lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@3da1dc),segFN=segments_1,generation=1}
[junit4] 2> 58389 T164 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 58389 T164 oass.SolrIndexSearcher.<init> Opening Searcher@16a90c9 main
[junit4] 2> 58397 T165 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@16a90c9 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 58400 T164 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 58401 T164 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:57807/exx collection:collection1 shard:shard2
[junit4] 2> 58401 T164 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=15000&socketTimeout=30000&retry=false
[junit4] 2> 58404 T164 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4] 2> 58424 T164 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
[junit4] 2> 58432 T164 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 58432 T164 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 58432 T164 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:57807/exx/collection1/
[junit4] 2> 58432 T164 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 58432 T164 oasc.SyncStrategy.syncToMe http://127.0.0.1:57807/exx/collection1/ has no replicas
[junit4] 2> 58433 T164 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:57807/exx/collection1/ shard2
[junit4] 2> 58434 T164 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4] 2> 59518 T128 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 59544 T127 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 59544 T163 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 59545 T147 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 59546 T134 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 59574 T164 oasc.ZkController.register We are http://127.0.0.1:57807/exx/collection1/ and leader is http://127.0.0.1:57807/exx/collection1/
[junit4] 2> 59574 T164 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:57807/exx
[junit4] 2> 59574 T164 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 59574 T164 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 59574 T164 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 59578 T164 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 59581 T104 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0
[junit4] 2> 59581 T104 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 59581 T104 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 60034 T104 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 60037 T104 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:57816
[junit4] 2> 60039 T104 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 60039 T104 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 60039 T104 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-jetty3-1381262216152
[junit4] 2> 60040 T104 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-jetty3-1381262216152\'
[junit4] 2> 60065 T104 oasc.ConfigSolr.fromFile Loading container configuration from C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-jetty3-1381262216152\solr.xml
[junit4] 2> 60143 T104 oasc.CoreContainer.<init> New CoreContainer 17733848
[junit4] 2> 60144 T104 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-jetty3-1381262216152\]
[junit4] 2> 60145 T104 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 60145 T104 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 60145 T104 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 60146 T104 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 60146 T104 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 60147 T104 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 60147 T104 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 60147 T104 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 60148 T104 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 60148 T104 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4] 2> 60151 T104 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 60152 T104 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 60152 T104 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:57779/solr
[junit4] 2> 60153 T104 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 60154 T104 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 60158 T177 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@154b574 name:ZooKeeperConnection Watcher:127.0.0.1:57779 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 60159 T104 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 60162 T104 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4] 2> 60165 T104 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 60167 T179 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@169bc15 name:ZooKeeperConnection Watcher:127.0.0.1:57779/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 60167 T104 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 60176 T104 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 60861 T128 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 60863 T128 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:57807/exx",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:57807_exx",
[junit4] 2> "shard":"shard2",
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":"core_node2"}
[junit4] 2> 60871 T127 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 60872 T179 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 60872 T163 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 60872 T147 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 60873 T134 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 61047 T104 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:57816_exx
[junit4] 2> 61049 T104 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:57816_exx
[junit4] 2> 61057 T163 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 61059 T127 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 61059 T134 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 61060 T147 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 61061 T179 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 61077 T180 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 61077 T180 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 61080 T180 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 62183 T128 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 62184 T128 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:57816/exx",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:57816_exx",
[junit4] 2> "shard":null,
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":"core_node3"}
[junit4] 2> 62184 T128 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4] 2> 62184 T128 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 62194 T127 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4] 2> 62195 T163 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4] 2> 62195 T179 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4] 2> 62195 T147 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4] 2> 62195 T134 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4] 2> 62809 T180 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 62809 T180 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-jetty3-1381262216152\collection1
[junit4] 2> 62809 T180 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 62811 T180 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 62812 T180 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 62814 T180 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-jetty3-1381262216152\collection1\'
[junit4] 2> 62816 T180 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-jetty3-1381262216152/collection1/lib/classes/' to classloader
[junit4] 2> 62817 T180 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-jetty3-1381262216152/collection1/lib/README' to classloader
[junit4] 2> 62891 T180 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_46
[junit4] 2> 62968 T180 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 62971 T180 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 62981 T180 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 63646 T180 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 63649 T180 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 63652 T180 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 63659 T180 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 63713 T180 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 63713 T180 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-jetty3-1381262216152\collection1\, dataDir=.\org.apache.solr.cloud.ShardSplitTest-1381262196449/jetty3\
[junit4] 2> 63713 T180 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@857066
[junit4] 2> 63714 T180 oasc.CachingDirectoryFactory.get return new directory for .\org.apache.solr.cloud.ShardSplitTest-1381262196449/jetty3\
[junit4] 2> 63714 T180 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.ShardSplitTest-1381262196449/jetty3\index/
[junit4] 2> 63714 T180 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '.\org.apache.solr.cloud.ShardSplitTest-1381262196449\jetty3\index' doesn't exist. Creating new index...
[junit4] 2> 63715 T180 oasc.CachingDirectoryFactory.get return new directory for .\org.apache.solr.cloud.ShardSplitTest-1381262196449/jetty3\index
[junit4] 2> 63715 T180 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=30, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
[junit4] 2> 63716 T180 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@bbe73b lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1f899e9),segFN=segments_1,generation=1}
[junit4] 2> 63716 T180 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 63721 T180 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 63721 T180 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 63721 T180 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 63722 T180 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 63722 T180 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 63722 T180 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 63723 T180 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 63723 T180 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 63723 T180 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 63724 T180 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 63724 T180 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 63725 T180 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 63725 T180 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 63727 T180 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 63727 T180 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 63733 T180 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 63738 T180 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 63739 T180 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 63740 T180 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=10, maxMergeAtOnceExplicit=12, maxMergedSegmentMB=87.94140625, floorSegmentMB=0.33984375, forceMergeDeletesPctAllowed=8.442630454142778, segmentsPerTier=17.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.24392947557826317
[junit4] 2> 63740 T180 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@bbe73b lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1f899e9),segFN=segments_1,generation=1}
[junit4] 2> 63741 T180 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 63741 T180 oass.SolrIndexSearcher.<init> Opening Searcher@c4f498 main
[junit4] 2> 63748 T181 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@c4f498 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 63756 T180 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 63757 T180 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:57816/exx collection:collection1 shard:shard1
[junit4] 2> 63757 T180 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=15000&socketTimeout=30000&retry=false
[junit4] 2> 63765 T180 oasc.ZkController.register We are http://127.0.0.1:57816/exx/collection1/ and leader is http://127.0.0.1:57798/exx/collection1/
[junit4] 2> 63766 T180 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:57816/exx
[junit4] 2> 63766 T180 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4] 2> 63766 T180 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4] 2> ASYNC NEW_CORE C5 name=collection1 org.apache.solr.core.SolrCore@25a5d2 url=http://127.0.0.1:57816/exx/collection1 node=127.0.0.1:57816_exx C5_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:57816/exx, core=collection1, node_name=127.0.0.1:57816_exx}
[junit4] 2> 63771 T182 C5 P57816 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4] 2> 63772 T182 C5 P57816 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4] 2> 63772 T182 C5 P57816 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4] 2> 63772 T182 C5 P57816 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 63772 T180 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 63774 T182 C5 P57816 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 63775 T104 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0
[junit4] 2> 63775 T104 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 63776 T104 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 64236 T104 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 64254 T104 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:57826
[junit4] 2> 64254 T104 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 64255 T104 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 64255 T104 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: .\org.apache.solr.cloud.ShardSplitTest-jetty4-1381262220347
[junit4] 2> 64255 T104 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '.\org.apache.solr.cloud.ShardSplitTest-jetty4-1381262220347\'
[junit4] 2> 64489 T104 oasc.ConfigSolr.fromFile Loading container configuration from C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-jetty4-1381262220347\solr.xml
[junit4] 2> 64621 T104 oasc.CoreContainer.<init> New CoreContainer 2221552
[junit4] 2> 64621 T104 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=.\org.apache.solr.cloud.ShardSplitTest-jetty4-1381262220347\]
[junit4] 2> 64626 T104 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 64627 T104 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 64627 T104 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 64627 T104 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 64628 T104 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 64629 T104 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 64630 T104 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 64630 T104 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 64630 T104 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 64631 T104 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4] 2> 64637 T104 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 64637 T104 oasl.
[...truncated too long message...]
nt state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4] 2> 112126 T104 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 112127 T104 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 112134 T104 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@1110f31
[junit4] 2> 112178 T104 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=4,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=288,cumulative_deletesById=122,cumulative_deletesByQuery=1,cumulative_errors=0}
[junit4] 2> 112178 T104 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4] 2> 112179 T104 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 112179 T104 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4] 2> 112182 T104 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4] 2> 112182 T104 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 112183 T104 oasc.CachingDirectoryFactory.closeCacheValue looking to close .\org.apache.solr.cloud.ShardSplitTest-1381262196449/jetty4\ [CachedDir<<refCount=0;path=.\org.apache.solr.cloud.ShardSplitTest-1381262196449/jetty4\;done=false>>]
[junit4] 2> 112183 T104 oasc.CachingDirectoryFactory.close Closing directory: .\org.apache.solr.cloud.ShardSplitTest-1381262196449/jetty4\
[junit4] 2> 112184 T104 oasc.CachingDirectoryFactory.closeCacheValue looking to close .\org.apache.solr.cloud.ShardSplitTest-1381262196449/jetty4\index [CachedDir<<refCount=0;path=.\org.apache.solr.cloud.ShardSplitTest-1381262196449/jetty4\index;done=false>>]
[junit4] 2> 112184 T104 oasc.CachingDirectoryFactory.close Closing directory: .\org.apache.solr.cloud.ShardSplitTest-1381262196449/jetty4\index
[junit4] 2> 112186 T265 oasc.Overseer$ClusterStateUpdater.amILeader According to ZK I (id=90522399330664460-127.0.0.1:57826_exx-n_0000000004) am no longer a leader.
[junit4] 2> 112190 T250 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 112203 T104 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/exx,null}
[junit4] 2> !!!! WARNING: best effort to remove C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-1381262196449\zookeeper\server1\data\version-2\log.1 FAILED !!!!!
[junit4] 2> !!!! WARNING: best effort to remove C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-1381262196449\zookeeper\server1\data\version-2 FAILED !!!!!
[junit4] 2> !!!! WARNING: best effort to remove C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-1381262196449\zookeeper\server1\data FAILED !!!!!
[junit4] 2> !!!! WARNING: best effort to remove C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-1381262196449\zookeeper\server1 FAILED !!!!!
[junit4] 2> !!!! WARNING: best effort to remove C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-1381262196449\zookeeper FAILED !!!!!
[junit4] 2> !!!! WARNING: best effort to remove C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-1381262196449 FAILED !!!!!
[junit4] 2> 112306 T104 oas.SolrTestCaseJ4.tearDown ###Ending testDistribSearch
[junit4] 2> 112313 T104 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:57779 57779
[junit4] 2> 113671 T196 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 114885 T106 oazs.NIOServerCnxnFactory.run WARN Ignoring unexpected runtime exception java.nio.channels.CancelledKeyException
[junit4] 2> at sun.nio.ch.SelectionKeyImpl.ensureValid(SelectionKeyImpl.java:55)
[junit4] 2> at sun.nio.ch.SelectionKeyImpl.readyOps(SelectionKeyImpl.java:69)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:187)
[junit4] 2> at java.lang.Thread.run(Thread.java:662)
[junit4] 2>
[junit4] 2> 115004 T250 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@543360 name:ZooKeeperConnection Watcher:127.0.0.1:57779/solr got event WatchedEvent state:Disconnected type:None path:null path:null type:None
[junit4] 2> 115004 T104 oasc.ChaosMonkey.monkeyLog monkey: stop shard! 57786
[junit4] 2> 115004 T250 oascc.ConnectionManager.process Client->ZooKeeper status change trigger but we are already closed
[junit4] 2> 115028 T104 oas.SolrTestCaseJ4.tearDown ###Ending testDistribSearch
[junit4] 2> 115028 T104 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:57779 57779
[junit4] 1> /solr/collections/control_collection/leader_elect/shard1 (1)
[junit4] 1> /solr/collections/control_collection/leader_elect/shard1/election (1)
[junit4] 1> /solr/collections/control_collection/leader_elect/shard1/election/90522399330664451-core_node1-n_0000000000 (0)
[junit4] 1> /solr/collections/control_collection/leaders (1)
[junit4] 1> /solr/collections/control_collection/leaders/shard1 (0)
[junit4] 1> DATA:
[junit4] 1> {
[junit4] 1> "core":"collection1",
[junit4] 1> "node_name":"127.0.0.1:57786_exx",
[junit4] 1> "base_url":"http://127.0.0.1:57786/exx"}
[junit4] 1> /solr/overseer_elect (2)
[junit4] 1> /solr/overseer_elect/election (5)
[junit4] 1> /solr/overseer_elect/election/90522399330664451-127.0.0.1:57786_exx-n_0000000000 (0)
[junit4] 1> /solr/overseer_elect/election/90522399330664460-127.0.0.1:57826_exx-n_0000000004 (0)
[junit4] 1> /solr/overseer_elect/election/90522399330664456-127.0.0.1:57807_exx-n_0000000002 (0)
[junit4] 1> /solr/overseer_elect/election/90522399330664454-127.0.0.1:57798_exx-n_0000000001 (0)
[junit4] 1> /solr/overseer_elect/election/90522399330664458-127.0.0.1:57816_exx-n_0000000003 (0)
[junit4] 1> /solr/overseer_elect/leader (0)
[junit4] 1> DATA:
[junit4] 1> {"id":"90522399330664451-127.0.0.1:57786_exx-n_0000000000"}
[junit4] 1> /zookeeper (1)
[junit4] 1> DATA:
[junit4] 1>
[junit4] 1>
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=ShardSplitTest -Dtests.method=testDistribSearch -Dtests.seed=363EABD33CDF2EA2 -Dtests.slow=true -Dtests.locale=ga_IE -Dtests.timezone=Africa/Monrovia -Dtests.file.encoding=ISO-8859-1
[junit4] FAILURE 75.2s | ShardSplitTest.testDistribSearch <<<
[junit4] > Throwable #1: java.lang.AssertionError: Wrong doc count on shard1_1 expected:<51> but was:<33>
[junit4] > at __randomizedtesting.SeedInfo.seed([363EABD33CDF2EA2:B7D825CB4B804E9E]:0)
[junit4] > at org.apache.solr.cloud.ShardSplitTest.checkDocCountsAndShardStates(ShardSplitTest.java:327)
[junit4] > at org.apache.solr.cloud.ShardSplitTest.splitByUniqueKeyTest(ShardSplitTest.java:201)
[junit4] > at org.apache.solr.cloud.ShardSplitTest.doTest(ShardSplitTest.java:111)
[junit4] > at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:835)
[junit4] > at java.lang.Thread.run(Thread.java:662)
[junit4] 2> 115041 T104 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> 75176 T103 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 1 leaked thread(s).
[junit4] 2> NOTE: test params are: codec=Lucene42, sim=RandomSimilarityProvider(queryNorm=false,coord=no): {}, locale=ga_IE, timezone=Africa/Monrovia
[junit4] 2> NOTE: Windows 7 6.1 x86/Sun Microsystems Inc. 1.6.0_45 (32-bit)/cpus=2,threads=2,free=27982896,total=68628480
[junit4] 2> NOTE: All tests run in this JVM: [TestIndexingPerformance, TestManagedSchema, CoreMergeIndexesAdminHandlerTest, HdfsRecoveryZkTest, ShardSplitTest]
[junit4] Completed in 75.52s, 1 test, 1 failure <<< FAILURES!
[...truncated 1021 lines...]
BUILD FAILED
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\build.xml:428: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\build.xml:408: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\build.xml:39: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build.xml:189: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\common-build.xml:451: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\lucene\common-build.xml:1233: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\lucene\common-build.xml:876: There were test failures: 327 suites, 1453 tests, 1 failure, 41 ignored (13 assumptions)
Total time: 86 minutes 54 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 32bit/jdk1.6.0_45 -client -XX:+UseConcMarkSweepGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure