[JENKINS] Lucene-Solr-4.x-MacOSX (64bit/jdk1.6.0) - Build # 587 - Failure!

classic Classic list List threaded Threaded
1 message Options
Reply | Threaded
Open this post in threaded view
|

[JENKINS] Lucene-Solr-4.x-MacOSX (64bit/jdk1.6.0) - Build # 587 - Failure!

Policeman Jenkins Server-2
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-MacOSX/587/
Java: 64bit/jdk1.6.0 -XX:+UseCompressedOops -XX:+UseParallelGC

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

Error Message:
shard1 is not consistent.  Got 305 from http://127.0.0.1:53358/dpt/o/collection1lastClient and got 257 from http://127.0.0.1:53365/dpt/o/collection1

Stack Trace:
java.lang.AssertionError: shard1 is not consistent.  Got 305 from http://127.0.0.1:53358/dpt/o/collection1lastClient and got 257 from http://127.0.0.1:53365/dpt/o/collection1
        at __randomizedtesting.SeedInfo.seed([994F4C1E7409D04F:18A9C2060356B073]:0)
        at org.junit.Assert.fail(Assert.java:93)
        at org.apache.solr.cloud.AbstractFullDistribZkTestBase.checkShardConsistency(AbstractFullDistribZkTestBase.java:1018)
        at org.apache.solr.cloud.SyncSliceTest.doTest(SyncSliceTest.java:238)
        at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:835)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
        at java.lang.reflect.Method.invoke(Method.java:597)
        at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
        at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
        at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
        at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
        at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
        at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
        at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
        at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
        at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
        at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
        at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
        at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
        at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
        at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
        at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
        at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
        at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
        at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
        at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
        at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
        at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
        at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
        at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
        at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
        at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
        at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
        at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
        at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
        at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
        at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
        at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
        at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
        at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
        at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
        at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
        at java.lang.Thread.run(Thread.java:680)




Build Log:
[...truncated 9031 lines...]
[junit4:junit4] Suite: org.apache.solr.cloud.SyncSliceTest
[junit4:junit4]   2> 1835059 T4347 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /dpt/o
[junit4:junit4]   2> 1835067 T4347 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4:junit4]   2> Creating dataDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./solrtest-SyncSliceTest-1372390265578
[junit4:junit4]   2> 1835069 T4347 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4:junit4]   2> 1835070 T4348 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4:junit4]   2> 1835171 T4347 oasc.ZkTestServer.run start zk server on port:53351
[junit4:junit4]   2> 1835191 T4347 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 1835198 T4354 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4e8e7f53 name:ZooKeeperConnection Watcher:127.0.0.1:53351 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 1835198 T4347 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 1835199 T4347 oascc.SolrZkClient.makePath makePath: /solr
[junit4:junit4]   2> 1835215 T4347 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 1835222 T4356 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4673ab6e name:ZooKeeperConnection Watcher:127.0.0.1:53351/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 1835223 T4347 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 1835225 T4347 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4:junit4]   2> 1835237 T4347 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4:junit4]   2> 1835244 T4347 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4:junit4]   2> 1835252 T4347 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4:junit4]   2> 1835270 T4347 oasc.AbstractZkTestCase.putConfig 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]   2> 1835271 T4347 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4:junit4]   2> 1835286 T4347 oasc.AbstractZkTestCase.putConfig 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]   2> 1835287 T4347 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4:junit4]   2> 1835294 T4347 oasc.AbstractZkTestCase.putConfig 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]   2> 1835294 T4347 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4:junit4]   2> 1835300 T4347 oasc.AbstractZkTestCase.putConfig 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]   2> 1835301 T4347 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4:junit4]   2> 1835307 T4347 oasc.AbstractZkTestCase.putConfig 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]   2> 1835308 T4347 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4:junit4]   2> 1835314 T4347 oasc.AbstractZkTestCase.putConfig 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]   2> 1835315 T4347 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4:junit4]   2> 1835321 T4347 oasc.AbstractZkTestCase.putConfig 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]   2> 1835322 T4347 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4]   2> 1835328 T4347 oasc.AbstractZkTestCase.putConfig 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]   2> 1835328 T4347 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4:junit4]   2> 1835335 T4347 oasc.AbstractZkTestCase.putConfig 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]   2> 1835335 T4347 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4:junit4]   2> 1835760 T4347 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4]   2> 1835779 T4347 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:53354
[junit4:junit4]   2> 1835780 T4347 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 1835780 T4347 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 1835781 T4347 oasc.SolrResourceLoader.locateSolrHome 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.SyncSliceTest-controljetty-1372390265857
[junit4:junit4]   2> 1835781 T4347 oasc.CoreContainer$Initializer.initialize 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.SyncSliceTest-controljetty-1372390265857/solr.xml
[junit4:junit4]   2> 1835781 T4347 oasc.CoreContainer.<init> New CoreContainer 1166280740
[junit4:junit4]   2> 1835783 T4347 oasc.CoreContainer.load 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.SyncSliceTest-controljetty-1372390265857/'
[junit4:junit4]   2> 1835784 T4347 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-controljetty-1372390265857/'
[junit4:junit4]   2> 1835922 T4347 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4]   2> 1835924 T4347 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 1835925 T4347 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4]   2> 1835926 T4347 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 1835926 T4347 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 1835927 T4347 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 1835927 T4347 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 1835931 T4347 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 1835932 T4347 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 1835932 T4347 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4]   2> 1835971 T4347 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4]   2> 1835971 T4347 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:53351/solr
[junit4:junit4]   2> 1835972 T4347 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4]   2> 1835977 T4347 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 1835984 T4367 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7260aba8 name:ZooKeeperConnection Watcher:127.0.0.1:53351 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 1835985 T4347 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 1835989 T4347 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4]   2> 1836029 T4347 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 1836034 T4369 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2ce0d5e6 name:ZooKeeperConnection Watcher:127.0.0.1:53351/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 1836034 T4347 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 1836037 T4347 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4:junit4]   2> 1836045 T4347 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4:junit4]   2> 1836052 T4347 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4:junit4]   2> 1836056 T4347 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:53354_dpt%2Fo
[junit4:junit4]   2> 1836071 T4347 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:53354_dpt%2Fo
[junit4:junit4]   2> 1836079 T4347 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4:junit4]   2> 1836091 T4347 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4]   2> 1836096 T4347 oasc.Overseer.start Overseer (id=89940968445575171-127.0.0.1:53354_dpt%2Fo-n_0000000000) starting
[junit4:junit4]   2> 1836109 T4347 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4:junit4]   2> 1836120 T4371 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4]   2> 1836122 T4347 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4:junit4]   2> 1836128 T4347 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4:junit4]   2> 1836132 T4347 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4]   2> 1836139 T4370 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4]   2> 1836144 T4372 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4]   2> 1836144 T4372 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 1837650 T4370 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4]   2> 1837652 T4370 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4]   2>  "operation":"state",
[junit4:junit4]   2>  "core_node_name":"1",
[junit4:junit4]   2>  "numShards":"1",
[junit4:junit4]   2>  "shard":null,
[junit4:junit4]   2>  "roles":null,
[junit4:junit4]   2>  "state":"down",
[junit4:junit4]   2>  "shard_state":"active",
[junit4:junit4]   2>  "core":"collection1",
[junit4:junit4]   2>  "collection":"control_collection",
[junit4:junit4]   2>  "shard_range":null,
[junit4:junit4]   2>  "node_name":"127.0.0.1:53354_dpt%2Fo",
[junit4:junit4]   2>  "base_url":"http://127.0.0.1:53354/dpt/o"}
[junit4:junit4]   2> 1837652 T4370 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with numShards 1
[junit4:junit4]   2> 1837653 T4370 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard1
[junit4:junit4]   2> 1837697 T4369 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4:junit4]   2> 1838160 T4372 oasc.CoreContainer.create 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.SyncSliceTest-controljetty-1372390265857/collection1
[junit4:junit4]   2> 1838161 T4372 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4:junit4]   2> 1838164 T4372 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 1838164 T4372 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4:junit4]   2> 1838168 T4372 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-controljetty-1372390265857/collection1/'
[junit4:junit4]   2> 1838169 T4372 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-controljetty-1372390265857/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 1838170 T4372 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-controljetty-1372390265857/collection1/lib/README' to classloader
[junit4:junit4]   2> 1838241 T4372 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4]   2> 1838298 T4372 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 1838302 T4372 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4]   2> 1838308 T4372 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4]   2> 1838834 T4372 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4:junit4]   2> 1838836 T4372 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4:junit4]   2> 1838837 T4372 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 1838847 T4372 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 1838850 T4372 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 1838887 T4372 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 1838893 T4372 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 1838899 T4372 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 1838902 T4372 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 1838902 T4372 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4]   2> 1838902 T4372 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 1838906 T4372 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 1838906 T4372 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4]   2> 1838907 T4372 oasc.SolrCore.initDirectoryFactory solr.NRTCachingDirectoryFactory
[junit4:junit4]   2> 1838907 T4372 oasc.SolrCore.<init> [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.SyncSliceTest-controljetty-1372390265857/collection1/, dataDir=./org.apache.solr.cloud.SyncSliceTest-1372390265577/control/data/
[junit4:junit4]   2> 1838908 T4372 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@4578aae1
[junit4:junit4]   2> 1838909 T4372 oasc.SolrCore.initDirectoryFactory solr.NRTCachingDirectoryFactory
[junit4:junit4]   2> 1838910 T4372 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-1372390265577/control/data
[junit4:junit4]   2> 1838912 T4372 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.SyncSliceTest-1372390265577/control/data/index/
[junit4:junit4]   2> 1838912 T4372 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.SyncSliceTest-1372390265577/control/data/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 1838913 T4372 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-1372390265577/control/data/index
[junit4:junit4]   2> 1838921 T4372 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4]   2> commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-1372390265577/control/data/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@7e1bea2e; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1}
[junit4:junit4]   2> 1838922 T4372 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4]   2> 1838925 T4372 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 1838925 T4372 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 1838927 T4372 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 1838928 T4372 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 1838929 T4372 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 1838929 T4372 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 1838930 T4372 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 1838930 T4372 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 1838931 T4372 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 1838939 T4372 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 1838953 T4372 oass.SolrIndexSearcher.<init> Opening Searcher@3b65b38e main
[junit4:junit4]   2> 1838954 T4372 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 1838954 T4372 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 1838959 T4373 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@3b65b38e main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 1838961 T4372 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4]   2> 1838961 T4372 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:53354/dpt/o collection:control_collection shard:shard1
[junit4:junit4]   2> 1838963 T4372 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4:junit4]   2> 1838978 T4372 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4]   2> 1838984 T4372 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4]   2> 1838984 T4372 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4]   2> 1838984 T4372 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:53354/dpt/o/collection1/
[junit4:junit4]   2> 1838985 T4372 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4]   2> 1838985 T4372 oasc.SyncStrategy.syncToMe http://127.0.0.1:53354/dpt/o/collection1/ has no replicas
[junit4:junit4]   2> 1838986 T4372 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:53354/dpt/o/collection1/
[junit4:junit4]   2> 1838986 T4372 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4:junit4]   2> 1839209 T4370 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4]   2> 1839232 T4369 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4:junit4]   2> 1839254 T4372 oasc.ZkController.register We are http://127.0.0.1:53354/dpt/o/collection1/ and leader is http://127.0.0.1:53354/dpt/o/collection1/
[junit4:junit4]   2> 1839254 T4372 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:53354/dpt/o
[junit4:junit4]   2> 1839254 T4372 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 1839255 T4372 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4]   2> 1839255 T4372 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 1839258 T4372 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4]   2> 1839260 T4347 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0
[junit4:junit4]   2> 1839261 T4347 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 1839261 T4347 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 1839296 T4347 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4]   2> 1839299 T4347 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 1839313 T4376 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3b83dcf name:ZooKeeperConnection Watcher:127.0.0.1:53351/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 1839314 T4347 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 1839318 T4347 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4]   2> 1839325 T4347 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4:junit4]   2> 1839732 T4347 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4]   2> 1839738 T4347 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:53358
[junit4:junit4]   2> 1839739 T4347 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 1839740 T4347 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 1839740 T4347 oasc.SolrResourceLoader.locateSolrHome 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.SyncSliceTest-jetty1-1372390269834
[junit4:junit4]   2> 1839741 T4347 oasc.CoreContainer$Initializer.initialize 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.SyncSliceTest-jetty1-1372390269834/solr.xml
[junit4:junit4]   2> 1839741 T4347 oasc.CoreContainer.<init> New CoreContainer 604412439
[junit4:junit4]   2> 1839742 T4347 oasc.CoreContainer.load 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.SyncSliceTest-jetty1-1372390269834/'
[junit4:junit4]   2> 1839742 T4347 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty1-1372390269834/'
[junit4:junit4]   2> 1839850 T4347 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4]   2> 1839851 T4347 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 1839852 T4347 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4]   2> 1839853 T4347 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 1839853 T4347 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 1839854 T4347 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 1839854 T4347 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 1839855 T4347 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 1839855 T4347 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 1839856 T4347 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4]   2> 1839894 T4347 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4]   2> 1839895 T4347 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:53351/solr
[junit4:junit4]   2> 1839895 T4347 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4]   2> 1839897 T4347 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 1839902 T4387 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5ac9b726 name:ZooKeeperConnection Watcher:127.0.0.1:53351 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 1839902 T4347 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 1839907 T4347 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4]   2> 1839937 T4347 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 1839947 T4389 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@23408ba name:ZooKeeperConnection Watcher:127.0.0.1:53351/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 1839947 T4347 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 1839959 T4347 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4]   2> 1840750 T4370 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4]   2> 1840751 T4370 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4]   2>  "operation":"state",
[junit4:junit4]   2>  "core_node_name":"1",
[junit4:junit4]   2>  "numShards":"1",
[junit4:junit4]   2>  "shard":"shard1",
[junit4:junit4]   2>  "roles":null,
[junit4:junit4]   2>  "state":"active",
[junit4:junit4]   2>  "shard_state":"active",
[junit4:junit4]   2>  "core":"collection1",
[junit4:junit4]   2>  "collection":"control_collection",
[junit4:junit4]   2>  "shard_range":null,
[junit4:junit4]   2>  "node_name":"127.0.0.1:53354_dpt%2Fo",
[junit4:junit4]   2>  "base_url":"http://127.0.0.1:53354/dpt/o"}
[junit4:junit4]   2> 1840761 T4369 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4:junit4]   2> 1840761 T4376 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4:junit4]   2> 1840761 T4389 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4:junit4]   2> 1840972 T4347 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:53358_dpt%2Fo
[junit4:junit4]   2> 1840974 T4347 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:53358_dpt%2Fo
[junit4:junit4]   2> 1841002 T4376 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 1)
[junit4:junit4]   2> 1841003 T4369 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 1)
[junit4:junit4]   2> 1841009 T4376 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4]   2> 1841009 T4389 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4]   2> 1841010 T4389 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 2)
[junit4:junit4]   2> 1841012 T4390 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4]   2> 1841012 T4390 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 1841021 T4369 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4]   2> 1842288 T4370 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4]   2> 1842290 T4370 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4]   2>  "operation":"state",
[junit4:junit4]   2>  "core_node_name":"2",
[junit4:junit4]   2>  "numShards":"1",
[junit4:junit4]   2>  "shard":null,
[junit4:junit4]   2>  "roles":null,
[junit4:junit4]   2>  "state":"down",
[junit4:junit4]   2>  "shard_state":"active",
[junit4:junit4]   2>  "core":"collection1",
[junit4:junit4]   2>  "collection":"collection1",
[junit4:junit4]   2>  "shard_range":null,
[junit4:junit4]   2>  "node_name":"127.0.0.1:53358_dpt%2Fo",
[junit4:junit4]   2>  "base_url":"http://127.0.0.1:53358/dpt/o"}
[junit4:junit4]   2> 1842291 T4370 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with numShards 1
[junit4:junit4]   2> 1842291 T4370 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard1
[junit4:junit4]   2> 1842319 T4376 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4]   2> 1842324 T4369 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4]   2> 1842325 T4389 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4]   2> 1843023 T4390 oasc.CoreContainer.create 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.SyncSliceTest-jetty1-1372390269834/collection1
[junit4:junit4]   2> 1843023 T4390 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 1843025 T4390 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 1843026 T4390 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 1843029 T4390 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty1-1372390269834/collection1/'
[junit4:junit4]   2> 1843031 T4390 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-jetty1-1372390269834/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 1843031 T4390 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-jetty1-1372390269834/collection1/lib/README' to classloader
[junit4:junit4]   2> 1843122 T4390 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4]   2> 1843209 T4390 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 1843212 T4390 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4]   2> 1843235 T4390 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4]   2> 1843866 T4390 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4:junit4]   2> 1843867 T4390 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4:junit4]   2> 1843868 T4390 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 1843878 T4390 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 1843882 T4390 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 1843930 T4390 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 1843948 T4390 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 1843956 T4390 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 1843959 T4390 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 1843959 T4390 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4]   2> 1843960 T4390 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 1843963 T4390 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 1843964 T4390 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4]   2> 1843964 T4390 oasc.SolrCore.initDirectoryFactory solr.NRTCachingDirectoryFactory
[junit4:junit4]   2> 1843965 T4390 oasc.SolrCore.<init> [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.SyncSliceTest-jetty1-1372390269834/collection1/, dataDir=./org.apache.solr.cloud.SyncSliceTest-1372390265577/jetty1/
[junit4:junit4]   2> 1843965 T4390 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@4578aae1
[junit4:junit4]   2> 1843967 T4390 oasc.SolrCore.initDirectoryFactory solr.NRTCachingDirectoryFactory
[junit4:junit4]   2> 1843968 T4390 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-1372390265577/jetty1
[junit4:junit4]   2> 1843970 T4390 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.SyncSliceTest-1372390265577/jetty1/index/
[junit4:junit4]   2> 1843971 T4390 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.SyncSliceTest-1372390265577/jetty1/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 1843972 T4390 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-1372390265577/jetty1/index
[junit4:junit4]   2> 1843984 T4390 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4]   2> commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-1372390265577/jetty1/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@772552de; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1}
[junit4:junit4]   2> 1843984 T4390 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4]   2> 1843989 T4390 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 1843989 T4390 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 1843990 T4390 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 1843991 T4390 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 1843992 T4390 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 1843992 T4390 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 1843993 T4390 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 1843994 T4390 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 1843995 T4390 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 1844013 T4390 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 1844027 T4390 oass.SolrIndexSearcher.<init> Opening Searcher@231ac3a4 main
[junit4:junit4]   2> 1844029 T4390 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 1844030 T4390 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 1844050 T4391 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@231ac3a4 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 1844057 T4390 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4]   2> 1844058 T4390 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:53358/dpt/o collection:collection1 shard:shard1
[junit4:junit4]   2> 1844060 T4390 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4:junit4]   2> 1844078 T4390 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4]   2> 1844087 T4390 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4]   2> 1844089 T4390 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4]   2> 1844090 T4390 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:53358/dpt/o/collection1/
[junit4:junit4]   2> 1844091 T4390 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4]   2> 1844092 T4390 oasc.SyncStrategy.syncToMe http://127.0.0.1:53358/dpt/o/collection1/ has no replicas
[junit4:junit4]   2> 1844092 T4390 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:53358/dpt/o/collection1/
[junit4:junit4]   2> 1844093 T4390 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4:junit4]   2> 1845344 T4370 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4]   2> 1845368 T4369 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4]   2> 1845369 T4376 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4]   2> 1845372 T4389 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4]   2> 1845417 T4390 oasc.ZkController.register We are http://127.0.0.1:53358/dpt/o/collection1/ and leader is http://127.0.0.1:53358/dpt/o/collection1/
[junit4:junit4]   2> 1845418 T4390 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:53358/dpt/o
[junit4:junit4]   2> 1845418 T4390 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 1845418 T4390 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4]   2> 1845419 T4390 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 1845424 T4390 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4]   2> 1845445 T4347 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0
[junit4:junit4]   2> 1845449 T4347 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 1845451 T4347 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 1846135 T4347 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4]   2> 1846145 T4347 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:53361
[junit4:junit4]   2> 1846148 T4347 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 1846149 T4347 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 1846150 T4347 oasc.SolrResourceLoader.locateSolrHome 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.SyncSliceTest-jetty2-1372390276006
[junit4:junit4]   2> 1846151 T4347 oasc.CoreContainer$Initializer.initialize 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.SyncSliceTest-jetty2-1372390276006/solr.xml
[junit4:junit4]   2> 1846152 T4347 oasc.CoreContainer.<init> New CoreContainer 1808366395
[junit4:junit4]   2> 1846153 T4347 oasc.CoreContainer.load 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.SyncSliceTest-jetty2-1372390276006/'
[junit4:junit4]   2> 1846154 T4347 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty2-1372390276006/'
[junit4:junit4]   2> 1846311 T4347 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4]   2> 1846312 T4347 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 1846315 T4347 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4]   2> 1846320 T4347 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 1846320 T4347 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 1846321 T4347 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 1846321 T4347 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 1846323 T4347 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 1846325 T4347 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 1846326 T4347 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4]   2> 1846381 T4347 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4]   2> 1846383 T4347 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:53351/solr
[junit4:junit4]   2> 1846383 T4347 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4]   2> 1846386 T4347 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 1846401 T4403 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6017f66e name:ZooKeeperConnection Watcher:127.0.0.1:53351 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 1846402 T4347 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 1846408 T4347 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4]   2> 1846445 T4347 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 1846450 T4405 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@55126b15 name:ZooKeeperConnection Watcher:127.0.0.1:53351/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 1846450 T4347 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 1846461 T4347 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4]   2> 1846906 T4370 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4]   2> 1846908 T4370 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4]   2>  "operation":"state",
[junit4:junit4]   2>  "core_node_name":"2",
[junit4:junit4]   2>  "numShards":"1",
[junit4:junit4]   2>  "shard":"shard1",
[junit4:junit4]   2>  "roles":null,
[junit4:junit4]   2>  "state":"active",
[junit4:junit4]   2>  "shard_state":"active",
[junit4:junit4]   2>  "core":"collection1",
[junit4:junit4]   2>  "collection":"collection1",
[junit4:junit4]   2>  "shard_range":null,
[junit4:junit4]   2>  "node_name":"127.0.0.1:53358_dpt%2Fo",
[junit4:junit4]   2>  "base_url":"http://127.0.0.1:53358/dpt/o"}
[junit4:junit4]   2> 1846917 T4376 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4]   2> 1846917 T4389 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4]   2> 1846917 T4369 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4]   2> 1846925 T4405 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4]   2> 1847470 T4347 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:53361_dpt%2Fo
[junit4:junit4]   2> 1847474 T4347 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:53361_dpt%2Fo
[junit4:junit4]   2> 1847490 T4376 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 2)
[junit4:junit4]   2> 1847490 T4369 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 2)
[junit4:junit4]   2> 1847490 T4389 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4]   2> 1847492 T4389 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   2> 1847490 T4405 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 2)
[junit4:junit4]   2> 1847502 T4376 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4]   2> 1847504 T4369 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4]   2> 1847518 T4406 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4]   2> 1847519 T4406 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 1847521 T4405 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4]   2> 1848437 T4370 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4]   2> 1848439 T4370 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4]   2>  "operation":"state",
[junit4:junit4]   2>  "core_node_name":"3",
[junit4:junit4]   2>  "numShards":"1",
[junit4:junit4]   2>  "shard":null,
[junit4:junit4]   2>  "roles":null,
[junit4:junit4]   2>  "state":"down",
[junit4:junit4]   2>  "shard_state":"active",
[junit4:junit4]   2>  "core":"collection1",
[junit4:junit4]   2>  "collection":"collection1",
[junit4:junit4]   2>  "shard_range":null,
[junit4:junit4]   2>  "node_name":"127.0.0.1:53361_dpt%2Fo",
[junit4:junit4]   2>  "base_url":"http://127.0.0.1:53361/dpt/o"}
[junit4:junit4]   2> 1848439 T4370 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=1
[junit4:junit4]   2> 1848440 T4370 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard1
[junit4:junit4]   2> 1848474 T4376 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   2> 1848475 T4405 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   2> 1848476 T4389 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   2> 1848477 T4369 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   2> 1848523 T4406 oasc.CoreContainer.create 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.SyncSliceTest-jetty2-1372390276006/collection1
[junit4:junit4]   2> 1848524 T4406 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 1848526 T4406 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 1848526 T4406 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 1848529 T4406 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty2-1372390276006/collection1/'
[junit4:junit4]   2> 1848530 T4406 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-jetty2-1372390276006/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 1848531 T4406 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-jetty2-1372390276006/collection1/lib/README' to classloader
[junit4:junit4]   2> 1848587 T4406 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4]   2> 1848630 T4406 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 1848633 T4406 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4]   2> 1848641 T4406 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4]   2> 1849231 T4406 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4:junit4]   2> 1849232 T4406 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4:junit4]   2> 1849233 T4406 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 1849249 T4406 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 1849252 T4406 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 1849285 T4406 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 1849291 T4406 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 1849299 T4406 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 1849303 T4406 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 1849304 T4406 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4]   2> 1849304 T4406 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 1849306 T4406 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 1849307 T4406 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4]   2> 1849307 T4406 oasc.SolrCore.initDirectoryFactory solr.NRTCachingDirectoryFactory
[junit4:junit4]   2> 1849308 T4406 oasc.SolrCore.<init> [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.SyncSliceTest-jetty2-1372390276006/collection1/, dataDir=./org.apache.solr.cloud.SyncSliceTest-1372390265577/jetty2/
[junit4:junit4]   2> 1849308 T4406 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@4578aae1
[junit4:junit4]   2> 1849309 T4406 oasc.SolrCore.initDirectoryFactory solr.NRTCachingDirectoryFactory
[junit4:junit4]   2> 1849310 T4406 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-1372390265577/jetty2
[junit4:junit4]   2> 1849311 T4406 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.SyncSliceTest-1372390265577/jetty2/index/
[junit4:junit4]   2> 1849312 T4406 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.SyncSliceTest-1372390265577/jetty2/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 1849313 T4406 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-1372390265577/jetty2/index
[junit4:junit4]   2> 1849320 T4406 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4]   2> commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-1372390265577/jetty2/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@7793a105; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1}
[junit4:junit4]   2> 1849321 T4406 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4]   2> 1849332 T4406 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 1849333 T4406 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 1849334 T4406 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 1849336 T4406 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 1849338 T4406 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 1849338 T4406 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 1849339 T4406 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 1849341 T4406 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 1849342 T4406 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 1849355 T4406 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 1849365 T4406 oass.SolrIndexSearcher.<init> Opening Searcher@2fe3fb5f main
[junit4:junit4]   2> 1849366 T4406 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 1849367 T4406 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 1849390 T4407 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@2fe3fb5f main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 1849396 T4406 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4]   2> 1849397 T4406 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:53361/dpt/o collection:collection1 shard:shard1
[junit4:junit4]   2> 1849405 T4406 oasc.ZkController.register We are http://127.0.0.1:53361/dpt/o/collection1/ and leader is http://127.0.0.1:53358/dpt/o/collection1/
[junit4:junit4]   2> 1849406 T4406 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:53361/dpt/o
[junit4:junit4]   2> 1849406 T4406 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4]   2> 1849406 T4406 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4]   2> ASYNC  NEW_CORE C723 name=collection1 org.apache.solr.core.SolrCore@43539e01 url=http://127.0.0.1:53361/dpt/o/collection1 node=127.0.0.1:53361_dpt%2Fo C723_STATE=coll:collection1 core:collection1 props:{state=down, core=collection1, collection=collection1, node_name=127.0.0.1:53361_dpt%2Fo, base_url=http://127.0.0.1:53361/dpt/o}
[junit4:junit4]   2> 1849407 T4408 C723 P53361 oasc.RecoveryStrategy.run Starting recovery process.  core=collection1 recoveringAfterStartup=true
[junit4:junit4]   2> 1849409 T4408 C723 P53361 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4]   2> 1849410 T4408 C723 P53361 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4]   2> 1849410 T4408 C723 P53361 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 1849410 T4406 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4]   2> 1849414 T4408 C723 P53361 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 1849432 T4347 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0
[junit4:junit4]   2> 1849433 T4347 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 1849434 T4347 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 1849468 T4379 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: 3, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4]   2> 1849886 T4347 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4]   2> 1849895 T4347 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:53365
[junit4:junit4]   2> 1849896 T4347 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 1849897 T4347 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 1849897 T4347 oasc.SolrResourceLoader.locateSolrHome 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.SyncSliceTest-jetty3-1372390279978
[junit4:junit4]   2> 1849898 T4347 oasc.CoreContainer$Initializer.initialize 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.SyncSliceTest-jetty3-1372390279978/solr.xml
[junit4:junit4]   2> 1849899 T4347 oasc.CoreContainer.<init> New CoreContainer 710258926
[junit4:junit4]   2> 1849900 T4347 oasc.CoreContainer.load 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.SyncSliceTest-jetty3-1372390279978/'
[junit4:junit4]   2> 1849900 T4347 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty3-1372390279978/'
[junit4:junit4]   2> 1850018 T4370 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4]   2> 1850020 T4347 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4]   2> 1850020 T4370 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4]   2>  "operation":"state",
[junit4:junit4]   2>  "core_node_name":"3",
[junit4:junit4]   2>  "numShards":"1",
[junit4:junit4]   2>  "shard":"shard1",
[junit4:junit4]   2>  "roles":null,
[junit4:junit4]   2>  "state":"recovering",
[junit4:junit4]   2>  "shard_state":"active",
[junit4:junit4]   2>  "core":"collection1",
[junit4:junit4]   2>  "collection":"collection1",
[junit4:junit4]   2>  "shard_range":null,
[junit4:junit4]   2>  "node_name":"127.0.0.1:53361_dpt%2Fo",
[junit4:junit4]   2>  "base_url":"http://127.0.0.1:53361/dpt/o"}
[junit4:junit4]   2> 1850020 T4347 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 1850022 T4347 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4]   2> 1850022 T4347 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 1850023 T4347 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 1850023 T4347 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 1850024 T4347 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 1850025 T4347 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 1850025 T4347 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 1850026 T4347 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4]   2> 1850031 T4389 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   2> 1850031 T4376 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   2> 1850031 T4369 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   2> 1850031 T4405 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   2> 1850063 T4347 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4]   2> 1850064 T4347 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:53351/solr
[junit4:junit4]   2> 1850065 T4347 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4]   2> 1850071 T4347 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 1850084 T4420 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@11470cee name:ZooKeeperConnection Watcher:127.0.0.1:53351 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 1850084 T4347 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 1850089 T4347 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4]   2> 1850119 T4347 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 1850122 T4422 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3493d94a name:ZooKeeperConnection Watcher:127.0.0.1:53351/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 1850123 T4347 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 1850132 T4347 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4]   2> 1850470 T4379 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: 3, state: recovering, checkLive: true, onlyIfLeader: true for: 1 seconds.
[junit4:junit4]   2> 1850472 T4379 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={coreNodeName=3&state=recovering&nodeName=127.0.0.1:53361_dpt%252Fo&action=PREPRECOVERY&checkLive=true&core=collection1&wt=javabin&onlyIfLeader=true&version=2} status=0 QTime=1004
[junit4:junit4]   2> 1851142 T4347 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:53365_dpt%2Fo
[junit4:junit4]   2> 1851144 T4347 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:53365_dpt%2Fo
[junit4:junit4]   2> 1851152 T4376 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   2> 1851155 T4405 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   2> 1851155 T4369 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   2> 1851162 T4389 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 1851163 T4389 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 1851163 T4422 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 1851169 T4423 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4]   2> 1851169 T4423 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 1851171 T4405 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 1851173 T4369 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 1851176 T4376 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 1851574 T4370 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4]   2> 1851576 T4370 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4]   2>  "operation":"state",
[junit4:junit4]   2>  "core_node_name":"4",
[junit4:junit4]   2>  "numShards":"1",
[junit4:junit4]   2>  "shard":null,
[junit4:junit4]   2>  "roles":null,
[junit4:junit4]   2>  "state":"down",
[junit4:junit4]   2>  "shard_state":"active",
[junit4:junit4]   2>  "core":"collection1",
[junit4:junit4]   2>  "collection":"collection1",
[junit4:junit4]   2>  "shard_range":null,
[junit4:junit4]   2>  "node_name":"127.0.0.1:53365_dpt%2Fo",
[junit4:junit4]   2>  "base_url":"http://127.0.0.1:53365/dpt/o"}
[junit4:junit4]   2> 1851577 T4370 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=1
[junit4:junit4]   2> 1851577 T4370 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard1
[junit4:junit4]   2> 1851595 T4422 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 1851596 T4369 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 1851595 T4389 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 1851595 T4376 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 1851596 T4405 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 1852176 T4423 oasc.CoreContainer.create 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.SyncSliceTest-jetty3-1372390279978/collection1
[junit4:junit4]   2> 1852178 T4423 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 1852180 T4423 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 1852180 T4423 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 1852183 T4423 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty3-1372390279978/collection1/'
[junit4:junit4]   2> 1852184 T4423 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-jetty3-1372390279978/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 1852185 T4423 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-jetty3-1372390279978/collection1/lib/README' to classloader
[junit4:junit4]   2> 1852234 T4423 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4]   2> 1852294 T4423 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 1852297 T4423 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4]   2> 1852303 T4423 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4]   2> ASYNC  NEW_CORE C724 name=collection1 org.apache.solr.core.SolrCore@43539e01 url=http://127.0.0.1:53361/dpt/o/collection1 node=127.0.0.1:53361_dpt%2Fo C724_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=recovering, core=collection1, collection=collection1, node_name=127.0.0.1:53361_dpt%2Fo, base_url=http://127.0.0.1:53361/dpt/o}
[junit4:junit4]   2> 1852474 T4408 C724 P53361 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:53358/dpt/o/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4]   2> 1852474 T4408 C724 P53361 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:53361/dpt/o START replicas=[http://127.0.0.1:53358/dpt/o/collection1/] nUpdates=100
[junit4:junit4]   2> 1852479 T4408 C724 P53361 oasu.PeerSync.sync WARN no frame of reference to tell of we've missed updates
[junit4:junit4]   2> 1852480 T4408 C724 P53361 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4]   2> 1852480 T4408 C724 P53361 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4]   2> 1852480 T4408 C724 P53361 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4]   2> 1852480 T4408 C724 P53361 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4]   2> 1852481 T4408 C724 P53361 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:53358/dpt/o/collection1/. core=collection1
[junit4:junit4]   2> 1852481 T4408 C724 P53361 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> ASYNC  NEW_CORE C725 name=collection1 org.apache.solr.core.SolrCore@2ff2f56 url=http://127.0.0.1:53358/dpt/o/collection1 node=127.0.0.1:53358_dpt%2Fo C725_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:53358_dpt%2Fo, base_url=http://127.0.0.1:53358/dpt/o, leader=true}
[junit4:junit4]   2> 1852539 T4382 C725 P53358 oasc.SolrCore.execute [collection1] webapp=/dpt/o path=/get params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=5
[junit4:junit4]   2> 1852544 T4384 C725 P53358 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4]   2> 1852551 T4384 C725 P53358 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4]   2> commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-1372390265577/jetty1/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@772552de; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1}
[junit4:junit4]   2> 1852554 T4384 C725 P53358 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4]   2> 1852554 T4384 C725 P53358 oasu.DirectUpdateHandler2.commit No uncommitted changes. Skipping IW.commit.
[junit4:junit4]   2> 1852555 T4384 C725 P53358 oass.SolrIndexSearcher.<init> Opening Searcher@4060716c realtime
[junit4:junit4]   2> 1852555 T4384 C725 P53358 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 1852556 T4384 C725 P53358 oasup.LogUpdateProcessor.finish [collection1] webapp=/dpt/o path=/update params={waitSearcher=true&openSearcher=false&commit=true&wt=javabin&commit_end_point=true&version=2&softCommit=false} {commit=} 0 12
[junit4:junit4]   2> 1852558 T4408 C724 P53361 oash.ReplicationHandler.inform Commits will be reserved for  10000
[junit4:junit4]   2> 1852558 T4408 C724 P53361 oash.SnapPuller.<init>  No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4]   2> 1852569 T4381 C725 P53358 oash.ReplicationHandler.inform Commits will be reserved for  10000
[junit4:junit4]   2> 1852570 T4381 C725 P53358 oasc.SolrCore.execute [collection1] webapp=/dpt/o path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=1
[junit4:junit4]   2> 1852571 T4408 C724 P53361 oasc.RecoveryStrategy.replay No replay needed. core=collection1
[junit4:junit4]   2> 1852572 T4408 C724 P53361 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4]   2> 1852572 T4408 C724 P53361 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4]   2> 1852572 T4408 C724 P53361 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 1852575 T4408 C724 P53361 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4]   2> 1852901 T4423 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4:junit4]   2> 1852901 T4423 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4:junit4]   2> 1852902 T4423 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 1852918 T4423 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 1852925 T4423 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 1852953 T4423 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 1852959 T4423 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 1852964 T4423 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 1852967 T4423 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 1852967 T4423 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4]   2> 1852967 T4423 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 1852970 T4423 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 1852970 T4423 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4]   2> 1852970 T4423 oasc.SolrCore.initDirectoryFactory solr.NRTCachingDirectoryFactory
[junit4:junit4]   2> 1852971 T4423 oasc.SolrCore.<init> [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.SyncSliceTest-jetty3-1372390279978/collection1/, dataDir=./org.apache.solr.cloud.SyncSliceTest-1372390265577/jetty3/
[junit4:junit4]   2> 1852971 T4423 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@4578aae1
[junit4:junit4]   2> 1852973 T4423 oasc.SolrCore.initDirectoryFactory solr.NRTCachingDirectoryFactory
[junit4:junit4]   2> 1852974 T4423 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-1372390265577/jetty3
[junit4:junit4]   2> 1852974 T4423 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.SyncSliceTest-1372390265577/jetty3/index/
[junit4:junit4]   2> 1852975 T4423 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.SyncSliceTest-1372390265577/jetty3/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 1852976 T4423 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-1372390265577/jetty3/index
[junit4:junit4]   2> 1852990 T4423 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4]   2> commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-1372390265577/jetty3/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@1300138a; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1}
[junit4:junit4]   2> 1852991 T4423 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4]   2> 1852995 T4423 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 1852995 T4423 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 1852996 T4423 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 1852997 T4423 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 1852998 T4423 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 1852998 T4423 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 1853002 T4423 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 1853003 T4423 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 1853004 T4423 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 1853012 T4423 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 1853020 T4423 oass.SolrIndexSearcher.<init> Opening Searcher@72caec14 main
[junit4:junit4]   2> 1853021 T4423 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 1853021 T4423 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 1853033 T4425 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@72caec14 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 1853035 T4423 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4]   2> 1853036 T4423 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:53365/dpt/o collection:collection1 shard:shard1
[junit4:junit4]   2> 1853046 T4423 oasc.ZkController.register We are http://127.0.0.1:53365/dpt/o/collection1/ and leader is http://127.0.0.1:53358/dpt/o/collection1/
[junit4:junit4]   2> 1853046 T4423 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:53365/dpt/o
[junit4:junit4]   2> 1853047 T4423 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4]   2> 1853047 T4423 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4]   2> ASYNC  NEW_CORE C726 name=collection1 org.apache.solr.core.SolrCore@2cfd52ee url=http://127.0.0.1:53365/dpt/o/collection1 node=127.0.0.1:53365_dpt%2Fo C726_STATE=coll:collection1 core:collection1 props:{state=down, core=collection1, collection=collection1, node_name=127.0.0.1:53365_dpt%2Fo, base_url=http://127.0.0.1:53365/dpt/o}
[junit4:junit4]   2> 1853048 T4426 C726 P53365 oasc.RecoveryStrategy.run Starting recovery process.  core=collection1 recoveringAfterStartup=true
[junit4:junit4]   2> 1853052 T4426 C726 P53365 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4]   2> 1853052 T4426 C726 P53365 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4]   2> 1853052 T4426 C726 P53365 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 1853053 T4423 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4]   2> 1853054 T4426 C726 P53365 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 1853067 T4347 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0
[junit4:junit4]   2> 1853067 T4347 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 1853068 T4347 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 1853105 T4382 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: 4, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4]   2> 1853110 T4370 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4]   2> 1853112 T4370 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4]   2>  "operation":"state",
[junit4:junit4]   2>  "core_node_name":"3",
[junit4:junit4]   2>  "numShards":"1",
[junit4:junit4]   2>  "shard":"shard1",
[junit4:junit4]   2>  "roles":null,
[junit4:junit4]   2>  "state":"active",
[junit4:junit4]   2>  "shard_state":"active",
[junit4:junit4]   2>  "core":"collection1",
[junit4:junit4]   2>  "collection":"collection1",
[junit4:junit4]   2>  "shard_range":null,
[junit4:junit4]   2>  "node_name":"127.0.0.1:53361_dpt%2Fo",
[junit4:junit4]   2>  "base_url":"http://127.0.0.1:53361/dpt/o"}
[junit4:junit4]   2> 1853120 T4370 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4]   2>  "operation":"state",
[junit4:junit4]   2>  "core_node_name":"4",
[junit4:junit4]   2>  "numShards":"1",
[junit4:junit4]   2>  "shard":"shard1",
[junit4:junit4]   2>  "roles":null,
[junit4:junit4]   2>  "state":"recovering",
[junit4:junit4]   2>  "shard_state":"active",
[junit4:junit4]   2>  "core":"collection1",
[junit4:junit4]   2>  "collection":"collection1",
[junit4:junit4]   2>  "shard_range":null,
[junit4:junit4]   2>  "node_name":"127.0.0.1:53365_dpt%2Fo",
[junit4:junit4]   2>  "base_url":"http://127.0.0.1:53365/dpt/o"}
[junit4:junit4]   2> 1853148 T4405 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 1853149 T4369 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 1853149 T4389 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 1853149 T4376 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 1853151 T4422 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 1853535 T4347 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4]   2> 1853543 T4347 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:53372
[junit4:junit4]   2> 1853544 T4347 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 1853544 T4347 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 1853545 T4347 oasc.SolrResourceLoader.locateSolrHome 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.SyncSliceTest-jetty4-1372390283612
[junit4:junit4]   2> 1853545 T4347 oasc.CoreContainer$Initializer.initialize 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.SyncSliceTest-jetty4-1372390283612/solr.xml
[junit4:junit4]   2> 1853545 T4347 oasc.CoreContainer.<init> New CoreContainer 1885559539
[junit4:junit4]   2> 1853546 T4347 oasc.CoreContainer.load 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.SyncSliceTest-jetty4-1372390283612/'
[junit4:junit4]   2> 1853546 T4347 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty4-1372390283612/'
[junit4:junit4]   2> 1853650 T4347 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4]   2> 1853650 T4347 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 1853651 T4347 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4]   2> 1853652 T4347 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 1853652 T4347 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 1853652 T4347 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 1853653 T4347 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 1853653 T4347 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 1853654 T4347 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 1853654 T4347 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4]   2> 1853686 T4347 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4]   2> 1853688 T4347 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:53351/solr
[junit4:junit4]   2> 1853689 T4347 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4]   2> 1853692 T4347 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 1853696 T4438 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@160e31fe name:ZooKeeperConnection Watcher:127.0.0.1:53351 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 1853696 T4347 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 1853700 T4347 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4]   2> 1853734 T4347 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 1853739 T4440 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7d0688b8 name:ZooKeeperConnection Watcher:127.0.0.1:53351/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 1853739 T4347 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 1853749 T4347 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4]   2> 1854108 T4382 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: 4, state: recovering, checkLive: true, onlyIfLeader: true for: 1 seconds.
[junit4:junit4]   2> 1854111 T4382 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={coreNodeName=4&state=recovering&nodeName=127.0.0.1:53365_dpt%252Fo&action=PREPRECOVERY&checkLive=true&core=collection1&wt=javabin&onlyIfLeader=true&version=2} status=0 QTime=1006
[junit4:junit4]   2> 1854757 T4347 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:53372_dpt%2Fo
[junit4:junit4]   2> 1854759 T4347 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:53372_dpt%2Fo
[junit4:junit4]   2> 1854766 T4376 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 1854766 T4405 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 1854767 T4422 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 1854767 T4369 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 1854770 T4440 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4]   2> 1854791 T4389 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4]   2> 1854791 T4389 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 1854793 T4441 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4]   2> 1854793 T4441 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 1854794 T4376 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4]   2> 1854795 T4422 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4]   2> 1854794 T4405 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4]   2> 1854797 T4369 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4]   2>  C726_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=recovering, core=collection1, collection=collection1, node_name=127.0.0.1:53365_dpt%2Fo, base_url=http://127.0.0.1:53365/dpt/o}
[junit4:junit4]   2> 1856121 T4426 C726 P53365 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:53358/dpt/o/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4]   2> 1856122 T4426 C726 P53365 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:53365/dpt/o START replicas=[http://127.0.0.1:53358/dpt/o/collection1/] nUpdates=100
[junit4:junit4]   2> 1856122 T4426 C726 P53365 oasu.PeerSync.sync WARN no frame of reference to tell of we've missed updates
[junit4:junit4]   2> 1856123 T4426 C726 P53365 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4]   2> 1856123 T4426 C726 P53365 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4]   2> 1856124 T4426 C726 P53365 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4]   2> 1856124 T4426 C726 P53365 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4]   2> 1856124 T4426 C726 P53365 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:53358/dpt/o/collection1/. core=collection1
[junit4:junit4]   2> 1856124 T4426 C726 P53365 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> ASYNC  NEW_CORE C727 name=collection1 org.apache.solr.core.SolrCore@2ff2f56 url=http://127.0.0.1:53358/dpt/o/collection1 node=127.0.0.1:53358_dpt%2Fo C727_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:53358_dpt%2Fo, base_url=http://127.0.0.1:53358/dpt/o, leader=true}
[junit4:junit4]   2> 1856127 T4380 C727 P53358 oasc.SolrCore.execute [collection1] webapp=/dpt/o path=/get params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=0
[junit4:junit4]   2> 1856160 T4381 C727 P53358 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4]   2> 1856161 T4381 C727 P53358 oasu.DirectUpdateHandler2.commit No uncommitted changes. Skipping IW.commit.
[junit4:junit4]   2> 1856161 T4381 C727 P53358 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 1856162 T4381 C727 P53358 oasup.LogUpdateProcessor.finish [collection1] webapp=/dpt/o path=/update params={waitSearcher=true&openSearcher=false&commit=true&wt=javabin&commit_end_point=true&version=2&softCommit=false} {commit=} 0 2
[junit4:junit4]   2> 1856163 T4426 C726 P53365 oash.ReplicationHandler.inform Commits will be reserved for  10000
[junit4:junit4]   2> 1856163 T4426 C726 P53365 oash.SnapPuller.<init>  No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4]   2> 1856165 T4383 C727 P53358 oasc.SolrCore.execute [collection1] webapp=/dpt/o path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=0
[junit4:junit4]   2> 1856166 T4426 C726 P53365 oasc.RecoveryStrategy.replay No replay needed. core=collection1
[junit4:junit4]   2> 1856166 T4426 C726 P53365 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4]   2> 1856166 T4426 C726 P53365 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4]   2> 1856166 T4426 C726 P53365 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 1856168 T4426 C726 P53365 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4]   2> 1856173 T4370 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4]   2> 1856174 T4370 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4]   2>  "operation":"state",
[junit4:junit4]   2>  "core_node_name":"5",
[junit4:junit4]   2>  "numShards":"1",
[junit4:junit4]   2>  "shard":null,
[junit4:junit4]   2>  "roles":null,
[junit4:junit4]   2>  "state":"down",
[junit4:junit4]   2>  "shard_state":"active",
[junit4:junit4]   2>  "core":"collection1",
[junit4:junit4]   2>  "collection":"collection1",
[junit4:junit4]   2>  "shard_range":null,
[junit4:junit4]   2>  "node_name":"127.0.0.1:53372_dpt%2Fo",
[junit4:junit4]   2>  "base_url":"http://127.0.0.1:53372/dpt/o"}
[junit4:junit4]   2> 1856174 T4370 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=1
[junit4:junit4]   2> 1856174 T4370 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard1
[junit4:junit4]   2> 1856190 T4370 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4]   2>  "operation":"state",
[junit4:junit4]   2>  "core_node_name":"4",
[junit4:junit4]   2>  "numShards":"1",
[junit4:junit4]   2>  "shard":"shard1",
[junit4:junit4]   2>  "roles":null,
[junit4:junit4]   2>  "state":"active",
[junit4:junit4]   2>  "shard_state":"active",
[junit4:junit4]   2>  "core":"collection1",
[junit4:junit4]   2>  "collection":"collection1",
[junit4:junit4]   2>  "shard_range":null,
[junit4:junit4]   2>  "node_name":"127.0.0.1:53365_dpt%2Fo",
[junit4:junit4]   2>  "base_url":"http://127.0.0.1:53365/dpt/o"}
[junit4:junit4]   2> 1856198 T4405 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 1856199 T4389 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 1856200 T4369 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 1856200 T4440 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 1856199 T4376 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 1856200 T4422 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 1856800 T4441 oasc.CoreContainer.create 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.SyncSliceTest-jetty4-1372390283612/collection1
[junit4:junit4]   2> 1856801 T4441 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 1856802 T4441 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 1856803 T4441 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 1856806 T4441 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty4-1372390283612/collection1/'
[junit4:junit4]   2> 1856807 T4441 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-jetty4-1372390283612/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 1856807 T4441 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-jetty4-1372390283612/collection1/lib/README' to classloader
[junit4:junit4]   2> 1856869 T4441 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4]   2> 1856927 T4441 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 1856930 T4441 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4]   2> 1856942 T4441 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4]   2> 1857582 T4441 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4:junit4]   2> 1857583 T4441 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4:junit4]   2> 1857584 T4441 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 1857596 T4441 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 1857599 T4441 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 1857636 T4441 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 1857643 T4441 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 1857653 T4441 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 1857655 T4441 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 1857656 T4441 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4]   2> 1857656 T4441 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 1857658 T4441 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 1857658 T4441 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4]   2> 1857658 T4441 oasc.SolrCore.initDirectoryFactory solr.NRTCachingDirectoryFactory
[junit4:junit4]   2> 1857659 T4441 oasc.SolrCore.<init> [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.SyncSliceTest-jetty4-1372390283612/collection1/, dataDir=./org.apache.solr.cloud.SyncSliceTest-1372390265577/jetty4/
[junit4:junit4]   2> 1857659 T4441 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@4578aae1
[junit4:junit4]   2> 1857660 T4441 oasc.SolrCore.initDirectoryFactory solr.NRTCachingDirectoryFactory
[junit4:junit4]   2> 1857664 T4441 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-1372390265577/jetty4
[junit4:junit4]   2> 1857665 T4441 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.SyncSliceTest-1372390265577/jetty4/index/
[junit4:junit4]   2> 1857666 T4441 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.SyncSliceTest-1372390265577/jetty4/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 1857667 T4441 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-1372390265577/jetty4/index
[junit4:junit4]   2> 1857675 T4441 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4]   2> commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-1372390265577/jetty4/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@40d9cd4e; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1}
[junit4:junit4]   2> 1857676 T4441 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4]   2> 1857680 T4441 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 1857681 T4441 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 1857682 T4441 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 1857683 T4441 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 1857684 T4441 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 1857684 T4441 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 1857689 T4441 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 1857693 T4441 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 1857698 T4441 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 1857713 T4441 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 1857728 T4441 oass.SolrIndexSearcher.<init> Opening Searcher@7ecb09a6 main
[junit4:junit4]   2> 1857730 T4441 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 1857730 T4441 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 1857736 T4443 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@7ecb09a6 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 1857741 T4441 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4]   2> 1857741 T4441 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:53372/dpt/o collection:collection1 shard:shard1
[junit4:junit4]   2> 1857748 T4441 oasc.ZkController.register We are http://127.0.0.1:53372/dpt/o/collection1/ and leader is http://127.0.0.1:53358/dpt/o/collection1/
[junit4:junit4]   2> 1857749 T4441 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:53372/dpt/o
[junit4:junit4]   2> 1857749 T4441 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4]   2> 1857749 T4441 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4]   2> ASYNC  NEW_CORE C728 name=collection1 org.apache.solr.core.SolrCore@6650dc54 url=http://127.0.0.1:53372/dpt/o/collection1 node=127.0.0.1:53372_dpt%2Fo C728_STATE=coll:collection1 core:collection1 props:{state=down, core=collection1, collection=collection1, node_name=127.0.0.1:53372_dpt%2Fo, base_url=http://127.0.0.1:53372/dpt/o}
[junit4:junit4]   2> 1857750 T4444 C728 P53372 oasc.RecoveryStrategy.run Starting recovery process.  core=collection1 recoveringAfterStartup=true
[junit4:junit4]   2> 1857751 T4444 C728 P53372 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4]   2> 1857751 T4444 C728 P53372 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4]   2> 1857751 T4444 C728 P53372 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 1857755 T4444 C728 P53372 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 1857767 T4441 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4]   2> 1857797 T4347 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0
[junit4:junit4]   2> 1857798 T4347 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 1857798 T4347 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 1857822 T4379 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: 5, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4]   2> 1857833 T4347 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4]   2> 1857836 T4347 oasc.AbstractFullDistribZkTestBase.waitForThingsToLevelOut Wait for recoveries to finish - wait 15 for each attempt
[junit4:junit4]   2> 1857837 T4347 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Wait for recoveries to finish - collection: collection1 failOnTimeout:true timeout (sec):15
[junit4:junit4]   2> 1857838 T4347 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4]   2> 1858847 T4347 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4]   2> 1859228 T4370 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4]   2> 1859230 T4370 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4]   2>  "operation":"state",
[junit4:junit4]   2>  "core_node_name":"5",
[junit4:junit4]   2>  "numShards":"1",
[junit4:junit4]   2>  "shard":"shard1",
[junit4:junit4]   2>  "roles":null,
[junit4:junit4]   2>  "state":"recovering",
[junit4:junit4]   2>  "shard_state":"active",
[junit4:junit4]   2>  "core":"collection1",
[junit4:junit4]   2>  "collection":"collection1",
[junit4:junit4]   2>  "shard_range":null,
[junit4:junit4]   2>  "node_name":"127.0.0.1:53372_dpt%2Fo",
[junit4:junit4]   2>  "base_url":"http://127.0.0.1:53372/dpt/o"}
[junit4:junit4]   2> 1859246 T4376 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 1859246 T4369 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 1859247 T4422 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 1859258 T4389 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 1859259 T4405 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 1859259 T4440 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 1859829 T4379 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: 5, state: recovering, checkLive: true, onlyIfLeader: true for: 2 seconds.
[junit4:junit4]   2> 1859830 T4379 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={coreNodeName=5&state=recovering&nodeName=127.0.0.1:53372_dpt%252Fo&action=PREPRECOVERY&checkLive=true&core=collection1&wt=javabin&onlyIfLeader=true&version=2} status=0 QTime=2008
[junit4:junit4]   2> 1859857 T4347 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4]   2> 1860862 T4347 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4]   2>  C728_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=recovering, core=collection1, collection=collection1, node_name=127.0.0.1:53372_dpt%2Fo, base_url=http://127.0.0.1:53372/dpt/o}
[junit4:junit4]   2> 1861832 T4444 C728 P53372 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:53358/dpt/o/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4]   2> 1861832 T4444 C728 P53372 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:53372/dpt/o START replicas=[http://127.0.0.1:53358/dpt/o/collection1/] nUpdates=100
[junit4:junit4]   2> 1861833 T4444 C728 P53372 oasu.PeerSync.sync WARN no frame of reference to tell of we've missed updates
[junit4:junit4]   2> 1861833 T4444 C728 P53372 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4]   2> 1861833 T4444 C728 P53372 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4]   2> 1861834 T4444 C728 P53372 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4]   2> 1861834 T4444 C728 P53372 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4]   2> 1861834 T4444 C728 P53372 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:53358/dpt/o/collection1/. core=collection1
[junit4:junit4]   2> 1861834 T4444 C728 P53372 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> ASYNC  NEW_CORE C729 name=collection1 org.apache.solr.core.SolrCore@2ff2f56 url=http://127.0.0.1:53358/dpt/o/collection1 node=127.0.0.1:53358_dpt%2Fo C729_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:53358_dpt%2Fo, base_url=http://127.0.0.1:53358/dpt/o, leader=true}
[junit4:junit4]   2> 1861836 T4379 C729 P53358 oasc.SolrCore.execute [collection1] webapp=/dpt/o path=/get params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=0
[junit4:junit4]   2> 1861873 T4347 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4]   2> 1861875 T4384 C729 P53358 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4]   2> 1861875 T4384 C729 P53358 oasu.DirectUpdateHandler2.commit No uncommitted changes. Skipping IW.commit.
[junit4:junit4]   2> 1861876 T4384 C729 P53358 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 1861877 T4384 C729 P53358 oasup.LogUpdateProcessor.finish [collection1] webapp=/dpt/o path=/update params={waitSearcher=true&openSearcher=false&commit=true&wt=javabin&commit_end_point=true&version=2&softCommit=false} {commit=} 0 3
[junit4:junit4]   2> 1861878 T4444 C728 P53372 oash.ReplicationHandler.inform Commits will be reserved for  10000
[junit4:junit4]   2> 1861879 T4444 C728 P53372 oash.SnapPuller.<init>  No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4]   2> 1861883 T4380 C729 P53358 oasc.SolrCore.execute [collection1] webapp=/dpt/o path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=1
[junit4:junit4]   2> 1861889 T4444 C728 P53372 oasc.RecoveryStrategy.replay No replay needed. core=collection1
[junit4:junit4]   2> 1861889 T4444 C728 P53372 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4]   2> 1861889 T4444 C728 P53372 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4]   2> 1861890 T4444 C728 P53372 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 1861892 T4444 C728 P53372 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4]   2> 1862274 T4370 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4]   2> 1862276 T4370 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4]   2>  "operation":"state",
[junit4:junit4]   2>  "core_node_name":"5",
[junit4:junit4]   2>  "numShards":"1",
[junit4:junit4]   2>  "shard":"shard1",
[junit4:junit4]   2>  "roles":null,
[junit4:junit4]   2>  "state":"active",
[junit4:junit4]   2>  "shard_state":"active",
[junit4:junit4]   2>  "core":"collection1",
[junit4:junit4]   2>  "collection":"collection1",
[junit4:junit4]   2>  "shard_range":null,
[junit4:junit4]   2>  "node_name":"127.0.0.1:53372_dpt%2Fo",
[junit4:junit4]   2>  "base_url":"http://127.0.0.1:53372/dpt/o"}
[junit4:junit4]   2> 1862286 T4389 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 1862286 T4405 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 1862286 T4440 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 1862286 T4369 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 1862286 T4376 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 1862287 T4422 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 1862884 T4347 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4]   2> 1862886 T4347 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Recoveries finished - collection: collection1
[junit4:junit4]   2> ASYNC  NEW_CORE C730 name=collection1 org.apache.solr.core.SolrCore@15d9b140 url=http://127.0.0.1:53354/dpt/o/collection1 node=127.0.0.1:53354_dpt%2Fo C730_STATE=coll:control_collection core:collection1 props:{shard=shard1, state=active, core=collection1, collection=control_collection, node_name=127.0.0.1:53354_dpt%2Fo, base_url=http://127.0.0.1:53354/dpt/o, leader=true}
[junit4:junit4]   2> 1862896 T4365 C730 P53354 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4]   2> 1862903 T4365 C730 P53354 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4]   2> commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-1372390265577/control/data/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@7e1bea2e; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1}
[junit4:junit4]   2> 1862904 T4365 C730 P53354 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4]   2> 1862905 T4365 C730 P53354 oasu.DirectUpdateHandler2.commit No uncommitted changes. Skipping IW.commit.
[junit4:junit4]   2> 1862906 T4365 C730 P53354 oass.SolrIndexSearcher.<init> Opening Searcher@45c7bf93 main
[junit4:junit4]   2> 1862906 T4365 C730 P53354 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 1862908 T4373 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@45c7bf93 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4:junit4]   2> 1862909 T4365 C730 P53354 oasup.LogUpdateProcessor.finish [collection1] webapp=/dpt/o path=/update params={waitSearcher=true&commit=true&wt=javabin&version=2&softCommit=false} {commit=} 0 13
[junit4:junit4]   2> ASYNC  NEW_CORE C731 name=collection1 org.apache.solr.core.SolrCore@2cfd52ee url=http://127.0.0.1:53365/dpt/o/collection1 node=127.0.0.1:53365_dpt%2Fo C731_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:53365_dpt%2Fo, base_url=http://127.0.0.1:53365/dpt/o}
[junit4:junit4]   2> 1862967 T4414 C731 P53365 oasu.SolrCmdDistributor.distribCommit Distrib commit to:[StdNode: http://127.0.0.1:53358/dpt/o/collection1/, StdNode: http://127.0.0.1:53361/dpt/o/collection1/, StdNode: http://127.0.0.1:53365/dpt/o/collection1/, StdNode: http://127.0.0.1:53372/dpt/o/collection1/] params:commit_end_point=true&commit=true&softCommit=false&waitSearcher=true&expungeDeletes=false
[junit4:junit4]   2> ASYNC  NEW_CORE C732 name=collection1 org.apache.solr.core.SolrCore@2ff2f56 url=http://127.0.0.1:53358/dpt/o/collection1 node=127.0.0.1:53358_dpt%2Fo C732_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:53358_dpt%2Fo, base_url=http://127.0.0.1:53358/dpt/o, leader=true}
[junit4:junit4]   2> 1863037 T4383 C732 P53358 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4]   2> 1863038 T4383 C732 P53358 oasu.DirectUpdateHandler2.commit No uncommitted changes. Skipping IW.commit.
[junit4:junit4]   2> 1863039 T4383 C732 P53358 oass.SolrIndexSearcher.<init> Opening Searcher@3abcab10 main
[junit4:junit4]   2> 1863039 T4383 C732 P53358 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> ASYNC  NEW_CORE C733 name=collection1 org.apache.solr.core.SolrCore@43539e01 url=http://127.0.0.1:53361/dpt/o/collection1 node=127.0.0.1:53361_dpt%2Fo C733_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:53361_dpt%2Fo, base_url=http://127.0.0.1:53361/dpt/o}
[junit4:junit4]   2> 1863048 T4400 C733 P53361 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4]   2> 1863061 T4400 C733 P53361 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4]   2> commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-1372390265577/jetty2/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@7793a105; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1}
[junit4:junit4]   2> 1863061 T4391 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@3abcab10 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4:junit4]   2> ASYNC  NEW_CORE C734 name=collection1 org.apache.solr.core.SolrCore@6650dc54 url=http://127.0.0.1:53372/dpt/o/collection1 node=127.0.0.1:53372_dpt%2Fo C734_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:53372_dpt%2Fo, base_url=http://127.0.0.1:53372/dpt/o}
[junit4:junit4]   2> 1863063 T4436 C734 P53372 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4]   2> 1863063 T4400 C733 P53361 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4]   2> 1863068 T4383 C732 P53358 oasup.LogUpdateProcessor.finish [collection1] webapp=/dpt/o path=/update params={waitSearcher=true&commit=true&wt=javabin&expungeDeletes=false&commit_end_point=true&version=2&softCommit=false} {commit=} 0 31
[junit4:junit4]   2> ASYNC  NEW_CORE C735 name=collection1 org.apache.solr.core.SolrCore@2cfd52ee url=http://127.0.0.1:53365/dpt/o/collection1 node=127.0.0.1:53365_dpt%2Fo C735_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:53365_dpt%2Fo, base_url=http://127.0.0.1:53365/dpt/o}
[junit4:junit4]   2> 1863067 T4415 C735 P53365 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4]   2> 1863076 T4415 C735 P53365 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4]   2> commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-1372390265577/jetty3/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@1300138a; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1}
[junit4:junit4]   2> 1863077 T4400 C733 P53361 oasu.DirectUpdateHandler2.commit No uncommitted changes. Skipping IW.commit.
[junit4:junit4]   2> 1863079 T4400 C733 P53361 oass.SolrIndexSearcher.<init> Opening Searcher@52fed6f9 main
[junit4:junit4]   2> 1863080 T4415 C735 P53365 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4]   2> 1863080 T4415 C735 P53365 oasu.DirectUpdateHandler2.commit No uncommitted changes. Skipping IW.commit.
[junit4:junit4]   2> 1863081 T4415 C735 P53365 oass.SolrIndexSearcher.<init> Opening Searcher@2dad8d8f main
[junit4:junit4]   2> 1863082 T4415 C735 P53365 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 1863083 T4425 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@2dad8d8f main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4:junit4]   2> 1863085 T4400 C733 P53361 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 1863086 T4436 C734 P53372 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4]   2> commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-1372390265577/jetty4/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@40d9cd4e; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1}
[junit4:junit4]   2> 1863086 T4407 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@52fed6f9 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4:junit4]   2> 1863087 T4415 C735 P53365 oasup.LogUpdateProcessor.finish [collection1] webapp=/dpt/o path=/update params={waitSearcher=true&commit=true&wt=javabin&expungeDeletes=false&commit_end_point=true&version=2&softCommit=false} {commit=} 0 20
[junit4:junit4]   2> 1863088 T4436 C734 P53372 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4]   2> 1863091 T4436 C734 P53372 oasu.DirectUpdateHandler2.commit No uncommitted changes. Skipping IW.commit.
[junit4:junit4]   2> 1863091 T4436 C734 P53372 oass.SolrIndexSearcher.<init> Opening Searcher@46f5c831 main
[junit4:junit4]   2> 1863092 T4436 C734 P53372 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 1863093 T4443 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@46f5c831 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4:junit4]   2> 1863090 T4400 C733 P53361 oasup.LogUpdateProcessor.finish [collection1] webapp=/dpt/o path=/update params={waitSearcher=true&commit=true&wt=javabin&expungeDeletes=false&commit_end_point=true&version=2&softCommit=false} {commit=} 0 42
[junit4:junit4]   2> 1863094 T4436 C734 P53372 oasup.LogUpdateProcessor.finish [collection1] webapp=/dpt/o path=/update params={waitSearcher=true&commit=true&wt=javabin&expungeDeletes=false&commit_end_point=true&version=2&softCommit=false} {commit=} 0 31
[junit4:junit4]   2> 1863096 T4414 C735 P53365 oasup.LogUpdateProcessor.finish [collection1] webapp=/dpt/o path=/update params={waitSearcher=true&commit=true&wt=javabin&version=2&softCommit=false} {commit=} 0 129
[junit4:junit4]   2> 1863098 T4347 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4]   2> 1863105 T4384 C732 P53358 oasc.SolrCore.execute [collection1] webapp=/dpt/o path=/select params={tests=checkShardConsistency&q=*:*&distrib=false&wt=javabin&version=2&rows=0} hits=0 status=0 QTime=0
[junit4:junit4]   2> 1863111 T4401 C733 P53361 oasc.SolrCore.execute [collection1] webapp=/dpt/o path=/select params={tests=checkShardConsistency&q=*:*&distrib=false&wt=javabin&version=2&rows=0} hits=0 status=0 QTime=0
[junit4:junit4]   2> 1863116 T4416 C735 P53365 oasc.SolrCore.execute [collection1] webapp=/dpt/o path=/select params={tests=checkShardConsistency&q=*:*&distrib=false&wt=javabin&version=2&rows=0} hits=0 status=0 QTime=0
[junit4:junit4]   2> 1863122 T4431 C734 P53372 oasc.SolrCore.execute [collection1] webapp=/dpt/o path=/select params={tests=checkShardConsistency&q=*:*&distrib=false&wt=javabin&version=2&rows=0} hits=0 status=0 QTime=1
[junit4:junit4]   2> ASYNC  NEW_CORE C736 name=collection1 org.apache.solr.core.SolrCore@15d9b140 url=http://127.0.0.1:53354/dpt/o/collection1 node=127.0.0.1:53354_dpt%2Fo C736_STATE=coll:control_collection core:collection1 props:{shard=shard1, state=active, core=collection1, collection=control_collection, node_name=127.0.0.1:53354_dpt%2Fo, base_url=http://127.0.0.1:53354/dpt/o, leader=true}
[junit4:junit4]   2> 1865128 T4365 C736 P53354 oasup.LogUpdateProcessor.finish [collection1] webapp=/dpt/o path=/update params={wt=javabin&version=2} {deleteByQuery=*:* (-1439055526636814336)} 0 1
[junit4:junit4]   2> 1865166 T4431 C734 P53372 oasup.LogUpdateProcessor.finish [collection1] webapp=/dpt/o path=/update params={update.distrib=FROMLEADER&_version_=-1439055526644154368&update.from=http://127.0.0.1:53358/dpt/o/collection1/&wt=javabin&version=2} {deleteByQuery=*:* (-1439055526644154368)} 0 9
[junit4:junit4]   2> 1865169 T4417 C735 P53365 oasup.LogUpdateProcessor.finish [collection1] webapp=/dpt/o path=/update params={update.distrib=FROMLEADER&_version_=-1439055526644154368&update.from=http://127.0.0.1:53358/dpt/o/collection1/&wt=javabin&version=2} {deleteByQuery=*:* (-1439055526644154368)} 0 6
[junit4:junit4]   2> 1865176 T4401 C733 P53361 oasup.LogUpdateProcessor.finish [collection1] webapp=/dpt/o path=/update params={update.distrib=FROMLEADER&_version_=-1439055526644154368&update.from=http://127.0.0.1:53358/dpt/o/collection1/&wt=javabin&version=2} {deleteByQuery=*:* (-1439055526644154368)} 0 6
[junit4:junit4]   2> 1865178 T4383 C732 P53358 oasup.LogUpdateProcessor.finish [collection1] webapp=/dpt/o path=/update params={update.distrib=TOLEADER&wt=javabin&version=2} {deleteByQuery=*:* (-1439055526644154368)} 0 44
[junit4:junit4]   2> 1865179 T4416 C735 P53365 oasup.LogUpdateProcessor.finish [collection1] webapp=/dpt/o path=/update params={wt=javabin&version=2} {deleteByQuery=*:*} 0 48
[junit4:junit4]   2> 1865185 T4360 C736 P53354 oasup.LogUpdateProcessor.finish [collection1] webapp=/dpt/o path=/update params={wt=javabin&version=2} {add=[0 (1439055526695534592)]} 0 2
[junit4:junit4]   2> 1865198 T4396 C733 P53361 oasup.LogUpdateProcessor.finish [collection1] webapp=/dpt/o path=/update params={distrib.from=http://127.0.0.1:53358/dpt/o/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[0 (1439055526703923200)]} 0 2
[junit4:junit4]   2> 1865201 T4413 C735 P53365 oasup.LogUpdateProcessor.finish [collection1] webapp=/dpt/o path=/update params={distrib.from=http://127.0.0.1:53358/dpt/o/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[0 (1439055526703923200)]} 0 2
[junit4:junit4]   2> 1865204 T4432 C734 P53372 oasup.LogUpdateProcessor.finish [collection1] webapp=/dpt/o path=/update params={distrib.from=http://127.0.0.1:53358/dpt/o/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[0 (1439055526703923200)]} 0 2
[junit4:junit4]   2> 1865205 T4382 C732 P53358 oasup.LogUpdateProcessor.finish [collection1] webapp=/dpt/o path=/update params={distrib.from=http://127.0.0.1:53365/dpt/o/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[0 (1439055526703923200)]} 0 14
[junit4:junit4]   2> 1865206 T4418 C735 P53365 oasup.LogUpdateProcessor.finish [collection1] webapp=/dpt/o path=/update params={wt=javabin&version=2} {add=[0]} 0 17
[junit4:junit4]   2> 1865210 T4361 C736 P53354 oasup.LogUpdateProcessor.finish [collection1] webapp=/dpt/o path=/update params={wt=javabin&version=2} {add=[1 (1439055526722797568)]} 0 1
[junit4:junit4]   2> 1865221 T4433 C734 P53372 oasup.LogUpdateProcessor.finish [collection1] webapp=/dpt/o path=/update params={distrib.from=http://127.0.0.1:53358/dpt/o/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[1 (1439055526730137600)]} 0 1
[junit4:junit4]   2> 1865224 T4397 C733 P53361 oasup.LogUpdateProcessor.finish [collection1] webapp=/dpt/o path=/update params={distrib.from=http://127.0.0.1:53358/dpt/o/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[1 (1439055526730137600)]} 0 1
[junit4:junit4]   2> 1865226 T4414 C735 P53365 oasup.LogUpdateProcessor.finish [collection1] webapp=/dpt/o path=/update params={distrib.from=http://127.0.0.1:53358/dpt/o/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[1 (1439055526730137600)]} 0 1
[junit4:junit4]   2> 1865229 T4380 C732 P53358 oasup.LogUpdateProcessor.finish [collection1] webapp=/dpt/o path=/update params={distrib.from=http://127.0.0.1:53365/dpt/o/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[1 (1439055526730137600)]} 0 14
[junit4:junit4]   2> 1865230 T4415 C735 P53365 oasup.LogUpdateProcessor.finish [collection1] webapp=/dpt/o path=/update params={wt=javabin&version=2} {add=[1]} 0 17
[junit4:junit4]   2> 1865235 T4362 C736 P53354 oasup.LogUpdateProcessor.finish [collection1] webapp=/dpt/o path=/update params={wt=javabin&version=2} {add=[2 (1439055526749011968)]} 0 1
[junit4:junit4]   2> 1865242 T4381 C732 P53358 oasup.DistributedUpdateProcessor.setupRequest test.distrib.skip.servers was found and contains:[http://127.0.0.1:53361/dpt/o/collection1/]
[junit4:junit4]   2> 1865243 T4381 C732 P53358 oasup.DistributedUpdateProcessor.setupRequest check url:http://127.0.0.1:53361/dpt/o/collection1/ against:[http://127.0.0.1:53361/dpt/o/collection1/] result:true
[junit4:junit4]   2> 1865244 T4381 C732 P53358 oasup.DistributedUpdateProcessor.setupRequest check url:http://127.0.0.1:53365/dpt/o/collection1/ against:[http://127.0.0.1:53361/dpt/o/collection1/] result:false
[junit4:junit4]   2> 1865244 T4381 C732 P53358 oasup.DistributedUpdateProcessor.setupRequest check url:http://127.0.0.1:53372/dpt/o/collection1/ against:[http://127.0.0.1:53361/dpt/o/collection1/] result:false
[junit4:junit4]   2> 1865257 T4417 C735 P53365 oasup.LogUpdateProcessor.finish [collection1] webapp=/dpt/o path=/update params={distrib.from=http://127.0.0.1:53358/dpt/o/collection1/&update.distrib=FROMLEADER&test.distrib.skip.servers=http://127.0.0.1:53361/dpt/o/collection1/&wt=javabin&version=2} {add=[2 (1439055526761594880)]} 0 1
[junit4:junit4]   2> 1865257 T4434 C734 P53372 oasup.LogUpdateProcessor.finish [collection1] webapp=/dpt/o path=/update params={distrib.from=http://127.0.0.1:53358/dpt/o/collection1/&update.distrib=FROMLEADER&test.distrib.skip.servers=http://127.0.0.1:53361/dpt/o/collection1/&wt=javabin&version=2} {add=[2 (1439055526761594880)]} 0 1
[junit4:junit4]   2> 1865259 T4381 C732 P53358 oasup.LogUpdateProcessor.finish [collection1] webapp=/dpt/o path=/update params={test.distrib.skip.servers=http://127.0.0.1:53361/dpt/o/collection1/&wt=javabin&version=2} {add=[2 (1439055526761594880)]} 0 17
[junit4:junit4]   2> 1865264 T4363 C736 P53354 oasup.LogUpdateProcessor.finish [collection1] webapp=/dpt/o path=/update params={wt=javabin&version=2} {add=[3 (1439055526779420672)]} 0 1
[junit4:junit4]   2> 1865277 T4379 C732 P53358 oasup.DistributedUpdateProcessor.setupRequest test.distrib.skip.servers was found and contains:[http://127.0.0.1:53361/dpt/o/collection1/]
[junit4:junit4]   2> 1865279 T4379 C732 P53358 oasup.DistributedUpdateProcessor.setupRequest check url:http://127.0.0.1:53361/dpt/o/collection1/ against:[http://127.0.0.1:53361/dpt/o/collection1/] result:true
[junit4:junit4]   2> 1865279 T4379 C732 P53358 oasup.DistributedUpdateProcessor.setupRequest check url:http://127.0.0.1:53365/dpt/o/collection1/ against:[http://127.0.0.1:53361/dpt/o/collection1/] result:false
[junit4:junit4]   2> 1865280 T4379 C732 P53358 oasup.DistributedUpdateProcessor.setupRequest check url:http://127.0.0.1:53372/dpt/o/collection1/ against:[http://127.0.0.1:53361/dpt/o/collection1/] result:false
[junit4:junit4]   2> 1865287 T4416 C735 P53365 oasup.LogUpdateProcessor.finish [collection1] webapp=/dpt/o path=/update params={distrib.from=http://127.0.0.1:53358/dpt/o/collection1/&update.distrib=FROMLEADER&test.distrib.skip.servers=http://127.0.0.1:53361/dpt/o/collection1/&wt=javabin&version=2} {add=[3 (1439055526798295040)]} 0 2
[junit4:junit4]   2> 1865290 T4435 C734 P53372 oasup.LogUpdateProcessor.finish [collection1] webapp=/dpt/o path=/update params={distrib.from=http://127.0.0.1:53358/dpt/o/collection1/&update.distrib=FROMLEADER&test.distrib.skip.servers=http://127.0.0.1:53361/dpt/o/collection1/&wt=javabin&version=2} {add=[3 (1439055526798295040)]} 0 1
[junit4:junit4]   2> 1865292 T4379 C732 P53358 oasup.LogUpdateProcessor.finish [collection1] webapp=/dpt/o path=/update params={distrib.from=http://127.0.0.1:53361/dpt/o/collection1/&update.distrib=TOLEADER&test.distrib.skip.servers=http://127.0.0.1:53361/dpt/o/collection1/&wt=javabin&version=2} {add=[3 (1439055526798295040)]} 0 15
[junit4:junit4]   2> 1865294 T4398 C733 P53361 oasup.LogUpdateProcessor.finish [collection1] webapp=/dpt/o path=/update params={test.distrib.skip.servers=http://127.0.0.1:53361/dpt/o/collection1/&test.distrib.skip.servers=http://127.0.0.1:53365/dpt/o/collection1/&wt=javabin&version=2} {add=[3]} 0 25
[junit4:junit4]   2> 1865300 T4364 C736 P53354 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4]   2> 1865366 T4364 C736 P53354 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4]   2> commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-1372390265577/control/data/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@7e1bea2e; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1}
[junit4:junit4]   2> commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-1372390265577/control/data/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@7e1bea2e; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_2,generation=2}
[junit4:junit4]   2> 1865366 T4364 C736 P53354 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4]   2> 1865378 T4364 C736 P53354 oass.SolrIndexSearcher.<init> Opening Searcher@10f7fd3a main
[junit4:junit4]   2> 1865379 T4364 C736 P53354 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 1865381 T4373 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@10f7fd3a main{StandardDirectoryReader(segments_2:3:nrt _0(4.4):C4)}
[junit4:junit4]   2> 1865382 T4364 C736 P53354 oasup.LogUpdateProcessor.finish [collection1] webapp=/dpt/o path=/update params={waitSearcher=true&commit=true&wt=javabin&version=2&softCommit=false} {commit=} 0 83
[junit4:junit4]   2> 1865388 T4436 C734 P53372 oasu.SolrCmdDistributor.distribCommit Distrib commit to:[StdNode: http://127.0.0.1:53358/dpt/o/collection1/, StdNode: http://127.0.0.1:53361/dpt/o/collection1/, StdNode: http://127.0.0.1:53365/dpt/o/collection1/, StdNode: http://127.0.0.1:53372/dpt/o/collection1/] params:commit_end_point=true&commit=true&softCommit=false&waitSearcher=true&expungeDeletes=false
[junit4:junit4]   2> 1865404 T4384 C732 P53358 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4]   2> 1865405 T4399 C733 P53361 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4]   2> 1865419 T4431 C734 P53372 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4]   2> 1865420 T4413 C735 P53365 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4]   2> 1865525 T4384 C732 P53358 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4]   2> commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-1372390265577/jetty1/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@772552de; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1}
[junit4:junit4]   2> commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-1372390265577/jetty1/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@772552de; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_2,generation=2}
[junit4:junit4]   2> 1865526 T4384 C732 P53358 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4]   2> 1865539 T4399 C733 P53361 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4]   2> commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-1372390265577/jetty2/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@7793a105; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1}
[junit4:junit4]   2> commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-1372390265577/jetty2/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@7793a105; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_2,generation=2}
[junit4:junit4]   2> 1865540 T4399 C733 P53361 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4]   2> 1865557 T4431 C734 P53372 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4]   2> commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-1372390265577/jetty4/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@40d9cd4e; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1}
[junit4:junit4]   2> commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-1372390265577/jetty4/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@40d9cd4e; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_2,generation=2}
[junit4:junit4]   2> 1865558 T4431 C734 P53372 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4]   2> 1865561 T4384 C732 P53358 oass.SolrIndexSearcher.<init> Opening Searcher@5b9851d2 main
[junit4:junit4]   2> 1865562 T4384 C732 P53358 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 1865566 T4391 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@5b9851d2 main{StandardDirectoryReader(segments_2:3:nrt _0(4.4):C4)}
[junit4:junit4]   2> 1865567 T4413 C735 P53365 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4]   2> commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-1372390265577/jetty3/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@1300138a; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1}
[junit4:junit4]   2> commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-1372390265577/jetty3/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@1300138a; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_2,generation=2}
[junit4:junit4]   2> 1865568 T4413 C735 P53365 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4]   2> 1865569 T4399 C733 P53361 oass.SolrIndexSearcher.<init> Opening Searcher@7d529bc main
[junit4:junit4]   2> 1865570 T4399 C733 P53361 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 1865570 T4384 C732 P53358 oasup.LogUpdateProcessor.finish [collection1] webapp=/dpt/o path=/update params={waitSearcher=true&commit=true&wt=javabin&expungeDeletes=false&commit_end_point=true&version=2&softCommit=false} {commit=} 0 166
[junit4:junit4]   2> 1865571 T4407 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@7d529bc main{StandardDirectoryReader(segments_2:3:nrt _0(4.4):C2)}
[junit4:junit4]   2> 1865580 T4399 C733 P53361 oasup.LogUpdateProcessor.finish [collection1] webapp=/dpt/o path=/update params={waitSearcher=true&commit=true&wt=javabin&expungeDeletes=false&commit_end_point=true&version=2&softCommit=false} {commit=} 0 175
[junit4:junit4]   2> 1865581 T4431 C734 P53372 oass.SolrIndexSearcher.<init> Opening Searcher@4c3cde78 main
[junit4:junit4]   2> 1865583 T4431 C734 P53372 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 1865584 T4443 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@4c3cde78 main{StandardDirectoryReader(segments_2:3:nrt _0(4.4):C4)}
[junit4:junit4]   2> 1865587 T4431 C734 P53372 oasup.LogUpdateProcessor.finish [collection1] webapp=/dpt/o path=/update params={waitSearcher=true&commit=true&wt=javabin&expungeDeletes=false&commit_end_point=true&version=2&softCommit=false} {commit=} 0 168
[junit4:junit4]   2> 1865587 T4413 C735 P53365 oass.SolrIndexSearcher.<init> Opening Searcher@5786b3b9 main
[junit4:junit4]   2> 1865595 T4413 C735 P53365 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 1865596 T4425 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@5786b3b9 main{StandardDirectoryReader(segments_2:3:nrt _0(4.4):C4)}
[junit4:junit4]   2> 1865598 T4413 C735 P53365 oasup.LogUpdateProcessor.finish [collection1] webapp=/dpt/o path=/update params={waitSearcher=true&commit=true&wt=javabin&expungeDeletes=false&commit_end_point=true&version=2&softCommit=false} {commit=} 0 178
[junit4:junit4]   2> 1865600 T4436 C734 P53372 oasup.LogUpdateProcessor.finish [collection1] webapp=/dpt/o path=/update params={waitSearcher=true&commit=true&wt=javabin&version=2&softCommit=false} {commit=} 0 212
[junit4:junit4]   2> 1865601 T4347 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Wait for recoveries to finish - collection: collection1 failOnTimeout:true timeout (sec):230
[junit4:junit4]   2> 1865603 T4347 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4]   2> 1865605 T4347 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Recoveries finished - collection: collection1
[junit4:junit4]   2> 1865608 T4382 C732 P53358 oasc.SolrCore.execute [collection1] webapp=/dpt/o path=/select params={tests=checkShardConsistency&q=*:*&distrib=false&wt=javabin&version=2&rows=0} hits=4 status=0 QTime=1
[junit4:junit4]   2> 1865612 T4401 C733 P53361 oasc.SolrCore.execute [collection1] webapp=/dpt/o path=/select params={tests=checkShardConsistency&q=*:*&distrib=false&wt=javabin&version=2&rows=0} hits=2 status=0 QTime=0
[junit4:junit4]   2> 1865616 T4414 C735 P53365 oasc.SolrCore.execute [collection1] webapp=/dpt/o path=/select params={tests=checkShardConsistency&q=*:*&distrib=false&wt=javabin&version=2&rows=0} hits=4 status=0 QTime=0
[junit4:junit4]   2> 1865620 T4433 C734 P53372 oasc.SolrCore.execute [collection1] webapp=/dpt/o path=/select params={tests=checkShardConsistency&q=*:*&distrib=false&wt=javabin&version=2&rows=0} hits=4 status=0 QTime=0
[junit4:junit4]   2> 1865621 T4347 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 1865665 T4415 oasha.CollectionsHandler.handleSyncShardAction Syncing shard : shard=shard1&action=SYNCSHARD&collection=collection1&wt=javabin&version=2
[junit4:junit4]   2> 1865665 T4415 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 1865704 T4380 oasha.CoreAdminHandler.handleRequestSyncAction I have been requested to sync up my shard
[junit4:junit4]   2> 1865705 T4380 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:53358/dpt/o/collection1/
[junit4:junit4]   2> 1865705 T4380 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:53358/dpt/o START replicas=[http://127.0.0.1:53361/dpt/o/collection1/, http://127.0.0.1:53365/dpt/o/collection1/, http://127.0.0.1:53372/dpt/o/collection1/] nUpdates=100
[junit4:junit4]   2> 1865715 T4396 C733 P53361 oasc.SolrCore.execute [collection1] webapp=/dpt/o path=/get params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=1
[junit4:junit4]   2> 1865717 T4380 oasu.PeerSync.handleVersions PeerSync: core=collection1 url=http://127.0.0.1:53358/dpt/o  Received 3 versions from 127.0.0.1:53361/dpt/o/collection1/
[junit4:junit4]   2> 1865721 T4380 oasu.PeerSync.handleVersions PeerSync: core=collection1 url=http://127.0.0.1:53358/dpt/o  Our versions are newer. ourLowThreshold=1439055526644154368 otherHigh=1439055526730137600
[junit4:junit4]   2> 1865722 T4434 C734 P53372 oasc.SolrCore.execute [collection1] webapp=/dpt/o path=/get params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=0
[junit4:junit4]   2> 1865725 T4417 C735 P53365 oasc.SolrCore.execute [collection1] webapp=/dpt/o path=/get params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=0
[junit4:junit4]   2> 1865725 T4380 oasu.PeerSync.handleVersions PeerSync: core=collection1 url=http://127.0.0.1:53358/dpt/o  Received 5 versions from 127.0.0.1:53372/dpt/o/collection1/
[junit4:junit4]   2> 1865726 T4380 oasu.PeerSync.handleVersions PeerSync: core=collection1 url=http://127.0.0.1:53358/dpt/o  Our versions are newer. ourLowThreshold=1439055526644154368 otherHigh=1439055526761594880
[junit4:junit4]   2> 1865727 T4380 oasu.PeerSync.handleVersions PeerSync: core=collection1 url=http://127.0.0.1:53358/dpt/o  Received 5 versions from 127.0.0.1:53365/dpt/o/collection1/
[junit4:junit4]   2> 1865727 T4380 oasu.PeerSync.handleVersions PeerSync: core=collection1 url=http://127.0.0.1:53358/dpt/o  Our versions are newer. ourLowThreshold=1439055526644154368 otherHigh=1439055526761594880
[junit4:junit4]   2> 1865728 T4380 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:53358/dpt/o DONE. sync succeeded
[junit4:junit4]   2> 1865728 T4380 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4]   2> 1865728 T4380 oasc.SyncStrategy.syncToMe http://127.0.0.1:53358/dpt/o/collection1/: try and ask http://127.0.0.1:53361/dpt/o/collection1/ to sync
[junit4:junit4]   2> 1865729 T4380 oasc.SyncStrategy.syncToMe http://127.0.0.1:53358/dpt/o/collection1/: try and ask http://127.0.0.1:53365/dpt/o/collection1/ to sync
[junit4:junit4]   2> 1865730 T4380 oasc.SyncStrategy.syncToMe http://127.0.0.1:53358/dpt/o/collection1/: try and ask http://127.0.0.1:53372/dpt/o/collection1/ to sync
[junit4:junit4]   2> 1865743 T4416 C735 P53365 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:53365/dpt/o START replicas=[http://127.0.0.1:53358/dpt/o/collection1/] nUpdates=100
[junit4:junit4]   2> 1865744 T4397 C733 P53361 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:53361/dpt/o START replicas=[http://127.0.0.1:53358/dpt/o/collection1/] nUpdates=100
[junit4:junit4]   2> 1865749 T4381 C732 P53358 oasc.SolrCore.execute [collection1] webapp=/dpt/o path=/get params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=0
[junit4:junit4]   2> 1865750 T4416 C735 P53365 oasu.PeerSync.handleVersions PeerSync: core=collection1 url=http://127.0.0.1:53365/dpt/o  Received 5 versions from 127.0.0.1:53358/dpt/o/collection1/
[junit4:junit4]   2> 1865751 T4416 C735 P53365 oasu.PeerSync.handleVersions PeerSync: core=collection1 url=http://127.0.0.1:53365/dpt/o  Our versions are newer. ourLowThreshold=1439055526644154368 otherHigh=1439055526761594880
[junit4:junit4]   2> 1865753 T4416 C735 P53365 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:53365/dpt/o DONE. sync succeeded
[junit4:junit4]   2> 1865754 T4416 C735 P53365 oasc.SolrCore.execute [collection1] webapp=/dpt/o path=/get params={sync=http://127.0.0.1:53358/dpt/o/collection1/&getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=11
[junit4:junit4]   2> 1865752 T4435 C734 P53372 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:53372/dpt/o START replicas=[http://127.0.0.1:53358/dpt/o/collection1/] nUpdates=100
[junit4:junit4]   2> 1865754 T4379 C732 P53358 oasc.SolrCore.execute [collection1] webapp=/dpt/o path=/get params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=0
[junit4:junit4]   2> 1865755 T4380 oasc.SyncStrategy.syncToMe http://127.0.0.1:53358/dpt/o/collection1/:  sync completed with http://127.0.0.1:53365/dpt/o/collection1/
[junit4:junit4]   2> 1865757 T4397 C733 P53361 oasu.PeerSync.handleVersions PeerSync: core=collection1 url=http://127.0.0.1:53361/dpt/o  Received 5 versions from 127.0.0.1:53358/dpt/o/collection1/
[junit4:junit4]   2> 1865758 T4397 C733 P53361 oasu.PeerSync.requestUpdates PeerSync: core=collection1 url=http://127.0.0.1:53361/dpt/o Requesting updates from 127.0.0.1:53358/dpt/o/collection1/n=2 versions=[1439055526798295040, 1439055526761594880]
[junit4:junit4]   2> 1865759 T4383 C732 P53358 oasc.SolrCore.execute [collection1] webapp=/dpt/o path=/get params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=0
[junit4:junit4]   2> 1865761 T4435 C734 P53372 oasu.PeerSync.handleVersions PeerSync: core=collection1 url=http://127.0.0.1:53372/dpt/o  Received 5 versions from 127.0.0.1:53358/dpt/o/collection1/
[junit4:junit4]   2> 1865761 T4435 C734 P53372 oasu.PeerSync.handleVersions PeerSync: core=collection1 url=http://127.0.0.1:53372/dpt/o  Our versions are newer. ourLowThreshold=1439055526644154368 otherHigh=1439055526761594880
[junit4:junit4]   2> 1865762 T4435 C734 P53372 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:53372/dpt/o DONE. sync succeeded
[junit4:junit4]   2> 1865761 T4383 C732 P53358 oasc.SolrCore.execute [collection1] webapp=/dpt/o path=/get params={distrib=false&getUpdates=1439055526798295040,1439055526761594880&wt=javabin&qt=/get&version=2} status=0 QTime=1
[junit4:junit4]   2> 1865762 T4435 C734 P53372 oasc.SolrCore.execute [collection1] webapp=/dpt/o path=/get params={sync=http://127.0.0.1:53358/dpt/o/collection1/&getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=10
[junit4:junit4]   2> 1865764 T4380 oasc.SyncStrategy.syncToMe http://127.0.0.1:53358/dpt/o/collection1/:  sync completed with http://127.0.0.1:53372/dpt/o/collection1/
[junit4:junit4]   2> 1865770 T4397 C733 P53361 oasup.LogUpdateProcessor.finish [collection1] {add=[2 (1439055526761594880), 3 (1439055526798295040)]} 0 6
[junit4:junit4]   2> 1865770 T4397 C733 P53361 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:53361/dpt/o DONE. sync succeeded
[junit4:junit4]   2> 1865771 T4397 C733 P53361 oasc.SolrCore.execute [collection1] webapp=/dpt/o path=/get params={sync=http://127.0.0.1:53358/dpt/o/collection1/&getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=27
[junit4:junit4]   2> 1865773 T4380 oasc.SyncStrategy.syncToMe http://127.0.0.1:53358/dpt/o/collection1/:  sync completed with http://127.0.0.1:53361/dpt/o/collection1/
[junit4:junit4]   2> 1865773 T4380 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={shard=shard1&action=REQUESTSYNCSHARD&core=collection1&collection=collection1&wt=javabin&version=2} status=0 QTime=69
[junit4:junit4]   2> 1865774 T4415 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/collections params={shard=shard1&action=SYNCSHARD&collection=collection1&wt=javabin&version=2} status=0 QTime=110
[junit4:junit4]   2> 1865775 T4347 oasc.AbstractFullDistribZkTestBase.waitForThingsToLevelOut Wait for recoveries to finish - wait 15 for each attempt
[junit4:junit4]   2> 1865776 T4347 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Wait for recoveries to finish - collection: collection1 failOnTimeout:true timeout (sec):15
[junit4:junit4]   2> 1865778 T4347 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4]   2> 1865780 T4347 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Recoveries finished - collection: collection1
[junit4:junit4]   2> 1865783 T4360 C736 P53354 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4]   2> 1865784 T4360 C736 P53354 oasu.DirectUpdateHandler2.commit No uncommitted changes. Skipping IW.commit.
[junit4:junit4]   2> 1865785 T4360 C736 P53354 oass.SolrIndexSearcher.<init> Opening Searcher@68bedd6c main
[junit4:junit4]   2> 1865786 T4360 C736 P53354 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 1865787 T4373 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@68bedd6c main{StandardDirectoryReader(segments_2:3:nrt _0(4.4):C4)}
[junit4:junit4]   2> 1865788 T4360 C736 P53354 oasup.LogUpdateProcessor.finish [collection1] webapp=/dpt/o path=/update params={waitSearcher=true&commit=true&wt=javabin&version=2&softCommit=false} {commit=} 0 5
[junit4:junit4]   2> 1865791 T4382 C732 P53358 oasu.SolrCmdDistributor.distribCommit Distrib commit to:[StdNode: http://127.0.0.1:53358/dpt/o/collection1/, StdNode: http://127.0.0.1:53361/dpt/o/collection1/, StdNode: http://127.0.0.1:53365/dpt/o/collection1/, StdNode: http://127.0.0.1:53372/dpt/o/collection1/] params:commit_end_point=true&commit=true&softCommit=false&waitSearcher=true&expungeDeletes=false
[junit4:junit4]   2> 1865797 T4398 C733 P53361 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4]   2> 1865797 T4413 C735 P53365 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4]   2> 1865801 T4381 C732 P53358 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4]   2> 1865802 T4381 C732 P53358 oasu.DirectUpdateHandler2.commit No uncommitted changes. Skipping IW.commit.
[junit4:junit4]   2> 1865803 T4381 C732 P53358 oass.SolrIndexSearcher.<init> Opening Searcher@5d10ef3 main
[junit4:junit4]   2> 1865804 T4381 C732 P53358 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 1865806 T4391 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@5d10ef3 main{StandardDirectoryReader(segments_2:3:nrt _0(4.4):C4)}
[junit4:junit4]   2> 1865806 T4381 C732 P53358 oasup.LogUpdateProcessor.finish [collection1] webapp=/dpt/o path=/update params={waitSearcher=true&commit=true&wt=javabin&expungeDeletes=false&commit_end_point=true&version=2&softCommit=false} {commit=} 0 5
[junit4:junit4]   2> 1865808 T4413 C735 P53365 oasu.DirectUpdateHandler2.commit No uncommitted changes. Skipping IW.commit.
[junit4:junit4]   2> 1865809 T4413 C735 P53365 oass.SolrIndexSearcher.<init> Opening Searcher@717fed4 main
[junit4:junit4]   2> 1865810 T4425 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@717fed4 main{StandardDirectoryReader(segments_2:3:nrt _0(4.4):C4)}
[junit4:junit4]   2> 1865811 T4413 C735 P53365 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 1865801 T4432 C734 P53372 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4]   2> 1865817 T4432 C734 P53372 oasu.DirectUpdateHandler2.commit No uncommitted changes. Skipping IW.commit.
[junit4:junit4]   2> 1865818 T4432 C734 P53372 oass.SolrIndexSearcher.<init> Opening Searcher@106a6db main
[junit4:junit4]   2> 1865819 T4432 C734 P53372 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 1865822 T4443 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@106a6db main{StandardDirectoryReader(segments_2:3:nrt _0(4.4):C4)}
[junit4:junit4]   2> 1865824 T4413 C735 P53365 oasup.LogUpdateProcessor.finish [collection1] webapp=/dpt/o path=/update params={waitSearcher=true&commit=true&wt=javabin&expungeDeletes=false&commit_end_point=true&version=2&softCommit=false} {commit=} 0 27
[junit4:junit4]   2> 1865825 T4432 C734 P53372 oasup.LogUpdateProcessor.finish [collection1] webapp=/dpt/o path=/update params={waitSearcher=true&commit=true&wt=javabin&expungeDeletes=false&commit_end_point=true&version=2&softCommit=false} {commit=} 0 25
[junit4:junit4]   2> 1865861 T4398 C733 P53361 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4]   2> commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-1372390265577/jetty2/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@7793a105; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_2,generation=2}
[junit4:junit4]   2> commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-1372390265577/jetty2/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@7793a105; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_3,generation=3}
[junit4:junit4]   2> 1865862 T4398 C733 P53361 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
[junit4:junit4]   2> 1865872 T4398 C733 P53361 oass.SolrIndexSearcher.<init> Opening Searcher@15108e60 main
[junit4:junit4]   2> 1865873 T4398 C733 P53361 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 1865874 T4407 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@15108e60 main{StandardDirectoryReader(segments_3:5:nrt _0(4.4):C2 _1(4.4):C2)}
[junit4:junit4]   2> 1865875 T4398 C733 P53361 oasup.LogUpdateProcessor.finish [collection1] webapp=/dpt/o path=/update params={waitSearcher=true&commit=true&wt=javabin&expungeDeletes=false&commit_end_point=true&version=2&softCommit=false} {commit=} 0 78
[junit4:junit4]   2> 1865876 T4382 C732 P53358 oasup.LogUpdateProcessor.finish [collection1] webapp=/dpt/o path=/update params={waitSearcher=true&commit=true&wt=javabin&version=2&softCommit=false} {commit=} 0 85
[junit4:junit4]   2> 1865878 T4347 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4]   2> 1865883 T4379 C732 P53358 oasc.SolrCore.execute [collection1] webapp=/dpt/o path=/select params={tests=checkShardConsistency&q=*:*&distrib=false&wt=javabin&version=2&rows=0} hits=4 status=0 QTime=0
[junit4:junit4]   2> 1865887 T4399 C733 P53361 oasc.SolrCore.execute [collection1] webapp=/dpt/o path=/select params={tests=checkShardConsistency&q=*:*&distrib=false&wt=javabin&version=2&rows=0} hits=4 status=0 QTime=0
[junit4:junit4]   2> 1865894 T4418 C735 P53365 oasc.SolrCore.execute [collection1] webapp=/dpt/o path=/select params={tests=checkShardConsistency&q=*:*&distrib=false&wt=javabin&version=2&rows=0} hits=4 status=0 QTime=1
[junit4:junit4]   2> 1865898 T4431 C734 P53372 oasc.SolrCore.execute [collection1] webapp=/dpt/o path=/select params={tests=checkShardConsistency&q=*:*&distrib=false&wt=javabin&version=2&rows=0} hits=4 status=0 QTime=0
[junit4:junit4]   2> 1867903 T4347 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4]   2> check const of shard1
[junit4:junit4]   2> client0
[junit4:junit4]   2> PROPS:2:{"shard":"shard1","state":"active","core":"collection1","collection":"collection1","node_name":"127.0.0.1:53358_dpt%2Fo","base_url":"http://127.0.0.1:53358/dpt/o","leader":"true"}
[junit4:junit4]   2> 1867911 T4379 C732 P53358 oasc.SolrCore.execute [collection1] webapp=/dpt/o path=/select params={tests=checkShardConsistency&q=*:*&distrib=false&wt=javabin&version=2&rows=0} hits=4 status=0 QTime=1
[junit4:junit4]   2>  live:true
[junit4:junit4]   2>  num:4
[junit4:junit4]   2>
[junit4:junit4]   2> client1
[junit4:junit4]   2> PROPS:3:{"shard":"shard1","state":"active","core":"collection1","collection":"collection1","node_name":"127.0.0.1:53361_dpt%2Fo","base_url":"http://127.0.0.1:53361/dpt/o"}
[junit4:junit4]   2> 1867915 T4399 C733 P53361 oasc.SolrCore.execute [collection1] webapp=/dpt/o path=/select params={tests=checkShardConsistency&q=*:*&distrib=false&wt=javabin&version=2&rows=0} hits=4 status=0 QTime=0
[junit4:junit4]   2>  live:true
[junit4:junit4]   2>  num:4
[junit4:junit4]   2>
[junit4:junit4]   2> client2
[junit4:junit4]   2> PROPS:4:{"shard":"shard1","state":"active","core":"collection1","collection":"collection1","node_name":"127.0.0.1:53365_dpt%2Fo","base_url":"http://127.0.0.1:53365/dpt/o"}
[junit4:junit4]   2> 1867920 T4418 C735 P53365 oasc.SolrCore.execute [collection1] webapp=/dpt/o path=/select params={tests=checkShardConsistency&q=*:*&distrib=false&wt=javabin&version=2&rows=0} hits=4 status=0 QTime=1
[junit4:junit4]   2>  live:true
[junit4:junit4]   2>  num:4
[junit4:junit4]   2>
[junit4:junit4]   2> client3
[junit4:junit4]   2> PROPS:5:{"shard":"shard1","state":"active","core":"collection1","collection":"collection1","node_name":"127.0.0.1:53372_dpt%2Fo","base_url":"http://127.0.0.1:53372/dpt/o"}
[junit4:junit4]   2> 1867924 T4431 C734 P53372 oasc.SolrCore.execute [collection1] webapp=/dpt/o path=/select params={tests=checkShardConsistency&q=*:*&distrib=false&wt=javabin&version=2&rows=0} hits=4 status=0 QTime=0
[junit4:junit4]   2>  live:true
[junit4:junit4]   2>  num:4
[junit4:junit4]   2>
[junit4:junit4]   2> 1867928 T4384 C732 P53358 oasc.SolrCore.execute [collection1] webapp=/dpt/o path=/select params={q=*:*&wt=javabin&version=2} hits=4 status=0 QTime=0
[junit4:junit4]   2> 1867938 T4361 C736 P53354 oasup.LogUpdateProcessor.finish [collection1] webapp=/dpt/o path=/update params={wt=javabin&version=2} {add=[4 (1439055529579118592)]} 0 5
[junit4:junit4]   2> 1867946 T4383 C732 P53358 oasup.DistributedUpdateProcessor.setupRequest test.distrib.skip.servers was found and contains:[http://127.0.0.1:53361/dpt/o/collection1/]
[junit4:junit4]   2> 1867947 T4383 C732 P53358 oasup.DistributedUpdateProcessor.setupRequest check url:http://127.0.0.1:53361/dpt/o/collection1/ against:[http://127.0.0.1:53361/dpt/o/collection1/] result:true
[junit4:junit4]   2> 1867948 T4383 C732 P53358 oasup.DistributedUpdateProcessor.setupRequest check url:http://127.0.0.1:53365/dpt/o/collection1/ against:[http://127.0.0.1:53361/dpt/o/collection1/] result:false
[junit4:junit4]   2> 1867948 T4383 C732 P53358 oasup.DistributedUpdateProcessor.setupRequest check url:http://127.0.0.1:53372/dpt/o/collection1/ against:[http://127.0.0.1:53361/dpt/o/collection1/] result:false
[junit4:junit4]   2> 1867959 T4414 C735 P53365 oasup.LogUpdateProcessor.finish [collection1] webapp=/dpt/o path=/update params={distrib.from=http://127.0.0.1:53358/dpt/o/collection1/&update.distrib=FROMLEADER&test.distrib.skip.servers=http://127.0.0.1:53361/dpt/o/collection1/&wt=javabin&version=2} {add=[4 (1439055529594847232)]} 0 3
[junit4:junit4]   2> 1867973 T4433 C734 P53372 oasup.LogUpdateProcessor.finish [collection1] webapp=/dpt/o path=/update params={distrib.from=http://127.0.0.1:53358/dpt/o/collection1/&update.distrib=FROMLEADER&test.distrib.skip.servers=http://127.0.0.1:53361/dpt/o/collection1/&wt=javabin&version=2} {add=[4 (1439055529594847232)]} 0 13
[junit4:junit4]   2> 1867974 T4383 C732 P53358 oasup.LogUpdateProcessor.finish [collection1] webapp=/dpt/o path=/update params={distrib.from=http://127.0.0.1:53372/dpt/o/collection1/&update.distrib=TOLEADER&test.distrib.skip.servers=http://127.0.0.1:53361/dpt/o/collection1/&wt=javabin&version=2} {add=[4 (1439055529594847232)]} 0 28
[junit4:junit4]   2> 1867975 T4436 C734 P53372 oasup.LogUpdateProcessor.finish [collection1] webapp=/dpt/o path=/update params={test.distrib.skip.servers=http://127.0.0.1:53361/dpt/o/collection1/&wt=javabin&version=2} {add=[4]} 0 32
[junit4:junit4]   2> 1867976 T4347 oasc.ChaosMonkey.monkeyLog monkey: kill shard! 53358
[junit4:junit4]   2> 1867991 T4347 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=604412439
[junit4:junit4]   2> 1868347 T4370 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4]   2> 1868349 T4370 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4:junit4]   2>  "operation":"state",
[junit4:junit4]   2>  "core_node_name":"2",
[junit4:junit4]   2>  "shard":"shard1",
[junit4:junit4]   2>  "roles":null,
[junit4:junit4]   2>  "state":"down",
[junit4:junit4]   2>  "core":"collection1",
[junit4:junit4]   2>  "collection":"collection1",
[junit4:junit4]   2>  "node_name":"127.0.0.1:53358_dpt%2Fo",
[junit4:junit4]   2>  "base_url":"http://127.0.0.1:53358/dpt/o"}
[junit4:junit4]   2> 1868361 T4440 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 1868361 T4405 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 1868362 T4389 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 1868362 T4369 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 1868363 T4376 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 1868364 T4422 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 1869997 T4347 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4]   2> 1869998 T4347 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 1870002 T4347 oasc.SolrCore.close [collection1]  CLOSING SolrCore org.apache.solr.core.SolrCore@2ff2f56
[junit4:junit4]   2> 1870027 T4347 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=6,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=1,adds=1,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=5,cumulative_deletesById=0,cumulative_deletesByQuery=1,cumulative_errors=0}
[junit4:junit4]   2> 1870028 T4347 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4:junit4]   2> 1870028 T4347 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4]   2> 1870029 T4347 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4]   2>  C732_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=down, core=collection1, collection=collection1, node_name=127.0.0.1:53358_dpt%2Fo, base_url=http://127.0.0.1:53358/dpt/o, leader=true}
[junit4:junit4]   2> 1870095 T4347 C732 P53358 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=3
[junit4:junit4]   2> commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-1372390265577/jetty1/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@772552de; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1}
[junit4:junit4]   2> commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-1372390265577/jetty1/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@772552de; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_2,generation=2}
[junit4:junit4]   2> commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-1372390265577/jetty1/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@772552de; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_3,generation=3}
[junit4:junit4]   2> 1870096 T4347 C732 P53358 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
[junit4:junit4]   2> 1870100 T4347 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4]   2> 1870101 T4347 oasc.CachingDirectoryFactory.close Closing NRTCachingDirectoryFactory - 2 directories currently being tracked
[junit4:junit4]   2> 1870102 T4347 oasc.CachingDirectoryFactory.closeCacheValue looking to close /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-1372390265577/jetty1/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.SyncSliceTest-1372390265577/jetty1/index;done=false>>]
[junit4:junit4]   2> 1870102 T4347 oasc.CachingDirectoryFactory.close Closing directory: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-1372390265577/jetty1/index
[junit4:junit4]   2> 1870103 T4347 oasc.CachingDirectoryFactory.closeCacheValue looking to close /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-1372390265577/jetty1 [CachedDir<<refCount=0;path=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-1372390265577/jetty1;done=false>>]
[junit4:junit4]   2> 1870104 T4347 oasc.CachingDirectoryFactory.close Closing directory: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-1372390265577/jetty1
[junit4:junit4]   2> 1870109 T4369 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 1870111 T4389 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4]   2> 1870116 T4389 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 1870117 T4389 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4]   2> 1870116 T4369 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 1870112 T4376 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 1870118 T4422 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 1870122 T4422 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 1870124 T4347 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/dpt/o,null}
[junit4:junit4]   2> 1870132 T4376 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 1870133 T4405 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4]   2> 1870138 T4440 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 1870138 T4440 oascc.Zk

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

collection1/leader_elect/shard1/election/89940968445575180-5-n_0000000003 (0)
[junit4:junit4]   1>        /solr/collections/collection1/leader_elect/shard1/election/89940968445575182-2-n_0000000004 (0)
[junit4:junit4]   1>     /solr/collections/collection1/leaders (1)
[junit4:junit4]   1>      /solr/collections/collection1/leaders/shard1 (0)
[junit4:junit4]   1>      DATA:
[junit4:junit4]   1>          {
[junit4:junit4]   1>            "core":"collection1",
[junit4:junit4]   1>            "node_name":"127.0.0.1:53372_dpt%2Fo",
[junit4:junit4]   1>            "base_url":"http://127.0.0.1:53372/dpt/o"}
[junit4:junit4]   1>    /solr/collections/control_collection (3)
[junit4:junit4]   1>    DATA:
[junit4:junit4]   1>        {"configName":"conf1"}
[junit4:junit4]   1>     /solr/collections/control_collection/shards (0)
[junit4:junit4]   1>     /solr/collections/control_collection/leader_elect (1)
[junit4:junit4]   1>      /solr/collections/control_collection/leader_elect/shard1 (1)
[junit4:junit4]   1>       /solr/collections/control_collection/leader_elect/shard1/election (1)
[junit4:junit4]   1>        /solr/collections/control_collection/leader_elect/shard1/election/89940968445575171-1-n_0000000000 (0)
[junit4:junit4]   1>     /solr/collections/control_collection/leaders (1)
[junit4:junit4]   1>      /solr/collections/control_collection/leaders/shard1 (0)
[junit4:junit4]   1>      DATA:
[junit4:junit4]   1>          {
[junit4:junit4]   1>            "core":"collection1",
[junit4:junit4]   1>            "node_name":"127.0.0.1:53354_dpt%2Fo",
[junit4:junit4]   1>            "base_url":"http://127.0.0.1:53354/dpt/o"}
[junit4:junit4]   1>   /solr/overseer_elect (2)
[junit4:junit4]   1>    /solr/overseer_elect/election (4)
[junit4:junit4]   1>     /solr/overseer_elect/election/89940968445575182-127.0.0.1:53358_dpt%2Fo-n_0000000005 (0)
[junit4:junit4]   1>     /solr/overseer_elect/election/89940968445575180-127.0.0.1:53372_dpt%2Fo-n_0000000004 (0)
[junit4:junit4]   1>     /solr/overseer_elect/election/89940968445575178-127.0.0.1:53365_dpt%2Fo-n_0000000003 (0)
[junit4:junit4]   1>     /solr/overseer_elect/election/89940968445575171-127.0.0.1:53354_dpt%2Fo-n_0000000000 (0)
[junit4:junit4]   1>    /solr/overseer_elect/leader (0)
[junit4:junit4]   1>    DATA:
[junit4:junit4]   1>        {"id":"89940968445575171-127.0.0.1:53354_dpt%2Fo-n_0000000000"}
[junit4:junit4]   1>  /zookeeper (1)
[junit4:junit4]   1>  DATA:
[junit4:junit4]   1>      
[junit4:junit4]   1>
[junit4:junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=SyncSliceTest -Dtests.method=testDistribSearch -Dtests.seed=994F4C1E7409D04F -Dtests.slow=true -Dtests.locale=ca_ES -Dtests.timezone=America/Knox_IN -Dtests.file.encoding=ISO-8859-1
[junit4:junit4] FAILURE  116s | SyncSliceTest.testDistribSearch <<<
[junit4:junit4]    > Throwable #1: java.lang.AssertionError: shard1 is not consistent.  Got 305 from http://127.0.0.1:53358/dpt/o/collection1lastClient and got 257 from http://127.0.0.1:53365/dpt/o/collection1
[junit4:junit4]    > at __randomizedtesting.SeedInfo.seed([994F4C1E7409D04F:18A9C2060356B073]:0)
[junit4:junit4]    > at org.apache.solr.cloud.AbstractFullDistribZkTestBase.checkShardConsistency(AbstractFullDistribZkTestBase.java:1018)
[junit4:junit4]    > at org.apache.solr.cloud.SyncSliceTest.doTest(SyncSliceTest.java:238)
[junit4:junit4]    > at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:835)
[junit4:junit4]    > at java.lang.Thread.run(Thread.java:680)
[junit4:junit4]   2> 1951304 T4347 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4:junit4]   2> 116252 T4346 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 2 leaked thread(s).
[junit4:junit4]   2> 1952081 T4440 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4]   2> 1952082 T4440 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 1)
[junit4:junit4]   2> 1952082 T4440 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4]   2> NOTE: test params are: codec=Lucene42: {range_facet_l=Pulsing41(freqCutoff=19 minBlockSize=80 maxBlockSize=172), text=MockFixedIntBlock(blockSize=1683), _version_=Pulsing41(freqCutoff=19 minBlockSize=80 maxBlockSize=172), rnd_b=PostingsFormat(name=Memory doPackFST= false), intDefault=Pulsing41(freqCutoff=19 minBlockSize=80 maxBlockSize=172), id=PostingsFormat(name=Memory doPackFST= false), timestamp=Pulsing41(freqCutoff=19 minBlockSize=80 maxBlockSize=172), a_t=Pulsing41(freqCutoff=19 minBlockSize=80 maxBlockSize=172), range_facet_sl=MockFixedIntBlock(blockSize=1683), range_facet_si=PostingsFormat(name=Asserting), other_tl1=Pulsing41(freqCutoff=19 minBlockSize=80 maxBlockSize=172), multiDefault=PostingsFormat(name=Asserting), a_si=PostingsFormat(name=Asserting)}, docValues:{}, sim=DefaultSimilarity, locale=ca_ES, timezone=America/Knox_IN
[junit4:junit4]   2> NOTE: Mac OS X 10.8.4 x86_64/Apple Inc. 1.6.0_51 (64-bit)/cpus=2,threads=1,free=167073672,total=290652160
[junit4:junit4]   2> NOTE: All tests run in this JVM: [QueryEqualityTest, FileBasedSpellCheckerTest, TestStressReorder, DocValuesTest, TestPerFieldSimilarity, TestSolrQueryParserDefaultOperatorResource, DOMUtilTest, DateMathParserTest, TestXIncludeConfig, BasicDistributedZkTest, TestPostingsSolrHighlighter, FastVectorHighlighterTest, TestManagedSchemaFieldResource, TestTrie, TestLMDirichletSimilarityFactory, QueryResultKeyTest, TestCollationKeyRangeQueries, PreAnalyzedFieldTest, ShardSplitTest, TestIBSimilarityFactory, TestGroupingSearch, TestZkChroot, DistributedQueryElevationComponentTest, PluginInfoTest, TestExtendedDismaxParser, TestReplicationHandler, TestReload, SliceStateUpdateTest, TestPhraseSuggestions, RecoveryZkTest, PeerSyncTest, TestCoreDiscovery, TestRTGBase, TestArbitraryIndexDir, MBeansHandlerTest, BadIndexSchemaTest, TestCSVLoader, TestLRUCache, SoftAutoCommitTest, ShardRoutingCustomTest, DistributedSpellCheckComponentTest, TestUpdate, TestFuzzyAnalyzedSuggestions, TestSolrQueryParserResource, TestWriterPerf, SampleTest, TestAtomicUpdateErrorCases, TestValueSourceCache, DisMaxRequestHandlerTest, SolrCmdDistributorTest, OpenExchangeRatesOrgProviderTest, TestJoin, DocumentBuilderTest, WordBreakSolrSpellCheckerTest, TestSort, RequiredFieldsTest, TermVectorComponentDistributedTest, URLClassifyProcessorTest, TestReloadAndDeleteDocs, AlternateDirectoryTest, TestCollationField, NotRequiredUniqueKeyTest, UniqFieldsUpdateProcessorFactoryTest, PrimUtilsTest, DistanceFunctionTest, XmlUpdateRequestHandlerTest, BasicDistributedZk2Test, CurrencyFieldOpenExchangeTest, TestSerializedLuceneMatchVersion, StatsComponentTest, TestIndexingPerformance, TestJmxMonitoredMap, LukeRequestHandlerTest, PreAnalyzedUpdateProcessorTest, TestSolrXMLSerializer, SuggesterWFSTTest, SpellCheckCollatorTest, PathHierarchyTokenizerFactoryTest, ZkNodePropsTest, TestSolrXml, ShowFileRequestHandlerTest, TestWordDelimiterFilterFactory, TestRandomFaceting, CacheHeaderTest, SpellingQueryConverterTest, MultiTermTest, TestLazyCores, DirectSolrConnectionTest, TestFunctionQuery, TestSolrDeletionPolicy2, TestFastLRUCache, TestRecovery, CSVRequestHandlerTest, SolrIndexSplitterTest, SolrPluginUtilsTest, StandardRequestHandlerTest, TestSchemaVersionResource, TestSolrIndexConfig, TestCharFilters, BinaryUpdateRequestHandlerTest, ExternalFileFieldSortTest, BasicZkTest, ZkSolrClientTest, ResourceLoaderTest, TestSolrCoreProperties, JsonLoaderTest, CurrencyFieldXmlFileTest, TestSolrJ, TestFoldingMultitermQuery, JSONWriterTest, AliasIntegrationTest, TestPHPSerializedResponseWriter, OverseerCollectionProcessorTest, TestAddFieldRealTimeGet, CollectionsAPIDistributedZkTest, TestBadConfig, UUIDFieldTest, TestUniqueKeyFieldResource, SimplePostToolTest, ZkCLITest, TestFieldTypeResource, IndexSchemaRuntimeFieldTest, TestReversedWildcardFilterFactory, FieldMutatingUpdateProcessorTest, TestSchemaSimilarityResource, DocValuesMultiTest, LeaderElectionTest, DebugComponentTest, CopyFieldTest, TestCloudManagedSchema, SortByFunctionTest, ClusterStateUpdateTest, TestCSVResponseWriter, TestBinaryField, TestRandomDVFaceting, TestPseudoReturnFields, TestFiltering, AnalysisAfterCoreReloadTest, TermVectorComponentTest, TestSchemaNameResource, TestMultiCoreConfBootstrap, CachingDirectoryFactoryTest, MoreLikeThisHandlerTest, ChaosMonkeySafeLeaderTest, UnloadDistributedZkTest, SyncSliceTest]
[junit4:junit4] Completed in 117.30s, 1 test, 1 failure <<< FAILURES!

[...truncated 461 lines...]
BUILD FAILED
/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/build.xml:392: The following error occurred while executing this line:
/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/build.xml:372: 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:437: The following error occurred while executing this line:
/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/lucene/common-build.xml:1248: The following error occurred while executing this line:
/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/lucene/common-build.xml:892: There were test failures: 299 suites, 1290 tests, 1 failure, 18 ignored (6 assumptions)

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




---------------------------------------------------------------------
To unsubscribe, e-mail: [hidden email]
For additional commands, e-mail: [hidden email]