lucene-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Policeman Jenkins Server <jenk...@thetaphi.de>
Subject [JENKINS] Lucene-Solr-4.x-MacOSX (64bit/jdk1.6.0) - Build # 392 - Still Failing!
Date Fri, 19 Apr 2013 01:00:50 GMT
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-MacOSX/392/
Java: 64bit/jdk1.6.0 -XX:+UseSerialGC

1 tests failed.
REGRESSION:  org.apache.solr.cloud.ShardSplitTest.testDistribSearch

Error Message:
Wrong doc count on shard1_0 expected:<114> but was:<113>

Stack Trace:
java.lang.AssertionError: Wrong doc count on shard1_0 expected:<114> but was:<113>
	at __randomizedtesting.SeedInfo.seed([F917BC7C26480A71:78F1326451176A4D]: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:158)
	at org.apache.solr.cloud.ShardSplitTest.doTest(ShardSplitTest.java:134)
	at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:806)
	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:680)




Build Log:
[...truncated 8533 lines...]
[junit4:junit4] Suite: org.apache.solr.cloud.ShardSplitTest
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:16.195; org.apache.solr.BaseDistributedSearchTestCase; Setting hostContext system property: /yb_zzk/q
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:16.202; org.apache.solr.SolrTestCaseJ4; ###Starting testDistribSearch
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:16.207; org.apache.solr.cloud.ZkTestServer; STARTING ZK TEST SERVER
[junit4:junit4]   1> client port:0.0.0.0/0.0.0.0:0
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:16.208; org.apache.solr.cloud.ZkTestServer$ZKServerMain; Starting server
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:16.320; org.apache.solr.cloud.ZkTestServer; start zk server on port:51530
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:16.339; org.apache.solr.common.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:16.347; org.apache.solr.common.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionManager@3aa368a4 name:ZooKeeperConnection Watcher:127.0.0.1:51530 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:16.389; org.apache.solr.common.cloud.ConnectionManager; Client is connected to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:16.390; org.apache.solr.common.cloud.SolrZkClient; makePath: /solr
[junit4:junit4]   1> WARN  - 2013-04-19 00:07:16.404; org.apache.zookeeper.server.NIOServerCnxn; caught end of stream exception
[junit4:junit4]   1> EndOfStreamException: Unable to read additional data from client sessionid 0x13e1f9dcffb0000, likely client has closed socket
[junit4:junit4]   1> 	at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:220)
[junit4:junit4]   1> 	at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4:junit4]   1> 	at java.lang.Thread.run(Thread.java:680)
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:16.411; org.apache.solr.common.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:16.419; org.apache.solr.common.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionManager@fc8837e name:ZooKeeperConnection Watcher:127.0.0.1:51530/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:16.419; org.apache.solr.common.cloud.ConnectionManager; Client is connected to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:16.420; org.apache.solr.common.cloud.SolrZkClient; makePath: /collections/collection1
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:16.430; org.apache.solr.common.cloud.SolrZkClient; makePath: /collections/collection1/shards
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:16.440; org.apache.solr.common.cloud.SolrZkClient; makePath: /collections/control_collection
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:16.454; org.apache.solr.common.cloud.SolrZkClient; makePath: /collections/control_collection/shards
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:16.465; org.apache.solr.cloud.AbstractZkTestCase; put /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:16.467; org.apache.solr.common.cloud.SolrZkClient; makePath: /configs/conf1/solrconfig.xml
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:16.482; org.apache.solr.cloud.AbstractZkTestCase; put /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:16.484; org.apache.solr.common.cloud.SolrZkClient; makePath: /configs/conf1/schema.xml
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:16.494; org.apache.solr.cloud.AbstractZkTestCase; put /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:16.495; org.apache.solr.common.cloud.SolrZkClient; makePath: /configs/conf1/stopwords.txt
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:16.505; org.apache.solr.cloud.AbstractZkTestCase; put /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:16.506; org.apache.solr.common.cloud.SolrZkClient; makePath: /configs/conf1/protwords.txt
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:16.521; org.apache.solr.cloud.AbstractZkTestCase; put /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:16.522; org.apache.solr.common.cloud.SolrZkClient; makePath: /configs/conf1/currency.xml
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:16.534; org.apache.solr.cloud.AbstractZkTestCase; put /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:16.535; org.apache.solr.common.cloud.SolrZkClient; makePath: /configs/conf1/open-exchange-rates.json
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:16.544; org.apache.solr.cloud.AbstractZkTestCase; put /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:16.545; org.apache.solr.common.cloud.SolrZkClient; makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:16.555; org.apache.solr.cloud.AbstractZkTestCase; put /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:16.556; org.apache.solr.common.cloud.SolrZkClient; makePath: /configs/conf1/old_synonyms.txt
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:16.564; org.apache.solr.cloud.AbstractZkTestCase; put /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:16.565; org.apache.solr.common.cloud.SolrZkClient; makePath: /configs/conf1/synonyms.txt
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:17.101; org.eclipse.jetty.server.Server; jetty-8.1.8.v20121106
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:17.132; org.eclipse.jetty.server.AbstractConnector; Started SelectChannelConnector@127.0.0.1:51533
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:17.133; org.apache.solr.servlet.SolrDispatchFilter; SolrDispatchFilter.init()
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:17.133; org.apache.solr.core.SolrResourceLoader; JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:17.134; org.apache.solr.core.SolrResourceLoader; using system property solr.solr.home: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-controljetty-1366330036583
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:17.135; org.apache.solr.core.CoreContainer$Initializer; looking for solr config file: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-controljetty-1366330036583/solr.xml
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:17.135; org.apache.solr.core.CoreContainer; New CoreContainer 78749786
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:17.136; org.apache.solr.core.CoreContainer; Loading CoreContainer using Solr Home: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-controljetty-1366330036583/'
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:17.139; org.apache.solr.core.SolrResourceLoader; new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-controljetty-1366330036583/'
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:17.460; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting socketTimeout to: 120000
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:17.461; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting urlScheme to: http://
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:17.462; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting connTimeout to: 15000
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:17.462; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maxConnectionsPerHost to: 20
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:17.463; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting corePoolSize to: 0
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:17.463; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maximumPoolSize to: 2147483647
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:17.464; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maxThreadIdleTime to: 5
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:17.464; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting sizeOfQueue to: -1
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:17.465; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting fairnessPolicy to: false
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:17.465; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:17.520; org.apache.solr.core.CoreContainer; Registering Log Listener
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:17.521; org.apache.solr.core.CoreContainer; Zookeeper client=127.0.0.1:51530/solr
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:17.522; org.apache.solr.cloud.ZkController; zkHost includes chroot
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:17.527; org.apache.solr.common.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:17.534; org.apache.solr.common.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionManager@5e71a70b name:ZooKeeperConnection Watcher:127.0.0.1:51530 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:17.535; org.apache.solr.common.cloud.ConnectionManager; Client is connected to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:17.543; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:17.594; org.apache.solr.common.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:17.600; org.apache.solr.common.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionManager@4223c010 name:ZooKeeperConnection Watcher:127.0.0.1:51530/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:17.601; org.apache.solr.common.cloud.ConnectionManager; Client is connected to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:17.606; org.apache.solr.common.cloud.SolrZkClient; makePath: /overseer/queue
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:17.620; org.apache.solr.common.cloud.SolrZkClient; makePath: /overseer/collection-queue-work
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:17.638; org.apache.solr.common.cloud.SolrZkClient; makePath: /live_nodes
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:17.646; org.apache.solr.cloud.ZkController; Register node as live in ZooKeeper:/live_nodes/127.0.0.1:51533_yb_zzk%2Fq
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:17.650; org.apache.solr.common.cloud.SolrZkClient; makePath: /live_nodes/127.0.0.1:51533_yb_zzk%2Fq
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:17.666; org.apache.solr.common.cloud.SolrZkClient; makePath: /overseer_elect/election
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:17.685; org.apache.solr.common.cloud.SolrZkClient; makePath: /overseer_elect/leader
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:17.695; org.apache.solr.cloud.Overseer; Overseer (id=89543805253648387-127.0.0.1:51533_yb_zzk%2Fq-n_0000000000) starting
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:17.708; org.apache.solr.common.cloud.SolrZkClient; makePath: /overseer/queue-work
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:17.726; org.apache.solr.cloud.OverseerCollectionProcessor; Process current queue of collection creations
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:17.731; org.apache.solr.common.cloud.SolrZkClient; makePath: /clusterstate.json
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:17.741; org.apache.solr.common.cloud.SolrZkClient; makePath: /aliases.json
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:17.748; org.apache.solr.common.cloud.ZkStateReader; Updating cluster state from ZooKeeper... 
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:17.770; org.apache.solr.core.CoreContainer; Creating SolrCore 'collection1' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-controljetty-1366330036583/collection1
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:17.771; org.apache.solr.cloud.ZkController; Check for collection zkNode:control_collection
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:17.774; org.apache.solr.cloud.Overseer$ClusterStateUpdater; Starting to work on the main queue
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:17.775; org.apache.solr.cloud.ZkController; Collection zkNode exists
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:17.782; org.apache.solr.cloud.ZkController; Load collection config from:/collections/control_collection
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:17.786; org.apache.solr.core.SolrResourceLoader; new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-controljetty-1366330036583/collection1/'
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:17.788; org.apache.solr.core.SolrResourceLoader; Adding 'file:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-controljetty-1366330036583/collection1/lib/classes/' to classloader
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:17.788; org.apache.solr.core.SolrResourceLoader; Adding 'file:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-controljetty-1366330036583/collection1/lib/README' to classloader
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:17.887; org.apache.solr.core.SolrConfig; Using Lucene MatchVersion: LUCENE_44
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:17.993; org.apache.solr.core.SolrConfig; Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:17.997; org.apache.solr.schema.IndexSchema; Reading Solr Schema from schema.xml
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:18.015; org.apache.solr.schema.IndexSchema; Schema name=test
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:19.144; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:19.165; org.apache.solr.schema.IndexSchema; default search field in schema is text
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:19.171; org.apache.solr.schema.IndexSchema; unique key field: id
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:19.251; org.apache.solr.schema.FileExchangeRateProvider; Reloading exchange rates from file currency.xml
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:19.261; org.apache.solr.schema.FileExchangeRateProvider; Reloading exchange rates from file currency.xml
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:19.269; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   1> WARN  - 2013-04-19 00:07:19.273; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOTE
[junit4:junit4]   1> WARN  - 2013-04-19 00:07:19.273; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:19.273; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   1> WARN  - 2013-04-19 00:07:19.276; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOTE
[junit4:junit4]   1> WARN  - 2013-04-19 00:07:19.277; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:19.277; org.apache.solr.core.SolrCore; org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:19.279; org.apache.solr.core.SolrCore; [collection1] Opening new SolrCore at /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-controljetty-1366330036583/collection1/, dataDir=./org.apache.solr.cloud.ShardSplitTest-1366330036205/control/data/
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:19.279; org.apache.solr.core.JmxMonitoredMap; JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@508de972
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:19.280; org.apache.solr.core.SolrCore; org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:19.280; org.apache.solr.core.CachingDirectoryFactory; return new directory for ./org.apache.solr.cloud.ShardSplitTest-1366330036205/control/data
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:19.281; org.apache.solr.core.SolrCore; New index directory detected: old=null new=./org.apache.solr.cloud.ShardSplitTest-1366330036205/control/data/index/
[junit4:junit4]   1> WARN  - 2013-04-19 00:07:19.281; org.apache.solr.core.SolrCore; [collection1] Solr index directory './org.apache.solr.cloud.ShardSplitTest-1366330036205/control/data/index' doesn't exist. Creating new index...
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:19.282; org.apache.solr.core.CachingDirectoryFactory; return new directory for ./org.apache.solr.cloud.ShardSplitTest-1366330036205/control/data/index
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:19.294; org.apache.solr.core.SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   1> 	commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@7e938520 lockFactory=org.apache.lucene.store.NativeFSLockFactory@72019dcd),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:19.294; org.apache.solr.core.SolrDeletionPolicy; newest commit = 1[segments_1]
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:19.298; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:19.299; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:19.300; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:19.301; org.apache.solr.core.RequestHandlers; created standard: solr.StandardRequestHandler
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:19.301; org.apache.solr.core.RequestHandlers; created /get: solr.RealTimeGetHandler
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:19.302; org.apache.solr.core.RequestHandlers; adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:19.302; org.apache.solr.core.RequestHandlers; created /replication: solr.ReplicationHandler
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:19.303; org.apache.solr.core.RequestHandlers; created /update: solr.UpdateRequestHandler
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:19.304; org.apache.solr.core.RequestHandlers; created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:19.321; org.apache.solr.handler.loader.XMLLoader; xsltCacheLifetimeSeconds=60
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:19.331; org.apache.solr.search.SolrIndexSearcher; Opening Searcher@691269e5 main
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:19.332; org.apache.solr.update.UpdateHandler; Clearing tlog files, tlogDir=./org.apache.solr.cloud.ShardSplitTest-1366330036205/control/data/tlog
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:19.334; org.apache.solr.update.CommitTracker; Hard AutoCommit: disabled
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:19.334; org.apache.solr.update.CommitTracker; Soft AutoCommit: disabled
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:19.340; org.apache.solr.core.SolrCore; [collection1] Registered new searcher Searcher@691269e5 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:19.342; org.apache.solr.cloud.ZkController; publishing core=collection1 state=down
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:19.343; org.apache.solr.cloud.ZkController; numShards not found on descriptor - reading it from system property
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:20.800; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper... 
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:20.802; org.apache.solr.cloud.Overseer$ClusterStateUpdater; Update state numShards=1 message={
[junit4:junit4]   1>   "operation":"state",
[junit4:junit4]   1>   "core_node_name":"1",
[junit4:junit4]   1>   "numShards":"1",
[junit4:junit4]   1>   "shard":null,
[junit4:junit4]   1>   "roles":null,
[junit4:junit4]   1>   "state":"down",
[junit4:junit4]   1>   "shard_state":"active",
[junit4:junit4]   1>   "core":"collection1",
[junit4:junit4]   1>   "collection":"control_collection",
[junit4:junit4]   1>   "shard_range":null,
[junit4:junit4]   1>   "node_name":"127.0.0.1:51533_yb_zzk%2Fq",
[junit4:junit4]   1>   "base_url":"http://127.0.0.1:51533/yb_zzk/q"}
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:20.803; org.apache.solr.cloud.Overseer$ClusterStateUpdater; Create collection control_collection with numShards 1
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:20.803; org.apache.solr.cloud.Overseer$ClusterStateUpdater; Assigning new node to shard=shard1
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:20.820; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:21.351; org.apache.solr.core.CoreContainer; registering core: collection1
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:21.352; org.apache.solr.cloud.ZkController; Register replica - core:collection1 address:http://127.0.0.1:51533/yb_zzk/q collection:control_collection shard:shard1
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:21.354; org.apache.solr.common.cloud.SolrZkClient; makePath: /collections/control_collection/leader_elect/shard1/election
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:21.387; org.apache.solr.cloud.ShardLeaderElectionContext; Running the leader process.
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:21.395; org.apache.solr.cloud.ShardLeaderElectionContext; Enough replicas found to continue.
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:21.396; org.apache.solr.cloud.ShardLeaderElectionContext; I may be the new leader - try and sync
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:21.397; org.apache.solr.cloud.SyncStrategy; Sync replicas to http://127.0.0.1:51533/yb_zzk/q/collection1/
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:21.397; org.apache.solr.cloud.SyncStrategy; Sync Success - now sync replicas to me
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:21.398; org.apache.solr.cloud.SyncStrategy; http://127.0.0.1:51533/yb_zzk/q/collection1/ has no replicas
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:21.398; org.apache.solr.cloud.ShardLeaderElectionContext; I am the new leader: http://127.0.0.1:51533/yb_zzk/q/collection1/
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:21.399; org.apache.solr.common.cloud.SolrZkClient; makePath: /collections/control_collection/leaders/shard1
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:22.343; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper... 
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:22.389; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:22.417; org.apache.solr.cloud.ZkController; We are http://127.0.0.1:51533/yb_zzk/q/collection1/ and leader is http://127.0.0.1:51533/yb_zzk/q/collection1/
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:22.419; org.apache.solr.cloud.ZkController; No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:51533/yb_zzk/q
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:22.419; org.apache.solr.cloud.ZkController; I am the leader, no recovery necessary
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:22.420; org.apache.solr.cloud.ZkController; publishing core=collection1 state=active
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:22.420; org.apache.solr.cloud.ZkController; numShards not found on descriptor - reading it from system property
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:22.425; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper... 
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:22.428; org.apache.solr.servlet.SolrDispatchFilter; user.dir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:22.429; org.apache.solr.servlet.SolrDispatchFilter; SolrDispatchFilter.init() done
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:22.430; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:22.485; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:22.487; org.apache.solr.common.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:22.493; org.apache.solr.common.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionManager@101b2f74 name:ZooKeeperConnection Watcher:127.0.0.1:51530/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:22.494; org.apache.solr.common.cloud.ConnectionManager; Client is connected to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:22.499; org.apache.solr.common.cloud.ZkStateReader; Updating cluster state from ZooKeeper... 
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:22.508; org.apache.solr.cloud.ChaosMonkey; monkey: init - expire sessions:true cause connection loss:true
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:23.066; org.eclipse.jetty.server.Server; jetty-8.1.8.v20121106
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:23.093; org.eclipse.jetty.server.AbstractConnector; Started SelectChannelConnector@127.0.0.1:51537
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:23.096; org.apache.solr.servlet.SolrDispatchFilter; SolrDispatchFilter.init()
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:23.097; org.apache.solr.core.SolrResourceLoader; JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:23.097; org.apache.solr.core.SolrResourceLoader; using system property solr.solr.home: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty1-1366330042509
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:23.098; org.apache.solr.core.CoreContainer$Initializer; looking for solr config file: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty1-1366330042509/solr.xml
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:23.101; org.apache.solr.core.CoreContainer; New CoreContainer 1879407023
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:23.102; org.apache.solr.core.CoreContainer; Loading CoreContainer using Solr Home: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty1-1366330042509/'
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:23.102; org.apache.solr.core.SolrResourceLoader; new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty1-1366330042509/'
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:23.404; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting socketTimeout to: 120000
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:23.405; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting urlScheme to: http://
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:23.406; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting connTimeout to: 15000
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:23.406; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maxConnectionsPerHost to: 20
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:23.407; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting corePoolSize to: 0
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:23.408; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maximumPoolSize to: 2147483647
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:23.408; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maxThreadIdleTime to: 5
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:23.409; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting sizeOfQueue to: -1
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:23.409; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting fairnessPolicy to: false
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:23.410; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:23.470; org.apache.solr.core.CoreContainer; Registering Log Listener
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:23.471; org.apache.solr.core.CoreContainer; Zookeeper client=127.0.0.1:51530/solr
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:23.472; org.apache.solr.cloud.ZkController; zkHost includes chroot
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:23.475; org.apache.solr.common.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:23.495; org.apache.solr.common.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionManager@4b6183d name:ZooKeeperConnection Watcher:127.0.0.1:51530 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:23.496; org.apache.solr.common.cloud.ConnectionManager; Client is connected to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:23.504; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:23.566; org.apache.solr.common.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:23.576; org.apache.solr.common.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionManager@3822cf60 name:ZooKeeperConnection Watcher:127.0.0.1:51530/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:23.577; org.apache.solr.common.cloud.ConnectionManager; Client is connected to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:23.602; org.apache.solr.common.cloud.ZkStateReader; Updating cluster state from ZooKeeper... 
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:23.899; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper... 
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:23.901; org.apache.solr.cloud.Overseer$ClusterStateUpdater; Update state numShards=1 message={
[junit4:junit4]   1>   "operation":"state",
[junit4:junit4]   1>   "core_node_name":"1",
[junit4:junit4]   1>   "numShards":"1",
[junit4:junit4]   1>   "shard":"shard1",
[junit4:junit4]   1>   "roles":null,
[junit4:junit4]   1>   "state":"active",
[junit4:junit4]   1>   "shard_state":"active",
[junit4:junit4]   1>   "core":"collection1",
[junit4:junit4]   1>   "collection":"control_collection",
[junit4:junit4]   1>   "shard_range":null,
[junit4:junit4]   1>   "node_name":"127.0.0.1:51533_yb_zzk%2Fq",
[junit4:junit4]   1>   "base_url":"http://127.0.0.1:51533/yb_zzk/q"}
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:23.921; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:23.927; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:23.930; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:24.621; org.apache.solr.cloud.ZkController; Register node as live in ZooKeeper:/live_nodes/127.0.0.1:51537_yb_zzk%2Fq
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:24.624; org.apache.solr.common.cloud.SolrZkClient; makePath: /live_nodes/127.0.0.1:51537_yb_zzk%2Fq
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:24.634; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (2)
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:24.634; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 2)
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:24.654; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 1)
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:24.655; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 1)
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:24.666; org.apache.solr.core.CoreContainer; Creating SolrCore 'collection1' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty1-1366330042509/collection1
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:24.667; org.apache.solr.cloud.ZkController; Check for collection zkNode:collection1
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:24.668; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (2)
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:24.670; org.apache.solr.cloud.ZkController; Collection zkNode exists
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:24.670; org.apache.solr.cloud.ZkController; Load collection config from:/collections/collection1
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:24.670; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (2)
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:24.674; org.apache.solr.core.SolrResourceLoader; new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty1-1366330042509/collection1/'
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:24.676; org.apache.solr.core.SolrResourceLoader; Adding 'file:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-jetty1-1366330042509/collection1/lib/classes/' to classloader
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:24.677; org.apache.solr.core.SolrResourceLoader; Adding 'file:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-jetty1-1366330042509/collection1/lib/README' to classloader
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:24.773; org.apache.solr.core.SolrConfig; Using Lucene MatchVersion: LUCENE_44
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:25.052; org.apache.solr.core.SolrConfig; Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:25.068; org.apache.solr.schema.IndexSchema; Reading Solr Schema from schema.xml
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:25.077; org.apache.solr.schema.IndexSchema; Schema name=test
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:26.340; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:26.364; org.apache.solr.schema.IndexSchema; default search field in schema is text
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:26.370; org.apache.solr.schema.IndexSchema; unique key field: id
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:26.424; org.apache.solr.schema.FileExchangeRateProvider; Reloading exchange rates from file currency.xml
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:26.438; org.apache.solr.schema.FileExchangeRateProvider; Reloading exchange rates from file currency.xml
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:26.450; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   1> WARN  - 2013-04-19 00:07:26.455; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOTE
[junit4:junit4]   1> WARN  - 2013-04-19 00:07:26.456; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:26.456; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   1> WARN  - 2013-04-19 00:07:26.460; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOTE
[junit4:junit4]   1> WARN  - 2013-04-19 00:07:26.460; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:26.461; org.apache.solr.core.SolrCore; org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:26.461; org.apache.solr.core.SolrCore; [collection1] Opening new SolrCore at /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty1-1366330042509/collection1/, dataDir=./org.apache.solr.cloud.ShardSplitTest-1366330036205/jetty1/
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:26.462; org.apache.solr.core.JmxMonitoredMap; JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@508de972
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:26.463; org.apache.solr.core.SolrCore; org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:26.464; org.apache.solr.core.CachingDirectoryFactory; return new directory for ./org.apache.solr.cloud.ShardSplitTest-1366330036205/jetty1
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:26.464; org.apache.solr.core.SolrCore; New index directory detected: old=null new=./org.apache.solr.cloud.ShardSplitTest-1366330036205/jetty1/index/
[junit4:junit4]   1> WARN  - 2013-04-19 00:07:26.465; org.apache.solr.core.SolrCore; [collection1] Solr index directory './org.apache.solr.cloud.ShardSplitTest-1366330036205/jetty1/index' doesn't exist. Creating new index...
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:26.465; org.apache.solr.core.CachingDirectoryFactory; return new directory for ./org.apache.solr.cloud.ShardSplitTest-1366330036205/jetty1/index
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:26.471; org.apache.solr.core.SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   1> 	commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@ec3b565 lockFactory=org.apache.lucene.store.NativeFSLockFactory@181f9666),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:26.471; org.apache.solr.core.SolrDeletionPolicy; newest commit = 1[segments_1]
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:26.476; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:26.477; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:26.478; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:26.479; org.apache.solr.core.RequestHandlers; created standard: solr.StandardRequestHandler
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:26.481; org.apache.solr.core.RequestHandlers; created /get: solr.RealTimeGetHandler
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:26.481; org.apache.solr.core.RequestHandlers; adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:26.482; org.apache.solr.core.RequestHandlers; created /replication: solr.ReplicationHandler
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:26.484; org.apache.solr.core.RequestHandlers; created /update: solr.UpdateRequestHandler
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:26.484; org.apache.solr.core.RequestHandlers; created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:26.496; org.apache.solr.handler.loader.XMLLoader; xsltCacheLifetimeSeconds=60
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:26.509; org.apache.solr.search.SolrIndexSearcher; Opening Searcher@3b96c983 main
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:26.513; org.apache.solr.update.UpdateHandler; Clearing tlog files, tlogDir=./org.apache.solr.cloud.ShardSplitTest-1366330036205/jetty1/tlog
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:26.516; org.apache.solr.update.CommitTracker; Hard AutoCommit: disabled
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:26.516; org.apache.solr.update.CommitTracker; Soft AutoCommit: disabled
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:26.525; org.apache.solr.core.SolrCore; [collection1] Registered new searcher Searcher@3b96c983 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:26.528; org.apache.solr.cloud.ZkController; publishing core=collection1 state=down
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:26.529; org.apache.solr.cloud.ZkController; numShards not found on descriptor - reading it from system property
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:26.973; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper... 
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:26.975; org.apache.solr.cloud.Overseer$ClusterStateUpdater; Update state numShards=2 message={
[junit4:junit4]   1>   "operation":"state",
[junit4:junit4]   1>   "core_node_name":"2",
[junit4:junit4]   1>   "numShards":"2",
[junit4:junit4]   1>   "shard":null,
[junit4:junit4]   1>   "roles":null,
[junit4:junit4]   1>   "state":"down",
[junit4:junit4]   1>   "shard_state":"active",
[junit4:junit4]   1>   "core":"collection1",
[junit4:junit4]   1>   "collection":"collection1",
[junit4:junit4]   1>   "shard_range":null,
[junit4:junit4]   1>   "node_name":"127.0.0.1:51537_yb_zzk%2Fq",
[junit4:junit4]   1>   "base_url":"http://127.0.0.1:51537/yb_zzk/q"}
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:26.975; org.apache.solr.cloud.Overseer$ClusterStateUpdater; Create collection collection1 with numShards 2
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:26.975; org.apache.solr.cloud.Overseer$ClusterStateUpdater; Assigning new node to shard=shard1
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:26.987; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:26.990; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:26.997; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:27.562; org.apache.solr.core.CoreContainer; registering core: collection1
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:27.562; org.apache.solr.cloud.ZkController; Register replica - core:collection1 address:http://127.0.0.1:51537/yb_zzk/q collection:collection1 shard:shard1
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:27.564; org.apache.solr.common.cloud.SolrZkClient; makePath: /collections/collection1/leader_elect/shard1/election
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:27.602; org.apache.solr.cloud.ShardLeaderElectionContext; Running the leader process.
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:27.610; org.apache.solr.cloud.ShardLeaderElectionContext; Enough replicas found to continue.
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:27.611; org.apache.solr.cloud.ShardLeaderElectionContext; I may be the new leader - try and sync
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:27.611; org.apache.solr.cloud.SyncStrategy; Sync replicas to http://127.0.0.1:51537/yb_zzk/q/collection1/
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:27.611; org.apache.solr.cloud.SyncStrategy; Sync Success - now sync replicas to me
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:27.612; org.apache.solr.cloud.SyncStrategy; http://127.0.0.1:51537/yb_zzk/q/collection1/ has no replicas
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:27.612; org.apache.solr.cloud.ShardLeaderElectionContext; I am the new leader: http://127.0.0.1:51537/yb_zzk/q/collection1/
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:27.612; org.apache.solr.common.cloud.SolrZkClient; makePath: /collections/collection1/leaders/shard1
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:28.524; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper... 
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:28.569; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:28.586; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:28.586; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:28.624; org.apache.solr.cloud.ZkController; We are http://127.0.0.1:51537/yb_zzk/q/collection1/ and leader is http://127.0.0.1:51537/yb_zzk/q/collection1/
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:28.625; org.apache.solr.cloud.ZkController; No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:51537/yb_zzk/q
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:28.625; org.apache.solr.cloud.ZkController; I am the leader, no recovery necessary
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:28.626; org.apache.solr.cloud.ZkController; publishing core=collection1 state=active
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:28.626; org.apache.solr.cloud.ZkController; numShards not found on descriptor - reading it from system property
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:28.631; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper... 
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:28.635; org.apache.solr.servlet.SolrDispatchFilter; user.dir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:28.635; org.apache.solr.servlet.SolrDispatchFilter; SolrDispatchFilter.init() done
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:28.636; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:29.229; org.eclipse.jetty.server.Server; jetty-8.1.8.v20121106
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:29.263; org.eclipse.jetty.server.AbstractConnector; Started SelectChannelConnector@127.0.0.1:51540
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:29.265; org.apache.solr.servlet.SolrDispatchFilter; SolrDispatchFilter.init()
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:29.265; org.apache.solr.core.SolrResourceLoader; JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:29.266; org.apache.solr.core.SolrResourceLoader; using system property solr.solr.home: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty2-1366330048688
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:29.266; org.apache.solr.core.CoreContainer$Initializer; looking for solr config file: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty2-1366330048688/solr.xml
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:29.267; org.apache.solr.core.CoreContainer; New CoreContainer 169192677
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:29.267; org.apache.solr.core.CoreContainer; Loading CoreContainer using Solr Home: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty2-1366330048688/'
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:29.268; org.apache.solr.core.SolrResourceLoader; new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty2-1366330048688/'
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:29.563; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting socketTimeout to: 120000
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:29.564; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting urlScheme to: http://
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:29.565; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting connTimeout to: 15000
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:29.565; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maxConnectionsPerHost to: 20
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:29.566; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting corePoolSize to: 0
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:29.566; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maximumPoolSize to: 2147483647
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:29.567; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maxThreadIdleTime to: 5
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:29.567; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting sizeOfQueue to: -1
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:29.568; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting fairnessPolicy to: false
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:29.568; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:29.620; org.apache.solr.core.CoreContainer; Registering Log Listener
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:29.621; org.apache.solr.core.CoreContainer; Zookeeper client=127.0.0.1:51530/solr
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:29.622; org.apache.solr.cloud.ZkController; zkHost includes chroot
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:29.632; org.apache.solr.common.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:29.634; org.apache.solr.common.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionManager@50322f85 name:ZooKeeperConnection Watcher:127.0.0.1:51530 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:29.635; org.apache.solr.common.cloud.ConnectionManager; Client is connected to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:29.643; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4]   1> WARN  - 2013-04-19 00:07:29.656; org.apache.zookeeper.server.NIOServerCnxn; caught end of stream exception
[junit4:junit4]   1> EndOfStreamException: Unable to read additional data from client sessionid 0x13e1f9dcffb0007, likely client has closed socket
[junit4:junit4]   1> 	at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:220)
[junit4:junit4]   1> 	at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4:junit4]   1> 	at java.lang.Thread.run(Thread.java:680)
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:29.741; org.apache.solr.common.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:29.758; org.apache.solr.common.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionManager@7abe362b name:ZooKeeperConnection Watcher:127.0.0.1:51530/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:29.758; org.apache.solr.common.cloud.ConnectionManager; Client is connected to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:29.776; org.apache.solr.common.cloud.ZkStateReader; Updating cluster state from ZooKeeper... 
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:30.108; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper... 
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:30.111; org.apache.solr.cloud.Overseer$ClusterStateUpdater; Update state numShards=2 message={
[junit4:junit4]   1>   "operation":"state",
[junit4:junit4]   1>   "core_node_name":"2",
[junit4:junit4]   1>   "numShards":"2",
[junit4:junit4]   1>   "shard":"shard1",
[junit4:junit4]   1>   "roles":null,
[junit4:junit4]   1>   "state":"active",
[junit4:junit4]   1>   "shard_state":"active",
[junit4:junit4]   1>   "core":"collection1",
[junit4:junit4]   1>   "collection":"collection1",
[junit4:junit4]   1>   "shard_range":null,
[junit4:junit4]   1>   "node_name":"127.0.0.1:51537_yb_zzk%2Fq",
[junit4:junit4]   1>   "base_url":"http://127.0.0.1:51537/yb_zzk/q"}
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:30.133; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:30.140; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:30.140; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:30.141; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:30.804; org.apache.solr.cloud.ZkController; Register node as live in ZooKeeper:/live_nodes/127.0.0.1:51540_yb_zzk%2Fq
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:30.809; org.apache.solr.common.cloud.SolrZkClient; makePath: /live_nodes/127.0.0.1:51540_yb_zzk%2Fq
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:30.825; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 2)
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:30.826; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 2)
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:30.826; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 2)
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:30.831; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (3)
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:30.832; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:30.839; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (3)
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:30.840; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (3)
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:30.841; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (3)
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:30.857; org.apache.solr.core.CoreContainer; Creating SolrCore 'collection1' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty2-1366330048688/collection1
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:30.858; org.apache.solr.cloud.ZkController; Check for collection zkNode:collection1
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:30.860; org.apache.solr.cloud.ZkController; Collection zkNode exists
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:30.861; org.apache.solr.cloud.ZkController; Load collection config from:/collections/collection1
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:30.867; org.apache.solr.core.SolrResourceLoader; new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty2-1366330048688/collection1/'
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:30.869; org.apache.solr.core.SolrResourceLoader; Adding 'file:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-jetty2-1366330048688/collection1/lib/classes/' to classloader
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:30.870; org.apache.solr.core.SolrResourceLoader; Adding 'file:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-jetty2-1366330048688/collection1/lib/README' to classloader
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:30.965; org.apache.solr.core.SolrConfig; Using Lucene MatchVersion: LUCENE_44
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:31.180; org.apache.solr.core.SolrConfig; Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:31.249; org.apache.solr.schema.IndexSchema; Reading Solr Schema from schema.xml
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:31.257; org.apache.solr.schema.IndexSchema; Schema name=test
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:32.991; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:33.031; org.apache.solr.schema.IndexSchema; default search field in schema is text
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:33.036; org.apache.solr.schema.IndexSchema; unique key field: id
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:33.092; org.apache.solr.schema.FileExchangeRateProvider; Reloading exchange rates from file currency.xml
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:33.108; org.apache.solr.schema.FileExchangeRateProvider; Reloading exchange rates from file currency.xml
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:33.121; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   1> WARN  - 2013-04-19 00:07:33.126; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOTE
[junit4:junit4]   1> WARN  - 2013-04-19 00:07:33.127; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:33.128; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   1> WARN  - 2013-04-19 00:07:33.132; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOTE
[junit4:junit4]   1> WARN  - 2013-04-19 00:07:33.132; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:33.133; org.apache.solr.core.SolrCore; org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:33.133; org.apache.solr.core.SolrCore; [collection1] Opening new SolrCore at /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty2-1366330048688/collection1/, dataDir=./org.apache.solr.cloud.ShardSplitTest-1366330036205/jetty2/
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:33.134; org.apache.solr.core.JmxMonitoredMap; JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@508de972
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:33.135; org.apache.solr.core.SolrCore; org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:33.136; org.apache.solr.core.CachingDirectoryFactory; return new directory for ./org.apache.solr.cloud.ShardSplitTest-1366330036205/jetty2
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:33.136; org.apache.solr.core.SolrCore; New index directory detected: old=null new=./org.apache.solr.cloud.ShardSplitTest-1366330036205/jetty2/index/
[junit4:junit4]   1> WARN  - 2013-04-19 00:07:33.137; org.apache.solr.core.SolrCore; [collection1] Solr index directory './org.apache.solr.cloud.ShardSplitTest-1366330036205/jetty2/index' doesn't exist. Creating new index...
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:33.137; org.apache.solr.core.CachingDirectoryFactory; return new directory for ./org.apache.solr.cloud.ShardSplitTest-1366330036205/jetty2/index
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:33.143; org.apache.solr.core.SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   1> 	commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@44f4d67a lockFactory=org.apache.lucene.store.NativeFSLockFactory@38f4596e),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:33.143; org.apache.solr.core.SolrDeletionPolicy; newest commit = 1[segments_1]
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:33.148; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:33.153; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:33.159; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:33.160; org.apache.solr.core.RequestHandlers; created standard: solr.StandardRequestHandler
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:33.162; org.apache.solr.core.RequestHandlers; created /get: solr.RealTimeGetHandler
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:33.162; org.apache.solr.core.RequestHandlers; adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:33.162; org.apache.solr.core.RequestHandlers; created /replication: solr.ReplicationHandler
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:33.163; org.apache.solr.core.RequestHandlers; created /update: solr.UpdateRequestHandler
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:33.164; org.apache.solr.core.RequestHandlers; created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:33.176; org.apache.solr.handler.loader.XMLLoader; xsltCacheLifetimeSeconds=60
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:33.225; org.apache.solr.search.SolrIndexSearcher; Opening Searcher@5ad54694 main
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:33.226; org.apache.solr.update.UpdateHandler; Clearing tlog files, tlogDir=./org.apache.solr.cloud.ShardSplitTest-1366330036205/jetty2/tlog
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:33.228; org.apache.solr.update.CommitTracker; Hard AutoCommit: disabled
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:33.228; org.apache.solr.update.CommitTracker; Soft AutoCommit: disabled
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:33.236; org.apache.solr.core.SolrCore; [collection1] Registered new searcher Searcher@5ad54694 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:33.240; org.apache.solr.cloud.ZkController; publishing core=collection1 state=down
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:33.241; org.apache.solr.cloud.ZkController; numShards not found on descriptor - reading it from system property
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:34.727; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper... 
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:34.730; org.apache.solr.cloud.Overseer$ClusterStateUpdater; Update state numShards=2 message={
[junit4:junit4]   1>   "operation":"state",
[junit4:junit4]   1>   "core_node_name":"3",
[junit4:junit4]   1>   "numShards":"2",
[junit4:junit4]   1>   "shard":null,
[junit4:junit4]   1>   "roles":null,
[junit4:junit4]   1>   "state":"down",
[junit4:junit4]   1>   "shard_state":"active",
[junit4:junit4]   1>   "core":"collection1",
[junit4:junit4]   1>   "collection":"collection1",
[junit4:junit4]   1>   "shard_range":null,
[junit4:junit4]   1>   "node_name":"127.0.0.1:51540_yb_zzk%2Fq",
[junit4:junit4]   1>   "base_url":"http://127.0.0.1:51540/yb_zzk/q"}
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:34.731; org.apache.solr.cloud.Overseer$ClusterStateUpdater; Collection already exists with numShards=2
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:34.731; org.apache.solr.cloud.Overseer$ClusterStateUpdater; Assigning new node to shard=shard2
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:34.747; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:34.747; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:34.753; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:34.754; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:35.247; org.apache.solr.core.CoreContainer; registering core: collection1
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:35.247; org.apache.solr.cloud.ZkController; Register replica - core:collection1 address:http://127.0.0.1:51540/yb_zzk/q collection:collection1 shard:shard2
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:35.253; org.apache.solr.common.cloud.SolrZkClient; makePath: /collections/collection1/leader_elect/shard2/election
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:35.276; org.apache.solr.cloud.ShardLeaderElectionContext; Running the leader process.
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:35.285; org.apache.solr.cloud.ShardLeaderElectionContext; Enough replicas found to continue.
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:35.285; org.apache.solr.cloud.ShardLeaderElectionContext; I may be the new leader - try and sync
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:35.285; org.apache.solr.cloud.SyncStrategy; Sync replicas to http://127.0.0.1:51540/yb_zzk/q/collection1/
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:35.286; org.apache.solr.cloud.SyncStrategy; Sync Success - now sync replicas to me
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:35.286; org.apache.solr.cloud.SyncStrategy; http://127.0.0.1:51540/yb_zzk/q/collection1/ has no replicas
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:35.286; org.apache.solr.cloud.ShardLeaderElectionContext; I am the new leader: http://127.0.0.1:51540/yb_zzk/q/collection1/
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:35.286; org.apache.solr.common.cloud.SolrZkClient; makePath: /collections/collection1/leaders/shard2
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:36.274; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper... 
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:36.306; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:36.307; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:36.307; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:36.308; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:36.355; org.apache.solr.cloud.ZkController; We are http://127.0.0.1:51540/yb_zzk/q/collection1/ and leader is http://127.0.0.1:51540/yb_zzk/q/collection1/
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:36.355; org.apache.solr.cloud.ZkController; No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:51540/yb_zzk/q
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:36.356; org.apache.solr.cloud.ZkController; I am the leader, no recovery necessary
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:36.356; org.apache.solr.cloud.ZkController; publishing core=collection1 state=active
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:36.356; org.apache.solr.cloud.ZkController; numShards not found on descriptor - reading it from system property
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:36.363; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper... 
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:36.366; org.apache.solr.servlet.SolrDispatchFilter; user.dir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:36.367; org.apache.solr.servlet.SolrDispatchFilter; SolrDispatchFilter.init() done
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:36.367; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:36.971; org.eclipse.jetty.server.Server; jetty-8.1.8.v20121106
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:36.981; org.eclipse.jetty.server.AbstractConnector; Started SelectChannelConnector@127.0.0.1:51543
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:36.982; org.apache.solr.servlet.SolrDispatchFilter; SolrDispatchFilter.init()
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:36.983; org.apache.solr.core.SolrResourceLoader; JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:36.983; org.apache.solr.core.SolrResourceLoader; using system property solr.solr.home: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty3-1366330056424
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:36.984; org.apache.solr.core.CoreContainer$Initializer; looking for solr config file: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty3-1366330056424/solr.xml
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:36.984; org.apache.solr.core.CoreContainer; New CoreContainer 1267974885
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:36.985; org.apache.solr.core.CoreContainer; Loading CoreContainer using Solr Home: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty3-1366330056424/'
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:36.985; org.apache.solr.core.SolrResourceLoader; new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty3-1366330056424/'
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:37.296; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting socketTimeout to: 120000
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:37.297; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting urlScheme to: http://
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:37.297; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting connTimeout to: 15000
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:37.298; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maxConnectionsPerHost to: 20
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:37.298; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting corePoolSize to: 0
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:37.299; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maximumPoolSize to: 2147483647
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:37.299; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maxThreadIdleTime to: 5
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:37.300; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting sizeOfQueue to: -1
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:37.300; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting fairnessPolicy to: false
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:37.303; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:37.357; org.apache.solr.core.CoreContainer; Registering Log Listener
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:37.358; org.apache.solr.core.CoreContainer; Zookeeper client=127.0.0.1:51530/solr
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:37.359; org.apache.solr.cloud.ZkController; zkHost includes chroot
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:37.362; org.apache.solr.common.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:37.370; org.apache.solr.common.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionManager@23f39002 name:ZooKeeperConnection Watcher:127.0.0.1:51530 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:37.372; org.apache.solr.common.cloud.ConnectionManager; Client is connected to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:37.379; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:37.430; org.apache.solr.common.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:37.437; org.apache.solr.common.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionManager@becbc86 name:ZooKeeperConnection Watcher:127.0.0.1:51530/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:37.437; org.apache.solr.common.cloud.ConnectionManager; Client is connected to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:37.453; org.apache.solr.common.cloud.ZkStateReader; Updating cluster state from ZooKeeper... 
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:37.840; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper... 
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:37.842; org.apache.solr.cloud.Overseer$ClusterStateUpdater; Update state numShards=2 message={
[junit4:junit4]   1>   "operation":"state",
[junit4:junit4]   1>   "core_node_name":"3",
[junit4:junit4]   1>   "numShards":"2",
[junit4:junit4]   1>   "shard":"shard2",
[junit4:junit4]   1>   "roles":null,
[junit4:junit4]   1>   "state":"active",
[junit4:junit4]   1>   "shard_state":"active",
[junit4:junit4]   1>   "core":"collection1",
[junit4:junit4]   1>   "collection":"collection1",
[junit4:junit4]   1>   "shard_range":null,
[junit4:junit4]   1>   "node_name":"127.0.0.1:51540_yb_zzk%2Fq",
[junit4:junit4]   1>   "base_url":"http://127.0.0.1:51540/yb_zzk/q"}
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:37.861; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:37.867; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:37.867; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:37.874; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:37.874; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:38.470; org.apache.solr.cloud.ZkController; Register node as live in ZooKeeper:/live_nodes/127.0.0.1:51543_yb_zzk%2Fq
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:38.473; org.apache.solr.common.cloud.SolrZkClient; makePath: /live_nodes/127.0.0.1:51543_yb_zzk%2Fq
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:38.485; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (4)
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:38.485; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:38.485; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (4)
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:38.486; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:38.492; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:38.499; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (4)
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:38.500; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:38.507; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (4)
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:38.508; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:38.522; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (4)
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:38.542; org.apache.solr.core.CoreContainer; Creating SolrCore 'collection1' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty3-1366330056424/collection1
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:38.542; org.apache.solr.cloud.ZkController; Check for collection zkNode:collection1
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:38.567; org.apache.solr.cloud.ZkController; Collection zkNode exists
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:38.567; org.apache.solr.cloud.ZkController; Load collection config from:/collections/collection1
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:38.571; org.apache.solr.core.SolrResourceLoader; new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty3-1366330056424/collection1/'
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:38.578; org.apache.solr.core.SolrResourceLoader; Adding 'file:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-jetty3-1366330056424/collection1/lib/classes/' to classloader
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:38.578; org.apache.solr.core.SolrResourceLoader; Adding 'file:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-jetty3-1366330056424/collection1/lib/README' to classloader
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:38.697; org.apache.solr.core.SolrConfig; Using Lucene MatchVersion: LUCENE_44
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:38.811; org.apache.solr.core.SolrConfig; Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:38.816; org.apache.solr.schema.IndexSchema; Reading Solr Schema from schema.xml
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:38.825; org.apache.solr.schema.IndexSchema; Schema name=test
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:39.943; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:39.961; org.apache.solr.schema.IndexSchema; default search field in schema is text
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:39.968; org.apache.solr.schema.IndexSchema; unique key field: id
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:40.020; org.apache.solr.schema.FileExchangeRateProvider; Reloading exchange rates from file currency.xml
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:40.029; org.apache.solr.schema.FileExchangeRateProvider; Reloading exchange rates from file currency.xml
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:40.039; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   1> WARN  - 2013-04-19 00:07:40.046; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOTE
[junit4:junit4]   1> WARN  - 2013-04-19 00:07:40.050; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:40.051; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   1> WARN  - 2013-04-19 00:07:40.055; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOTE
[junit4:junit4]   1> WARN  - 2013-04-19 00:07:40.055; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:40.055; org.apache.solr.core.SolrCore; org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:40.056; org.apache.solr.core.SolrCore; [collection1] Opening new SolrCore at /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty3-1366330056424/collection1/, dataDir=./org.apache.solr.cloud.ShardSplitTest-1366330036205/jetty3/
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:40.056; org.apache.solr.core.JmxMonitoredMap; JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@508de972
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:40.057; org.apache.solr.core.SolrCore; org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:40.058; org.apache.solr.core.CachingDirectoryFactory; return new directory for ./org.apache.solr.cloud.ShardSplitTest-1366330036205/jetty3
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:40.059; org.apache.solr.core.SolrCore; New index directory detected: old=null new=./org.apache.solr.cloud.ShardSplitTest-1366330036205/jetty3/index/
[junit4:junit4]   1> WARN  - 2013-04-19 00:07:40.059; org.apache.solr.core.SolrCore; [collection1] Solr index directory './org.apache.solr.cloud.ShardSplitTest-1366330036205/jetty3/index' doesn't exist. Creating new index...
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:40.059; org.apache.solr.core.CachingDirectoryFactory; return new directory for ./org.apache.solr.cloud.ShardSplitTest-1366330036205/jetty3/index
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:40.065; org.apache.solr.core.SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   1> 	commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@70cd7d24 lockFactory=org.apache.lucene.store.NativeFSLockFactory@783b3f7b),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:40.066; org.apache.solr.core.SolrDeletionPolicy; newest commit = 1[segments_1]
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:40.074; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:40.075; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:40.076; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:40.077; org.apache.solr.core.RequestHandlers; created standard: solr.StandardRequestHandler
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:40.078; org.apache.solr.core.RequestHandlers; created /get: solr.RealTimeGetHandler
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:40.078; org.apache.solr.core.RequestHandlers; adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:40.079; org.apache.solr.core.RequestHandlers; created /replication: solr.ReplicationHandler
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:40.080; org.apache.solr.core.RequestHandlers; created /update: solr.UpdateRequestHandler
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:40.081; org.apache.solr.core.RequestHandlers; created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:40.093; org.apache.solr.handler.loader.XMLLoader; xsltCacheLifetimeSeconds=60
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:40.106; org.apache.solr.search.SolrIndexSearcher; Opening Searcher@5ab9c149 main
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:40.107; org.apache.solr.update.UpdateHandler; Clearing tlog files, tlogDir=./org.apache.solr.cloud.ShardSplitTest-1366330036205/jetty3/tlog
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:40.111; org.apache.solr.update.CommitTracker; Hard AutoCommit: disabled
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:40.111; org.apache.solr.update.CommitTracker; Soft AutoCommit: disabled
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:40.124; org.apache.solr.core.SolrCore; [collection1] Registered new searcher Searcher@5ab9c149 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:40.129; org.apache.solr.cloud.ZkController; publishing core=collection1 state=down
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:40.129; org.apache.solr.cloud.ZkController; numShards not found on descriptor - reading it from system property
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:40.913; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper... 
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:40.916; org.apache.solr.cloud.Overseer$ClusterStateUpdater; Update state numShards=2 message={
[junit4:junit4]   1>   "operation":"state",
[junit4:junit4]   1>   "core_node_name":"4",
[junit4:junit4]   1>   "numShards":"2",
[junit4:junit4]   1>   "shard":null,
[junit4:junit4]   1>   "roles":null,
[junit4:junit4]   1>   "state":"down",
[junit4:junit4]   1>   "shard_state":"active",
[junit4:junit4]   1>   "core":"collection1",
[junit4:junit4]   1>   "collection":"collection1",
[junit4:junit4]   1>   "shard_range":null,
[junit4:junit4]   1>   "node_name":"127.0.0.1:51543_yb_zzk%2Fq",
[junit4:junit4]   1>   "base_url":"http://127.0.0.1:51543/yb_zzk/q"}
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:40.916; org.apache.solr.cloud.Overseer$ClusterStateUpdater; Collection already exists with numShards=2
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:40.916; org.apache.solr.cloud.Overseer$ClusterStateUpdater; Assigning new node to shard=shard1
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:40.935; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:40.936; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:40.936; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:40.937; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:40.935; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:41.135; org.apache.solr.core.CoreContainer; registering core: collection1
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:41.136; org.apache.solr.cloud.ZkController; Register replica - core:collection1 address:http://127.0.0.1:51543/yb_zzk/q collection:collection1 shard:shard1
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:41.147; org.apache.solr.cloud.ZkController; We are http://127.0.0.1:51543/yb_zzk/q/collection1/ and leader is http://127.0.0.1:51537/yb_zzk/q/collection1/
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:41.148; org.apache.solr.cloud.ZkController; No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:51543/yb_zzk/q
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:41.149; org.apache.solr.cloud.ZkController; Core needs to recover:collection1
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:41.149; org.apache.solr.update.DefaultSolrCoreState; Running recovery - first canceling any ongoing recovery
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:41.151; org.apache.solr.cloud.RecoveryStrategy; Starting recovery process.  core=collection1 recoveringAfterStartup=true
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:41.153; org.apache.solr.cloud.RecoveryStrategy; ###### startupVersions=[]
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:41.154; org.apache.solr.cloud.ZkController; publishing core=collection1 state=recovering
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:41.154; org.apache.solr.cloud.ZkController; numShards not found on descriptor - reading it from system property
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:41.159; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:41.170; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper... 
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:41.191; org.apache.solr.servlet.SolrDispatchFilter; user.dir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:41.192; org.apache.solr.servlet.SolrDispatchFilter; SolrDispatchFilter.init() done
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:41.193; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:41.228; org.apache.solr.handler.admin.CoreAdminHandler; Going to wait for coreNodeName: 4, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:41.790; org.eclipse.jetty.server.Server; jetty-8.1.8.v20121106
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:41.820; org.eclipse.jetty.server.AbstractConnector; Started SelectChannelConnector@127.0.0.1:51547
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:41.823; org.apache.solr.servlet.SolrDispatchFilter; SolrDispatchFilter.init()
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:41.823; org.apache.solr.core.SolrResourceLoader; JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:41.824; org.apache.solr.core.SolrResourceLoader; using system property solr.solr.home: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty4-1366330061251
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:41.825; org.apache.solr.core.CoreContainer$Initializer; looking for solr config file: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty4-1366330061251/solr.xml
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:41.826; org.apache.solr.core.CoreContainer; New CoreContainer 1810038970
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:41.827; org.apache.solr.core.CoreContainer; Loading CoreContainer using Solr Home: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty4-1366330061251/'
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:41.828; org.apache.solr.core.SolrResourceLoader; new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty4-1366330061251/'
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:42.124; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting socketTimeout to: 120000
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:42.125; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting urlScheme to: http://
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:42.126; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting connTimeout to: 15000
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:42.126; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maxConnectionsPerHost to: 20
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:42.127; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting corePoolSize to: 0
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:42.127; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maximumPoolSize to: 2147483647
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:42.128; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maxThreadIdleTime to: 5
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:42.129; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting sizeOfQueue to: -1
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:42.129; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting fairnessPolicy to: false
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:42.130; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:42.186; org.apache.solr.core.CoreContainer; Registering Log Listener
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:42.187; org.apache.solr.core.CoreContainer; Zookeeper client=127.0.0.1:51530/solr
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:42.188; org.apache.solr.cloud.ZkController; zkHost includes chroot
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:42.219; org.apache.solr.common.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:42.224; org.apache.solr.common.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionManager@30444c18 name:ZooKeeperConnection Watcher:127.0.0.1:51530 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:42.225; org.apache.solr.common.cloud.ConnectionManager; Client is connected to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:42.231; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:42.282; org.apache.solr.common.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:42.289; org.apache.solr.common.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionManager@2d34f41e name:ZooKeeperConnection Watcher:127.0.0.1:51530/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:42.290; org.apache.solr.common.cloud.ConnectionManager; Client is connected to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:42.304; org.apache.solr.common.cloud.ZkStateReader; Updating cluster state from ZooKeeper... 
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:42.463; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper... 
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:42.466; org.apache.solr.cloud.Overseer$ClusterStateUpdater; Update state numShards=2 message={
[junit4:junit4]   1>   "operation":"state",
[junit4:junit4]   1>   "core_node_name":"4",
[junit4:junit4]   1>   "numShards":"2",
[junit4:junit4]   1>   "shard":"shard1",
[junit4:junit4]   1>   "roles":null,
[junit4:junit4]   1>   "state":"recovering",
[junit4:junit4]   1>   "shard_state":"active",
[junit4:junit4]   1>   "core":"collection1",
[junit4:junit4]   1>   "collection":"collection1",
[junit4:junit4]   1>   "shard_range":null,
[junit4:junit4]   1>   "node_name":"127.0.0.1:51543_yb_zzk%2Fq",
[junit4:junit4]   1>   "base_url":"http://127.0.0.1:51543/yb_zzk/q"}
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:42.481; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:42.482; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:42.485; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:42.491; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:42.491; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:42.491; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:43.231; org.apache.solr.handler.admin.CoreAdminHandler; Waited coreNodeName: 4, state: recovering, checkLive: true, onlyIfLeader: true for: 2 seconds.
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:43.232; org.apache.solr.servlet.SolrDispatchFilter; [admin] webapp=null path=/admin/cores params={coreNodeName=4&state=recovering&nodeName=127.0.0.1:51543_yb_zzk%252Fq&action=PREPRECOVERY&checkLive=true&core=collection1&wt=javabin&onlyIfLeader=true&version=2} status=0 QTime=2004 
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:43.316; org.apache.solr.cloud.ZkController; Register node as live in ZooKeeper:/live_nodes/127.0.0.1:51547_yb_zzk%2Fq
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:43.321; org.apache.solr.common.cloud.SolrZkClient; makePath: /live_nodes/127.0.0.1:51547_yb_zzk%2Fq
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:43.338; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:43.342; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:43.350; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:43.356; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (5)
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:43.357; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:43.370; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (5)
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:43.370; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:43.381; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (5)
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:43.382; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:43.389; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (5)
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:43.389; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (5)
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:43.394; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (5)
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:43.414; org.apache.solr.core.CoreContainer; Creating SolrCore 'collection1' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty4-1366330061251/collection1
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:43.414; org.apache.solr.cloud.ZkController; Check for collection zkNode:collection1
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:43.420; org.apache.solr.cloud.ZkController; Collection zkNode exists
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:43.423; org.apache.solr.cloud.ZkController; Load collection config from:/collections/collection1
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:43.428; org.apache.solr.core.SolrResourceLoader; new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty4-1366330061251/collection1/'
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:43.430; org.apache.solr.core.SolrResourceLoader; Adding 'file:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-jetty4-1366330061251/collection1/lib/classes/' to classloader
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:43.431; org.apache.solr.core.SolrResourceLoader; Adding 'file:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-jetty4-1366330061251/collection1/lib/README' to classloader
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:43.538; org.apache.solr.core.SolrConfig; Using Lucene MatchVersion: LUCENE_44
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:43.660; org.apache.solr.core.SolrConfig; Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:43.665; org.apache.solr.schema.IndexSchema; Reading Solr Schema from schema.xml
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:43.688; org.apache.solr.schema.IndexSchema; Schema name=test
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:44.850; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:44.868; org.apache.solr.schema.IndexSchema; default search field in schema is text
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:44.875; org.apache.solr.schema.IndexSchema; unique key field: id
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:44.929; org.apache.solr.schema.FileExchangeRateProvider; Reloading exchange rates from file currency.xml
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:44.939; org.apache.solr.schema.FileExchangeRateProvider; Reloading exchange rates from file currency.xml
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:44.948; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   1> WARN  - 2013-04-19 00:07:44.958; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOTE
[junit4:junit4]   1> WARN  - 2013-04-19 00:07:44.959; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:44.959; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   1> WARN  - 2013-04-19 00:07:44.965; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOTE
[junit4:junit4]   1> WARN  - 2013-04-19 00:07:44.965; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:44.966; org.apache.solr.core.SolrCore; org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:44.966; org.apache.solr.core.SolrCore; [collection1] Opening new SolrCore at /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty4-1366330061251/collection1/, dataDir=./org.apache.solr.cloud.ShardSplitTest-1366330036205/jetty4/
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:44.966; org.apache.solr.core.JmxMonitoredMap; JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@508de972
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:44.967; org.apache.solr.core.SolrCore; org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:44.968; org.apache.solr.core.CachingDirectoryFactory; return new directory for ./org.apache.solr.cloud.ShardSplitTest-1366330036205/jetty4
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:44.968; org.apache.solr.core.SolrCore; New index directory detected: old=null new=./org.apache.solr.cloud.ShardSplitTest-1366330036205/jetty4/index/
[junit4:junit4]   1> WARN  - 2013-04-19 00:07:44.969; org.apache.solr.core.SolrCore; [collection1] Solr index directory './org.apache.solr.cloud.ShardSplitTest-1366330036205/jetty4/index' doesn't exist. Creating new index...
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:44.970; org.apache.solr.core.CachingDirectoryFactory; return new directory for ./org.apache.solr.cloud.ShardSplitTest-1366330036205/jetty4/index
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:44.975; org.apache.solr.core.SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   1> 	commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@5f3ac618 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1906c58a),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:44.975; org.apache.solr.core.SolrDeletionPolicy; newest commit = 1[segments_1]
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:44.980; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:44.981; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:44.983; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:44.984; org.apache.solr.core.RequestHandlers; created standard: solr.StandardRequestHandler
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:44.985; org.apache.solr.core.RequestHandlers; created /get: solr.RealTimeGetHandler
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:44.985; org.apache.solr.core.RequestHandlers; adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:44.986; org.apache.solr.core.RequestHandlers; created /replication: solr.ReplicationHandler
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:44.987; org.apache.solr.core.RequestHandlers; created /update: solr.UpdateRequestHandler
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:44.988; org.apache.solr.core.RequestHandlers; created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:44.999; org.apache.solr.handler.loader.XMLLoader; xsltCacheLifetimeSeconds=60
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:45.011; org.apache.solr.search.SolrIndexSearcher; Opening Searcher@3f8eebb6 main
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:45.012; org.apache.solr.update.UpdateHandler; Clearing tlog files, tlogDir=./org.apache.solr.cloud.ShardSplitTest-1366330036205/jetty4/tlog
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:45.013; org.apache.solr.update.CommitTracker; Hard AutoCommit: disabled
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:45.014; org.apache.solr.update.CommitTracker; Soft AutoCommit: disabled
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:45.031; org.apache.solr.core.SolrCore; [collection1] Registered new searcher Searcher@3f8eebb6 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:45.033; org.apache.solr.cloud.ZkController; publishing core=collection1 state=down
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:45.034; org.apache.solr.cloud.ZkController; numShards not found on descriptor - reading it from system property
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:45.235; org.apache.solr.cloud.RecoveryStrategy; Attempting to PeerSync from http://127.0.0.1:51537/yb_zzk/q/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:45.235; org.apache.solr.update.PeerSync; PeerSync: core=collection1 url=http://127.0.0.1:51543/yb_zzk/q START replicas=[http://127.0.0.1:51537/yb_zzk/q/collection1/] nUpdates=100
[junit4:junit4]   1> WARN  - 2013-04-19 00:07:45.236; org.apache.solr.update.PeerSync; no frame of reference to tell of we've missed updates
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:45.237; org.apache.solr.cloud.RecoveryStrategy; PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:45.238; org.apache.solr.cloud.RecoveryStrategy; Starting Replication Recovery. core=collection1
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:45.238; org.apache.solr.cloud.RecoveryStrategy; Begin buffering updates. core=collection1
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:45.240; org.apache.solr.update.UpdateLog; Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:45.242; org.apache.solr.cloud.RecoveryStrategy; Attempting to replicate from http://127.0.0.1:51537/yb_zzk/q/collection1/. core=collection1
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:45.242; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:45.284; org.apache.solr.core.SolrCore; [collection1] webapp=/yb_zzk/q path=/get params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=0 
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:45.318; org.apache.solr.update.DirectUpdateHandler2; start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:45.322; org.apache.solr.core.SolrDeletionPolicy; SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   1> 	commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@ec3b565 lockFactory=org.apache.lucene.store.NativeFSLockFactory@181f9666),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:45.323; org.apache.solr.core.SolrDeletionPolicy; newest commit = 1[segments_1]
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:45.324; org.apache.solr.core.SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   1> 	commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@ec3b565 lockFactory=org.apache.lucene.store.NativeFSLockFactory@181f9666),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   1> 	commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@ec3b565 lockFactory=org.apache.lucene.store.NativeFSLockFactory@181f9666),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:45.325; org.apache.solr.core.SolrDeletionPolicy; newest commit = 2[segments_2]
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:45.326; org.apache.solr.search.SolrIndexSearcher; Opening Searcher@e5a0fc1 realtime
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:45.326; org.apache.solr.update.DirectUpdateHandler2; end_commit_flush
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:45.326; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={waitSearcher=true&openSearcher=false&commit=true&wt=javabin&commit_end_point=true&version=2&softCommit=false} {commit=} 0 8
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:45.328; org.apache.solr.handler.ReplicationHandler; Commits will be reserved for  10000
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:45.329; org.apache.solr.handler.SnapPuller;  No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:45.339; org.apache.solr.handler.ReplicationHandler; Commits will be reserved for  10000
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:45.339; org.apache.solr.core.SolrCore; [collection1] webapp=/yb_zzk/q path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=2 
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:45.341; org.apache.solr.handler.SnapPuller; Master's generation: 2
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:45.341; org.apache.solr.handler.SnapPuller; Slave's generation: 1
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:45.342; org.apache.solr.handler.SnapPuller; Starting replication process
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:45.345; org.apache.solr.core.SolrCore; [collection1] webapp=/yb_zzk/q path=/replication params={command=filelist&qt=/replication&wt=javabin&generation=2&version=2} status=0 QTime=0 
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:45.347; org.apache.solr.handler.SnapPuller; Number of files in latest index in master: 1
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:45.348; org.apache.solr.core.CachingDirectoryFactory; return new directory for ./org.apache.solr.cloud.ShardSplitTest-1366330036205/jetty3/index.20130419020745347
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:45.349; org.apache.solr.handler.SnapPuller; Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory@1e69555f lockFactory=org.apache.lucene.store.NativeFSLockFactory@4a88d537) fullCopy=false
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:45.352; org.apache.solr.core.SolrCore; [collection1] webapp=/yb_zzk/q path=/replication params={file=segments_2&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0 
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:45.356; org.apache.solr.handler.SnapPuller; Total time taken for download : 0 secs
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:45.357; org.apache.solr.update.DefaultSolrCoreState; Creating new IndexWriter...
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:45.358; org.apache.solr.update.DefaultSolrCoreState; Waiting until IndexWriter is unused... core=collection1
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:45.361; org.apache.solr.core.SolrDeletionPolicy; SolrDeletionPolicy.onInit: commits:num=2
[junit4:junit4]   1> 	commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@70cd7d24 lockFactory=org.apache.lucene.store.NativeFSLockFactory@783b3f7b),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   1> 	commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@70cd7d24 lockFactory=org.apache.lucene.store.NativeFSLockFactory@783b3f7b),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:45.361; org.apache.solr.core.SolrDeletionPolicy; newest commit = 2[segments_2]
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:45.362; org.apache.solr.update.DefaultSolrCoreState; New IndexWriter is ready to be used.
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:45.362; org.apache.solr.search.SolrIndexSearcher; Opening Searcher@4d6bb924 main
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:45.364; org.apache.solr.core.SolrCore; [collection1] Registered new searcher Searcher@4d6bb924 main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:45.366; org.apache.solr.core.CachingDirectoryFactory; looking to close ./org.apache.solr.cloud.ShardSplitTest-1366330036205/jetty3/index.20130419020745347 [CachedDir<<refCount=0;path=./org.apache.solr.cloud.ShardSplitTest-1366330036205/jetty3/index.20130419020745347;done=true>>]
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:45.366; org.apache.solr.core.CachingDirectoryFactory; Closing directory: ./org.apache.solr.cloud.ShardSplitTest-1366330036205/jetty3/index.20130419020745347
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:45.367; org.apache.solr.core.CachingDirectoryFactory; Removing directory before core close: ./org.apache.solr.cloud.ShardSplitTest-1366330036205/jetty3/index.20130419020745347
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:45.367; org.apache.solr.cloud.RecoveryStrategy; No replay needed. core=collection1
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:45.368; org.apache.solr.cloud.RecoveryStrategy; Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:45.369; org.apache.solr.cloud.ZkController; publishing core=collection1 state=active
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:45.370; org.apache.solr.cloud.ZkController; numShards not found on descriptor - reading it from system property
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:45.378; org.apache.solr.cloud.RecoveryStrategy; Finished recovery process. core=collection1
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:45.546; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper... 
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:45.549; org.apache.solr.cloud.Overseer$ClusterStateUpdater; Update state numShards=2 message={
[junit4:junit4]   1>   "operation":"state",
[junit4:junit4]   1>   "core_node_name":"5",
[junit4:junit4]   1>   "numShards":"2",
[junit4:junit4]   1>   "shard":null,
[junit4:junit4]   1>   "roles":null,
[junit4:junit4]   1>   "state":"down",
[junit4:junit4]   1>   "shard_state":"active",
[junit4:junit4]   1>   "core":"collection1",
[junit4:junit4]   1>   "collection":"collection1",
[junit4:junit4]   1>   "shard_range":null,
[junit4:junit4]   1>   "node_name":"127.0.0.1:51547_yb_zzk%2Fq",
[junit4:junit4]   1>   "base_url":"http://127.0.0.1:51547/yb_zzk/q"}
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:45.550; org.apache.solr.cloud.Overseer$ClusterStateUpdater; Collection already exists with numShards=2
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:45.550; org.apache.solr.cloud.Overseer$ClusterStateUpdater; Assigning new node to shard=shard2
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:45.562; org.apache.solr.cloud.Overseer$ClusterStateUpdater; Update state numShards=2 message={
[junit4:junit4]   1>   "operation":"state",
[junit4:junit4]   1>   "core_node_name":"4",
[junit4:junit4]   1>   "numShards":"2",
[junit4:junit4]   1>   "shard":"shard1",
[junit4:junit4]   1>   "roles":null,
[junit4:junit4]   1>   "state":"active",
[junit4:junit4]   1>   "shard_state":"active",
[junit4:junit4]   1>   "core":"collection1",
[junit4:junit4]   1>   "collection":"collection1",
[junit4:junit4]   1>   "shard_range":null,
[junit4:junit4]   1>   "node_name":"127.0.0.1:51543_yb_zzk%2Fq",
[junit4:junit4]   1>   "base_url":"http://127.0.0.1:51543/yb_zzk/q"}
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:45.576; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:45.576; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:45.577; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:45.577; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:45.580; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:45.582; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:46.038; org.apache.solr.core.CoreContainer; registering core: collection1
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:46.038; org.apache.solr.cloud.ZkController; Register replica - core:collection1 address:http://127.0.0.1:51547/yb_zzk/q collection:collection1 shard:shard2
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:46.060; org.apache.solr.cloud.ZkController; We are http://127.0.0.1:51547/yb_zzk/q/collection1/ and leader is http://127.0.0.1:51540/yb_zzk/q/collection1/
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:46.061; org.apache.solr.cloud.ZkController; No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:51547/yb_zzk/q
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:46.061; org.apache.solr.cloud.ZkController; Core needs to recover:collection1
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:46.062; org.apache.solr.update.DefaultSolrCoreState; Running recovery - first canceling any ongoing recovery
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:46.063; org.apache.solr.cloud.RecoveryStrategy; Starting recovery process.  core=collection1 recoveringAfterStartup=true
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:46.068; org.apache.solr.cloud.RecoveryStrategy; ###### startupVersions=[]
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:46.068; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper... 
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:46.069; org.apache.solr.cloud.ZkController; publishing core=collection1 state=recovering
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:46.070; org.apache.solr.cloud.ZkController; numShards not found on descriptor - reading it from system property
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:46.073; org.apache.solr.servlet.SolrDispatchFilter; user.dir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:46.074; org.apache.solr.servlet.SolrDispatchFilter; SolrDispatchFilter.init() done
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:46.073; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:46.075; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:46.136; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper... 
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:46.138; org.apache.solr.cloud.AbstractFullDistribZkTestBase; Wait for recoveries to finish - wait 15 for each attempt
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:46.139; org.apache.solr.cloud.AbstractDistribZkTestBase; Wait for recoveries to finish - collection: collection1 failOnTimeout:true timeout (sec):15
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:46.154; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper... 
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:46.162; org.apache.solr.handler.admin.CoreAdminHandler; Going to wait for coreNodeName: 5, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:47.120; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper... 
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:47.122; org.apache.solr.cloud.Overseer$ClusterStateUpdater; Update state numShards=2 message={
[junit4:junit4]   1>   "operation":"state",
[junit4:junit4]   1>   "core_node_name":"5",
[junit4:junit4]   1>   "numShards":"2",
[junit4:junit4]   1>   "shard":"shard2",
[junit4:junit4]   1>   "roles":null,
[junit4:junit4]   1>   "state":"recovering",
[junit4:junit4]   1>   "shard_state":"active",
[junit4:junit4]   1>   "core":"collection1",
[junit4:junit4]   1>   "collection":"collection1",
[junit4:junit4]   1>   "shard_range":null,
[junit4:junit4]   1>   "node_name":"127.0.0.1:51547_yb_zzk%2Fq",
[junit4:junit4]   1>   "base_url":"http://127.0.0.1:51547/yb_zzk/q"}
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:47.138; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:47.139; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:47.140; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:47.139; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:47.144; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:47.145; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:47.175; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper... 
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:48.164; org.apache.solr.handler.admin.CoreAdminHandler; Waited coreNodeName: 5, state: recovering, checkLive: true, onlyIfLeader: true for: 2 seconds.
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:48.165; org.apache.solr.servlet.SolrDispatchFilter; [admin] webapp=null path=/admin/cores params={coreNodeName=5&state=recovering&nodeName=127.0.0.1:51547_yb_zzk%252Fq&action=PREPRECOVERY&checkLive=true&core=collection1&wt=javabin&onlyIfLeader=true&version=2} status=0 QTime=2003 
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:48.190; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper... 
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:49.198; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper... 
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:50.167; org.apache.solr.cloud.RecoveryStrategy; Attempting to PeerSync from http://127.0.0.1:51540/yb_zzk/q/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:50.168; org.apache.solr.update.PeerSync; PeerSync: core=collection1 url=http://127.0.0.1:51547/yb_zzk/q START replicas=[http://127.0.0.1:51540/yb_zzk/q/collection1/] nUpdates=100
[junit4:junit4]   1> WARN  - 2013-04-19 00:07:50.168; org.apache.solr.update.PeerSync; no frame of reference to tell of we've missed updates
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:50.169; org.apache.solr.cloud.RecoveryStrategy; PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:50.169; org.apache.solr.cloud.RecoveryStrategy; Starting Replication Recovery. core=collection1
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:50.169; org.apache.solr.cloud.RecoveryStrategy; Begin buffering updates. core=collection1
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:50.170; org.apache.solr.update.UpdateLog; Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:50.170; org.apache.solr.cloud.RecoveryStrategy; Attempting to replicate from http://127.0.0.1:51540/yb_zzk/q/collection1/. core=collection1
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:50.178; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:50.208; org.apache.solr.core.SolrCore; [collection1] webapp=/yb_zzk/q path=/get params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=7 
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:50.210; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper... 
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:50.239; org.apache.solr.update.DirectUpdateHandler2; start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:50.243; org.apache.solr.core.SolrDeletionPolicy; SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   1> 	commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@44f4d67a lockFactory=org.apache.lucene.store.NativeFSLockFactory@38f4596e),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:50.244; org.apache.solr.core.SolrDeletionPolicy; newest commit = 1[segments_1]
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:50.245; org.apache.solr.core.SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   1> 	commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@44f4d67a lockFactory=org.apache.lucene.store.NativeFSLockFactory@38f4596e),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   1> 	commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@44f4d67a lockFactory=org.apache.lucene.store.NativeFSLockFactory@38f4596e),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:50.245; org.apache.solr.core.SolrDeletionPolicy; newest commit = 2[segments_2]
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:50.246; org.apache.solr.search.SolrIndexSearcher; Opening Searcher@1b6301f4 realtime
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:50.247; org.apache.solr.update.DirectUpdateHandler2; end_commit_flush
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:50.247; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={waitSearcher=true&openSearcher=false&commit=true&wt=javabin&commit_end_point=true&version=2&softCommit=false} {commit=} 0 8
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:50.250; org.apache.solr.handler.ReplicationHandler; Commits will be reserved for  10000
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:50.250; org.apache.solr.handler.SnapPuller;  No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:50.257; org.apache.solr.handler.ReplicationHandler; Commits will be reserved for  10000
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:50.258; org.apache.solr.core.SolrCore; [collection1] webapp=/yb_zzk/q path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=1 
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:50.259; org.apache.solr.handler.SnapPuller; Master's generation: 2
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:50.259; org.apache.solr.handler.SnapPuller; Slave's generation: 1
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:50.260; org.apache.solr.handler.SnapPuller; Starting replication process
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:50.263; org.apache.solr.core.SolrCore; [collection1] webapp=/yb_zzk/q path=/replication params={command=filelist&qt=/replication&wt=javabin&generation=2&version=2} status=0 QTime=1 
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:50.264; org.apache.solr.handler.SnapPuller; Number of files in latest index in master: 1
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:50.266; org.apache.solr.core.CachingDirectoryFactory; return new directory for ./org.apache.solr.cloud.ShardSplitTest-1366330036205/jetty4/index.20130419020750264
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:50.266; org.apache.solr.handler.SnapPuller; Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory@71290aac lockFactory=org.apache.lucene.store.NativeFSLockFactory@756ac549) fullCopy=false
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:50.269; org.apache.solr.core.SolrCore; [collection1] webapp=/yb_zzk/q path=/replication params={file=segments_2&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0 
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:50.278; org.apache.solr.handler.SnapPuller; Total time taken for download : 0 secs
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:50.280; org.apache.solr.update.DefaultSolrCoreState; Creating new IndexWriter...
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:50.281; org.apache.solr.update.DefaultSolrCoreState; Waiting until IndexWriter is unused... core=collection1
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:50.289; org.apache.solr.core.SolrDeletionPolicy; SolrDeletionPolicy.onInit: commits:num=2
[junit4:junit4]   1> 	commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@5f3ac618 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1906c58a),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   1> 	commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@5f3ac618 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1906c58a),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:50.291; org.apache.solr.core.SolrDeletionPolicy; newest commit = 2[segments_2]
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:50.291; org.apache.solr.update.DefaultSolrCoreState; New IndexWriter is ready to be used.
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:50.292; org.apache.solr.search.SolrIndexSearcher; Opening Searcher@719e63be main
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:50.294; org.apache.solr.core.SolrCore; [collection1] Registered new searcher Searcher@719e63be main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:50.297; org.apache.solr.core.CachingDirectoryFactory; looking to close ./org.apache.solr.cloud.ShardSplitTest-1366330036205/jetty4/index.20130419020750264 [CachedDir<<refCount=0;path=./org.apache.solr.cloud.ShardSplitTest-1366330036205/jetty4/index.20130419020750264;done=true>>]
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:50.297; org.apache.solr.core.CachingDirectoryFactory; Closing directory: ./org.apache.solr.cloud.ShardSplitTest-1366330036205/jetty4/index.20130419020750264
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:50.297; org.apache.solr.core.CachingDirectoryFactory; Removing directory before core close: ./org.apache.solr.cloud.ShardSplitTest-1366330036205/jetty4/index.20130419020750264
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:50.298; org.apache.solr.cloud.RecoveryStrategy; No replay needed. core=collection1
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:50.298; org.apache.solr.cloud.RecoveryStrategy; Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:50.298; org.apache.solr.cloud.ZkController; publishing core=collection1 state=active
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:50.298; org.apache.solr.cloud.ZkController; numShards not found on descriptor - reading it from system property
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:50.301; org.apache.solr.cloud.RecoveryStrategy; Finished recovery process. core=collection1
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:51.219; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper... 
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:51.703; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper... 
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:51.706; org.apache.solr.cloud.Overseer$ClusterStateUpdater; Update state numShards=2 message={
[junit4:junit4]   1>   "operation":"state",
[junit4:junit4]   1>   "core_node_name":"5",
[junit4:junit4]   1>   "numShards":"2",
[junit4:junit4]   1>   "shard":"shard2",
[junit4:junit4]   1>   "roles":null,
[junit4:junit4]   1>   "state":"active",
[junit4:junit4]   1>   "shard_state":"active",
[junit4:junit4]   1>   "core":"collection1",
[junit4:junit4]   1>   "collection":"collection1",
[junit4:junit4]   1>   "shard_range":null,
[junit4:junit4]   1>   "node_name":"127.0.0.1:51547_yb_zzk%2Fq",
[junit4:junit4]   1>   "base_url":"http://127.0.0.1:51547/yb_zzk/q"}
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:51.724; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:51.725; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:51.725; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:51.734; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:51.738; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:51.742; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:52.225; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper... 
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:52.235; org.apache.solr.cloud.AbstractDistribZkTestBase; Recoveries finished - collection: collection1
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:52.259; org.apache.solr.update.DirectUpdateHandler2; start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:52.264; org.apache.solr.core.SolrDeletionPolicy; SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   1> 	commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@7e938520 lockFactory=org.apache.lucene.store.NativeFSLockFactory@72019dcd),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:52.266; org.apache.solr.core.SolrDeletionPolicy; newest commit = 1[segments_1]
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:52.268; org.apache.solr.core.SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   1> 	commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@7e938520 lockFactory=org.apache.lucene.store.NativeFSLockFactory@72019dcd),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   1> 	commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@7e938520 lockFactory=org.apache.lucene.store.NativeFSLockFactory@72019dcd),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:52.268; org.apache.solr.core.SolrDeletionPolicy; newest commit = 2[segments_2]
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:52.269; org.apache.solr.search.SolrIndexSearcher; Opening Searcher@5fb08ca4 main
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:52.270; org.apache.solr.update.DirectUpdateHandler2; end_commit_flush
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:52.272; org.apache.solr.core.SolrCore; [collection1] Registered new searcher Searcher@5fb08ca4 main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:52.272; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={waitSearcher=true&commit=true&wt=javabin&version=2&softCommit=false} {commit=} 0 13
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:52.336; org.apache.solr.update.DirectUpdateHandler2; start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:52.339; org.apache.solr.core.SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   1> 	commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@ec3b565 lockFactory=org.apache.lucene.store.NativeFSLockFactory@181f9666),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   1> 	commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@ec3b565 lockFactory=org.apache.lucene.store.NativeFSLockFactory@181f9666),segFN=segments_3,generation=3,filenames=[segments_3]
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:52.339; org.apache.solr.core.SolrDeletionPolicy; newest commit = 3[segments_3]
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:52.340; org.apache.solr.search.SolrIndexSearcher; Opening Searcher@431f5ba2 main
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:52.341; org.apache.solr.update.DirectUpdateHandler2; end_commit_flush
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:52.342; org.apache.solr.core.SolrCore; [collection1] Registered new searcher Searcher@431f5ba2 main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:52.343; org.apache.solr.update.SolrCmdDistributor; Distrib commit to:[StdNode: http://127.0.0.1:51543/yb_zzk/q/collection1/, StdNode: http://127.0.0.1:51540/yb_zzk/q/collection1/, StdNode: http://127.0.0.1:51547/yb_zzk/q/collection1/] params:commit_end_point=true&commit=true&softCommit=false&waitSearcher=true&expungeDeletes=false
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:52.418; org.apache.solr.update.DirectUpdateHandler2; start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:52.430; org.apache.solr.update.DirectUpdateHandler2; start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:52.432; org.apache.solr.update.DirectUpdateHandler2; start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:52.435; org.apache.solr.core.SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   1> 	commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@5f3ac618 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1906c58a),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   1> 	commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@5f3ac618 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1906c58a),segFN=segments_3,generation=3,filenames=[segments_3]
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:52.436; org.apache.solr.core.SolrDeletionPolicy; newest commit = 3[segments_3]
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:52.436; org.apache.solr.search.SolrIndexSearcher; Opening Searcher@5c9fd14a main
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:52.437; org.apache.solr.update.DirectUpdateHandler2; end_commit_flush
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:52.439; org.apache.solr.core.SolrCore; [collection1] Registered new searcher Searcher@5c9fd14a main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:52.440; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={waitSearcher=true&commit=true&wt=javabin&expungeDeletes=false&commit_end_point=true&version=2&softCommit=false} {commit=} 0 22
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:52.443; org.apache.solr.core.SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   1> 	commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@70cd7d24 lockFactory=org.apache.lucene.store.NativeFSLockFactory@783b3f7b),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   1> 	commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@70cd7d24 lockFactory=org.apache.lucene.store.NativeFSLockFactory@783b3f7b),segFN=segments_3,generation=3,filenames=[segments_3]
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:52.444; org.apache.solr.core.SolrDeletionPolicy; newest commit = 3[segments_3]
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:52.446; org.apache.solr.search.SolrIndexSearcher; Opening Searcher@23bd25db main
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:52.447; org.apache.solr.update.DirectUpdateHandler2; end_commit_flush
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:52.448; org.apache.solr.core.SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   1> 	commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@44f4d67a lockFactory=org.apache.lucene.store.NativeFSLockFactory@38f4596e),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   1> 	commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@44f4d67a lockFactory=org.apache.lucene.store.NativeFSLockFactory@38f4596e),segFN=segments_3,generation=3,filenames=[segments_3]
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:52.448; org.apache.solr.core.SolrDeletionPolicy; newest commit = 3[segments_3]
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:52.449; org.apache.solr.search.SolrIndexSearcher; Opening Searcher@2b525fb6 main
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:52.450; org.apache.solr.update.DirectUpdateHandler2; end_commit_flush
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:52.451; org.apache.solr.core.SolrCore; [collection1] Registered new searcher Searcher@23bd25db main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:52.453; org.apache.solr.core.SolrCore; [collection1] Registered new searcher Searcher@2b525fb6 main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:52.454; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={waitSearcher=true&commit=true&wt=javabin&expungeDeletes=false&commit_end_point=true&version=2&softCommit=false} {commit=} 0 22
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:52.455; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={waitSearcher=true&commit=true&wt=javabin&expungeDeletes=false&commit_end_point=true&version=2&softCommit=false} {commit=} 0 25
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:52.457; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={waitSearcher=true&commit=true&wt=javabin&version=2&softCommit=false} {commit=} 0 121
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:52.461; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper... 
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:52.488; org.apache.solr.core.SolrCore; [collection1] webapp=/yb_zzk/q path=/select params={tests=checkShardConsistency&q=*:*&distrib=false&wt=javabin&version=2&rows=0} hits=0 status=0 QTime=0 
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:52.498; org.apache.solr.core.SolrCore; [collection1] webapp=/yb_zzk/q path=/select params={tests=checkShardConsistency&q=*:*&distrib=false&wt=javabin&version=2&rows=0} hits=0 status=0 QTime=0 
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:52.509; org.apache.solr.core.SolrCore; [collection1] webapp=/yb_zzk/q path=/select params={tests=checkShardConsistency&q=*:*&distrib=false&wt=javabin&version=2&rows=0} hits=0 status=0 QTime=1 
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:52.521; org.apache.solr.core.SolrCore; [collection1] webapp=/yb_zzk/q path=/select params={tests=checkShardConsistency&q=*:*&distrib=false&wt=javabin&version=2&rows=0} hits=0 status=0 QTime=0 
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:54.538; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={wt=javabin&version=2} {deleteByQuery=*:* (-1432700924229320704)} 0 10
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:54.659; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={update.distrib=FROMLEADER&_version_=-1432700924353052672&update.from=http://127.0.0.1:51537/yb_zzk/q/collection1/&wt=javabin&version=2} {deleteByQuery=*:* (-1432700924353052672)} 0 4
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:54.662; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={update.distrib=TOLEADER&wt=javabin&version=2} {deleteByQuery=*:* (-1432700924353052672)} 0 15
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:54.669; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={update.distrib=FROMLEADER&_version_=-1432700924249243648&update.from=http://127.0.0.1:51540/yb_zzk/q/collection1/&wt=javabin&version=2} {deleteByQuery=*:* (-1432700924249243648)} 0 3
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:54.671; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={wt=javabin&version=2} {deleteByQuery=*:* (-1432700924249243648)} 0 124
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:54.688; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={wt=javabin&version=2} {add=[0 (1432700924391849984)]} 0 4
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:54.718; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={distrib.from=http://127.0.0.1:51537/yb_zzk/q/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[0 (1432700924403384320)]} 0 4
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:54.721; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={wt=javabin&version=2} {add=[0 (1432700924403384320)]} 0 26
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:54.729; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={wt=javabin&version=2} {add=[1 (1432700924436938752)]} 0 3
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:54.764; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={distrib.from=http://127.0.0.1:51537/yb_zzk/q/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[1 (1432700924463153152)]} 0 4
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:54.767; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={distrib.from=http://127.0.0.1:51540/yb_zzk/q/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[1 (1432700924463153152)]} 0 15
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:54.776; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={wt=javabin&version=2} {add=[1]} 0 41
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:54.785; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={wt=javabin&version=2} {add=[2 (1432700924495659008)]} 0 2
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:54.807; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={distrib.from=http://127.0.0.1:51540/yb_zzk/q/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[2 (1432700924502999040)]} 0 11
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:54.810; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={wt=javabin&version=2} {add=[2 (1432700924502999040)]} 0 21
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:54.826; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={wt=javabin&version=2} {add=[3 (1432700924536553472)]} 0 5
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:54.859; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={distrib.from=http://127.0.0.1:51540/yb_zzk/q/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[3 (1432700924561719296)]} 0 4
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:54.862; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={distrib.from=http://127.0.0.1:51537/yb_zzk/q/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[3 (1432700924561719296)]} 0 17
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:54.865; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={wt=javabin&version=2} {add=[3]} 0 27
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:54.875; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={wt=javabin&version=2} {add=[4 (1432700924588982272)]} 0 4
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:54.900; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={distrib.from=http://127.0.0.1:51537/yb_zzk/q/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[4 (1432700924604710912)]} 0 4
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:54.903; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={distrib.from=http://127.0.0.1:51540/yb_zzk/q/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[4 (1432700924604710912)]} 0 16
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:54.909; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={wt=javabin&version=2} {add=[4]} 0 27
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:54.925; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={wt=javabin&version=2} {add=[5 (1432700924641411072)]} 0 5
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:54.954; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={distrib.from=http://127.0.0.1:51540/yb_zzk/q/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[5 (1432700924661334016)]} 0 6
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:54.957; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={distrib.from=http://127.0.0.1:51537/yb_zzk/q/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[5 (1432700924661334016)]} 0 17
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:54.959; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={wt=javabin&version=2} {add=[5]} 0 25
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:54.969; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={wt=javabin&version=2} {add=[6 (1432700924688596992)]} 0 2
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:54.997; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={distrib.from=http://127.0.0.1:51540/yb_zzk/q/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[6 (1432700924701179904)]} 0 11
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:55.001; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={distrib.from=http://127.0.0.1:51537/yb_zzk/q/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[6 (1432700924701179904)]} 0 23
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:55.003; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={wt=javabin&version=2} {add=[6]} 0 30
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:55.013; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={wt=javabin&version=2} {add=[7 (1432700924733685760)]} 0 4
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:55.040; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={distrib.from=http://127.0.0.1:51540/yb_zzk/q/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[7 (1432700924754657280)]} 0 4
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:55.043; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={wt=javabin&version=2} {add=[7 (1432700924754657280)]} 0 14
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:55.062; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={wt=javabin&version=2} {add=[8 (1432700924777725952)]} 0 12
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:55.083; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={distrib.from=http://127.0.0.1:51537/yb_zzk/q/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[8 (1432700924797648896)]} 0 3
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:55.086; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={wt=javabin&version=2} {add=[8 (1432700924797648896)]} 0 16
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:55.099; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={wt=javabin&version=2} {add=[9 (1432700924822814720)]} 0 4
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:55.127; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={distrib.from=http://127.0.0.1:51540/yb_zzk/q/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[9 (1432700924835397632)]} 0 3
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:55.130; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={wt=javabin&version=2} {add=[9 (1432700924835397632)]} 0 24
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:55.140; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={wt=javabin&version=2} {add=[10 (1432700924865806336)]} 0 4
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:55.169; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={distrib.from=http://127.0.0.1:51537/yb_zzk/q/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10 (1432700924877340672)]} 0 4
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:55.189; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={wt=javabin&version=2} {add=[10 (1432700924877340672)]} 0 43
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:55.220; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={wt=javabin&version=2} {add=[11 (1432700924950740992)]} 0 3
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:55.243; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={distrib.from=http://127.0.0.1:51537/yb_zzk/q/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[11 (1432700924964372480)]} 0 5
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:55.278; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={distrib.from=http://127.0.0.1:51540/yb_zzk/q/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[11 (1432700924964372480)]} 0 49
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:55.280; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={wt=javabin&version=2} {add=[11]} 0 55
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:55.299; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={wt=javabin&version=2} {add=[12 (1432700925033578496)]} 0 4
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:55.346; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={distrib.from=http://127.0.0.1:51537/yb_zzk/q/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[12 (1432700925071327232)]} 0 5
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:55.349; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={distrib.from=http://127.0.0.1:51540/yb_zzk/q/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[12 (1432700925071327232)]} 0 18
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:55.352; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={wt=javabin&version=2} {add=[12]} 0 39
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:55.369; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={wt=javabin&version=2} {add=[13 (1432700925106978816)]} 0 4
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:55.426; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={distrib.from=http://127.0.0.1:51537/yb_zzk/q/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[13 (1432700925126901760)]} 0 4
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:55.429; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={wt=javabin&version=2} {add=[13 (1432700925126901760)]} 0 44
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:55.443; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={wt=javabin&version=2} {add=[14 (1432700925183524864)]} 0 5
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:55.544; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={distrib.from=http://127.0.0.1:51537/yb_zzk/q/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[14 (1432700925267410944)]} 0 4
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:55.549; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={distrib.from=http://127.0.0.1:51540/yb_zzk/q/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[14 (1432700925267410944)]} 0 30
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:55.552; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={wt=javabin&version=2} {add=[14]} 0 43
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:55.592; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={wt=javabin&version=2} {add=[15 (1432700925338714112)]} 0 6
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:55.633; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={distrib.from=http://127.0.0.1:51537/yb_zzk/q/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[15 (1432700925357588480)]} 0 6
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:55.647; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={wt=javabin&version=2} {add=[15 (1432700925357588480)]} 0 43
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:55.661; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={wt=javabin&version=2} {add=[16 (1432700925410017280)]} 0 7
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:55.753; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={distrib.from=http://127.0.0.1:51537/yb_zzk/q/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[16 (1432700925427843072)]} 0 5
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:55.757; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={distrib.from=http://127.0.0.1:51540/yb_zzk/q/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[16 (1432700925427843072)]} 0 86
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:55.762; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={wt=javabin&version=2} {add=[16]} 0 96
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:55.772; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={wt=javabin&version=2} {add=[17 (1432700925530603520)]} 0 3
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:55.815; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={distrib.from=http://127.0.0.1:51540/yb_zzk/q/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[17 (1432700925547380736)]} 0 6
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:55.820; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={distrib.from=http://127.0.0.1:51537/yb_zzk/q/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[17 (1432700925547380736)]} 0 34
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:55.823; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={wt=javabin&version=2} {add=[17]} 0 45
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:55.841; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={wt=javabin&version=2} {add=[18 (1432700925598760960)]} 0 7
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:55.886; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={distrib.from=http://127.0.0.1:51540/yb_zzk/q/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[18 (1432700925615538176)]} 0 8
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:55.890; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={wt=javabin&version=2} {add=[18 (1432700925615538176)]} 0 40
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:55.902; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={wt=javabin&version=2} {add=[19 (1432700925663772672)]} 0 6
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:56.004; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={distrib.from=http://127.0.0.1:51540/yb_zzk/q/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[19 (1432700925761290240)]} 0 5
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:56.006; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={distrib.from=http://127.0.0.1:51537/yb_zzk/q/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[19 (1432700925761290240)]} 0 16
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:56.028; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={wt=javabin&version=2} {add=[19]} 0 45
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:56.069; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={wt=javabin&version=2} {add=[20 (1432700925839933440)]} 0 4
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:56.135; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={distrib.from=http://127.0.0.1:51537/yb_zzk/q/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[20 (1432700925879779328)]} 0 4
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:56.138; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={distrib.from=http://127.0.0.1:51540/yb_zzk/q/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[20 (1432700925879779328)]} 0 36
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:56.149; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={wt=javabin&version=2} {add=[20]} 0 55
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:56.160; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={wt=javabin&version=2} {add=[21 (1432700925936402432)]} 0 3
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:56.173; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={distrib.from=http://127.0.0.1:51540/yb_zzk/q/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[21 (1432700925944791040)]} 0 2
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:56.228; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={wt=javabin&version=2} {add=[21 (1432700925944791040)]} 0 64
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:56.236; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={wt=javabin&version=2} {add=[22 (1432700926017142784)]} 0 2
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:56.341; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={distrib.from=http://127.0.0.1:51537/yb_zzk/q/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[22 (1432700926065377280)]} 0 2
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:56.344; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={wt=javabin&version=2} {add=[22 (1432700926065377280)]} 0 65
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:56.382; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={wt=javabin&version=2} {add=[23 (1432700926168137728)]} 0 4
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:56.447; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={distrib.from=http://127.0.0.1:51540/yb_zzk/q/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[23 (1432700926190157824)]} 0 7
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:56.450; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={wt=javabin&version=2} {add=[23 (1432700926190157824)]} 0 51
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:56.462; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={wt=javabin&version=2} {add=[24 (1432700926252023808)]} 0 4
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:56.489; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={distrib.from=http://127.0.0.1:51537/yb_zzk/q/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[24 (1432700926271946752)]} 0 4
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:56.504; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={distrib.from=http://127.0.0.1:51540/yb_zzk/q/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[24 (1432700926271946752)]} 0 27
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:56.506; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={wt=javabin&version=2} {add=[24]} 0 36
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:56.526; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={wt=javabin&version=2} {add=[25 (1432700926320181248)]} 0 8
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:56.556; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={distrib.from=http://127.0.0.1:51540/yb_zzk/q/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[25 (1432700926339055616)]} 0 4
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:56.559; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={distrib.from=http://127.0.0.1:51537/yb_zzk/q/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[25 (1432700926339055616)]} 0 18
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:56.562; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={wt=javabin&version=2} {add=[25]} 0 28
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:56.573; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={wt=javabin&version=2} {add=[26 (1432700926368415744)]} 0 4
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:56.602; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={distrib.from=http://127.0.0.1:51540/yb_zzk/q/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[26 (1432700926389387264)]} 0 4
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:56.603; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={wt=javabin&version=2} {add=[26 (1432700926389387264)]} 0 15
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:56.617; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={wt=javabin&version=2} {add=[27 (1432700926415601664)]} 0 3
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:56.644; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={distrib.from=http://127.0.0.1:51537/yb_zzk/q/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[27 (1432700926433427456)]} 0 5
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:56.652; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={wt=javabin&version=2} {add=[27 (1432700926433427456)]} 0 21
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:56.678; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={wt=javabin&version=2} {add=[28 (1432700926478516224)]} 0 4
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:56.719; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={distrib.from=http://127.0.0.1:51537/yb_zzk/q/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[28 (1432700926502633472)]} 0 5
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:56.721; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={distrib.from=http://127.0.0.1:51540/yb_zzk/q/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[28 (1432700926502633472)]} 0 25
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:56.724; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={wt=javabin&version=2} {add=[28]} 0 41
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:56.744; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={wt=javabin&version=2} {add=[29 (1432700926547722240)]} 0 5
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:56.804; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={distrib.from=http://127.0.0.1:51540/yb_zzk/q/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[29 (1432700926573936640)]} 0 2
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:56.806; org.apache.solr.update.processor.LogUpdateProcessor; [collection1] webapp=/yb_zzk/q path=/update params={distrib.from=http://127.0.0.1:51537/yb_zzk/q/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[29 (1432700926573936640)]} 0 42
[junit4:junit4]   1> INFO  - 2013-04-19 00:07:

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

he.solr.update.SolrCoreState; Closing SolrCoreState
[junit4:junit4]   1> INFO  - 2013-04-19 00:08:43.022; org.apache.solr.update.DefaultSolrCoreState; SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4]   1> INFO  - 2013-04-19 00:08:43.023; org.apache.solr.update.DefaultSolrCoreState; closing IndexWriter with IndexWriterCloser
[junit4:junit4]   1> INFO  - 2013-04-19 00:08:43.028; org.apache.solr.core.SolrCore; [collection1_shard1_1_replica2] Closing main searcher on request.
[junit4:junit4]   1> INFO  - 2013-04-19 00:08:43.031; org.apache.solr.core.CachingDirectoryFactory; Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4:junit4]   1> INFO  - 2013-04-19 00:08:43.033; org.apache.solr.core.CachingDirectoryFactory; looking to close /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty4-1366330061251/collection1_shard1_1_replica2/data [CachedDir<<refCount=0;path=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty4-1366330061251/collection1_shard1_1_replica2/data;done=false>>]
[junit4:junit4]   1> INFO  - 2013-04-19 00:08:43.034; org.apache.solr.core.CachingDirectoryFactory; Closing directory: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty4-1366330061251/collection1_shard1_1_replica2/data
[junit4:junit4]   1> INFO  - 2013-04-19 00:08:43.039; org.apache.solr.core.CachingDirectoryFactory; looking to close /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty4-1366330061251/collection1_shard1_1_replica2/data/index [CachedDir<<refCount=0;path=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty4-1366330061251/collection1_shard1_1_replica2/data/index;done=false>>]
[junit4:junit4]   1> INFO  - 2013-04-19 00:08:43.039; org.apache.solr.core.CachingDirectoryFactory; Closing directory: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty4-1366330061251/collection1_shard1_1_replica2/data/index
[junit4:junit4]   1> INFO  - 2013-04-19 00:08:43.049; org.apache.solr.cloud.Overseer$ClusterStateUpdater; According to ZK I (id=89543805253648396-127.0.0.1:51547_yb_zzk%2Fq-n_0000000004) am no longer a leader.
[junit4:junit4]   1> INFO  - 2013-04-19 00:08:43.073; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (0)
[junit4:junit4]   1> INFO  - 2013-04-19 00:08:43.074; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 0)
[junit4:junit4]   1> INFO  - 2013-04-19 00:08:43.096; org.eclipse.jetty.server.handler.ContextHandler; stopped o.e.j.s.ServletContextHandler{/yb_zzk/q,null}
[junit4:junit4]   1> INFO  - 2013-04-19 00:08:43.189; org.apache.solr.SolrTestCaseJ4; ###Ending testDistribSearch
[junit4:junit4]   1> INFO  - 2013-04-19 00:08:43.194; org.apache.solr.cloud.ZkTestServer; connecting to 127.0.0.1:51530 51530
[junit4:junit4]   1> INFO  - 2013-04-19 00:08:43.396; org.apache.solr.common.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionManager@44c7cb1f name:ZooKeeperConnection Watcher:127.0.0.1:51530/solr got event WatchedEvent state:Disconnected type:None path:null path:null type:None
[junit4:junit4]   1> INFO  - 2013-04-19 00:08:43.397; org.apache.solr.common.cloud.ConnectionManager; zkClient has disconnected
[junit4:junit4]   1> INFO  - 2013-04-19 00:08:43.458; org.apache.solr.cloud.ChaosMonkey; monkey: stop shard! 51533
[junit4:junit4]   1> INFO  - 2013-04-19 00:08:43.459; org.apache.solr.SolrTestCaseJ4; ###Ending testDistribSearch
[junit4:junit4]   1> INFO  - 2013-04-19 00:08:43.460; org.apache.solr.cloud.ZkTestServer; connecting to 127.0.0.1:51530 51530
[junit4:junit4]   2> Creating dataDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./solrtest-ShardSplitTest-1366330036206
[junit4:junit4]   2> !!!! WARNING: best effort to remove /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-1366330036205 FAILED !!!!!
[junit4:junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=ShardSplitTest -Dtests.method=testDistribSearch -Dtests.seed=F917BC7C26480A71 -Dtests.slow=true -Dtests.locale=ar_DZ -Dtests.timezone=Europe/Tirane -Dtests.file.encoding=MacRoman
[junit4:junit4] FAILURE 87.5s | ShardSplitTest.testDistribSearch <<<
[junit4:junit4]    > Throwable #1: java.lang.AssertionError: Wrong doc count on shard1_0 expected:<114> but was:<113>
[junit4:junit4]    > 	at __randomizedtesting.SeedInfo.seed([F917BC7C26480A71:78F1326451176A4D]:0)
[junit4:junit4]    > 	at org.apache.solr.cloud.ShardSplitTest.checkDocCountsAndShardStates(ShardSplitTest.java:158)
[junit4:junit4]    > 	at org.apache.solr.cloud.ShardSplitTest.doTest(ShardSplitTest.java:134)
[junit4:junit4]    > 	at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:806)
[junit4:junit4]    > 	at java.lang.Thread.run(Thread.java:680)
[junit4:junit4]   1> INFO  - 2013-04-19 00:08:43.725; org.apache.solr.SolrTestCaseJ4; ###deleteCore
[junit4:junit4]   2> 87546 T1139 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 3 leaked thread(s).
[junit4:junit4]   1> WARN  - 2013-04-19 00:08:44.382; org.apache.solr.common.cloud.ZkStateReader$3; ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4]   1> INFO  - 2013-04-19 00:08:44.383; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 1)
[junit4:junit4]   1> WARN  - 2013-04-19 00:08:44.383; org.apache.solr.common.cloud.ZkStateReader$2; ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4]   2> NOTE: test params are: codec=Lucene42: {range_facet_l=PostingsFormat(name=Asserting), n_ti1=PostingsFormat(name=Memory doPackFST= true), n_f1=Lucene41(blocksize=128), _version_=PostingsFormat(name=Asserting), n_tl1=Lucene41(blocksize=128), n_d1=PostingsFormat(name=Asserting), rnd_b=PostingsFormat(name=Memory doPackFST= true), intDefault=PostingsFormat(name=Asserting), n_td1=Lucene41(blocksize=128), timestamp=PostingsFormat(name=Asserting), id=PostingsFormat(name=Memory doPackFST= true), range_facet_sl=PostingsFormat(name=Direct), n_tdt1=PostingsFormat(name=Asserting), range_facet_si=Lucene41(blocksize=128), n_l1=PostingsFormat(name=Asserting), multiDefault=Lucene41(blocksize=128), n_tf1=PostingsFormat(name=Asserting), n_dt1=Lucene41(blocksize=128)}, docValues:{}, sim=RandomSimilarityProvider(queryNorm=true,coord=no): {}, locale=ar_DZ, timezone=Europe/Tirane
[junit4:junit4]   2> NOTE: Mac OS X 10.8.3 x86_64/Apple Inc. 1.6.0_43 (64-bit)/cpus=2,threads=1,free=15606264,total=94941184
[junit4:junit4]   2> NOTE: All tests run in this JVM: [ReturnFieldsTest, TestSurroundQueryParser, CurrencyFieldXmlFileTest, TestPostingsSolrHighlighter, ClusterStateTest, TestHashPartitioner, QueryElevationComponentTest, TestReplicationHandler, LoggingHandlerTest, SynonymTokenizerTest, TestReload, TestPHPSerializedResponseWriter, PingRequestHandlerTest, TestDynamicFieldCollectionResource, WordBreakSolrSpellCheckerTest, TestSystemIdResolver, OutputWriterTest, TestStressLucene, BasicZkTest, HighlighterConfigTest, AnalysisAfterCoreReloadTest, SuggesterTSTTest, SimplePostToolTest, SolrRequestParserTest, ShowFileRequestHandlerTest, TestLFUCache, TestIBSimilarityFactory, TestIndexingPerformance, TestRealTimeGet, TestRemoteStreaming, TestJmxIntegration, SliceStateTest, DocumentBuilderTest, DocValuesMultiTest, SimpleFacetsTest, TestReversedWildcardFilterFactory, OpenExchangeRatesOrgProviderTest, TestTrie, SpellCheckCollatorTest, TestRandomDVFaceting, SchemaVersionSpecificBehaviorTest, DateFieldTest, TestConfig, ClusterStateUpdateTest, RecoveryZkTest, TestSolrXml, TestBinaryField, TestCodecSupport, QueryParsingTest, AlternateDirectoryTest, TestFuzzyAnalyzedSuggestions, EchoParamsTest, TestElisionMultitermQuery, TestAnalyzedSuggestions, CoreContainerCoreInitFailuresTest, FileBasedSpellCheckerTest, FieldAnalysisRequestHandlerTest, SolrTestCaseJ4Test, ShardSplitTest]
[junit4:junit4] Completed in 88.38s, 1 test, 1 failure <<< FAILURES!

[...truncated 730 lines...]
BUILD FAILED
/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/build.xml:381: The following error occurred while executing this line:
/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/build.xml:361: The following error occurred while executing this line:
/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/build.xml:39: The following error occurred while executing this line:
/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build.xml:181: The following error occurred while executing this line:
/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/common-build.xml:438: The following error occurred while executing this line:
/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/lucene/common-build.xml:1234: The following error occurred while executing this line:
/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/lucene/common-build.xml:878: There were test failures: 291 suites, 1205 tests, 1 failure, 18 ignored (6 assumptions)

Total time: 116 minutes 37 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 64bit/jdk1.6.0 -XX:+UseSerialGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure



Mime
View raw message