lucene-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Policeman Jenkins Server <jenk...@thetaphi.de>
Subject [JENKINS] Lucene-Solr-4.x-MacOSX (64bit/jdk1.7.0) - Build # 1274 - Still Failing!
Date Fri, 07 Feb 2014 14:11:39 GMT
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-MacOSX/1274/
Java: 64bit/jdk1.7.0 -XX:+UseCompressedOops -XX:+UseSerialGC

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

Error Message:
There are still nodes recoverying - waited for 330 seconds

Stack Trace:
java.lang.AssertionError: There are still nodes recoverying - waited for 330 seconds
	at __randomizedtesting.SeedInfo.seed([D1C4C27AC9ABD11E:50224C62BEF4B122]:0)
	at org.junit.Assert.fail(Assert.java:93)
	at org.apache.solr.cloud.AbstractDistribZkTestBase.waitForRecoveriesToFinish(AbstractDistribZkTestBase.java:172)
	at org.apache.solr.cloud.AbstractDistribZkTestBase.waitForRecoveriesToFinish(AbstractDistribZkTestBase.java:131)
	at org.apache.solr.cloud.AbstractDistribZkTestBase.waitForRecoveriesToFinish(AbstractDistribZkTestBase.java:126)
	at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testCollectionsAPI(CollectionsAPIDistributedZkTest.java:717)
	at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.doTest(CollectionsAPIDistributedZkTest.java:202)
	at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:867)
	at sun.reflect.GeneratedMethodAccessor44.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:606)
	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:744)




Build Log:
[...truncated 10434 lines...]
   [junit4] Suite: org.apache.solr.cloud.CollectionsAPIDistributedZkTest
   [junit4]   2> 1663813 T6168 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /vxp/ul
   [junit4]   2> 1663818 T6168 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
   [junit4]   2> Creating dataDir: /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./solrtest-CollectionsAPIDistributedZkTest-1391780524858
   [junit4]   2> 1663820 T6168 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   2> 1663821 T6169 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 1663921 T6168 oasc.ZkTestServer.run start zk server on port:61341
   [junit4]   2> 1663923 T6168 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1663930 T6175 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5f9f7327 name:ZooKeeperConnection Watcher:127.0.0.1:61341 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1663931 T6168 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1663931 T6168 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 1663941 T6168 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1663947 T6177 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4bec4a65 name:ZooKeeperConnection Watcher:127.0.0.1:61341/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1663948 T6168 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1663949 T6168 oascc.SolrZkClient.makePath makePath: /collections/collection1
   [junit4]   2> 1663958 T6168 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
   [junit4]   2> 1663965 T6168 oascc.SolrZkClient.makePath makePath: /collections/control_collection
   [junit4]   2> 1663971 T6168 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
   [junit4]   2> 1663981 T6168 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
   [junit4]   2> 1663982 T6168 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
   [junit4]   2> 1663995 T6168 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
   [junit4]   2> 1663996 T6168 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
   [junit4]   2> 1664005 T6168 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 1664006 T6168 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 1664015 T6168 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
   [junit4]   2> 1664016 T6168 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
   [junit4]   2> 1664025 T6168 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
   [junit4]   2> 1664025 T6168 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
   [junit4]   2> 1664033 T6168 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
   [junit4]   2> 1664034 T6168 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
   [junit4]   2> 1664043 T6168 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml
   [junit4]   2> 1664044 T6168 oascc.SolrZkClient.makePath makePath: /configs/conf1/enumsConfig.xml
   [junit4]   2> 1664052 T6168 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/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]   2> 1664053 T6168 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
   [junit4]   2> 1664062 T6168 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/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]   2> 1664063 T6168 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 1664072 T6168 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/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]   2> 1664073 T6168 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
   [junit4]   2> 1664083 T6168 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
   [junit4]   2> 1664084 T6168 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
   [junit4]   2> Using new style solr.xml
   [junit4]   2> 1664450 T6168 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 1664458 T6168 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:61344
   [junit4]   2> 1664460 T6168 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 1664460 T6168 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 1664460 T6168 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1391780525135
   [junit4]   2> 1664461 T6168 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1391780525135/'
   [junit4]   2> 1664492 T6168 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1391780525135/solr.xml
   [junit4]   2> 1664580 T6168 oasc.ConfigSolrXml.<init> Config-defined core root directory: 
   [junit4]   2> 1664581 T6168 oasc.CoreContainer.<init> New CoreContainer 1943731489
   [junit4]   2> 1664581 T6168 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1391780525135/]
   [junit4]   2> 1664582 T6168 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 1664583 T6168 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 1664583 T6168 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 1664583 T6168 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 1664584 T6168 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 1664584 T6168 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 1664584 T6168 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 1664585 T6168 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 1664586 T6168 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 1664596 T6168 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 1664596 T6168 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 1664597 T6168 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 1664597 T6168 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:61341/solr
   [junit4]   2> 1664598 T6168 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 1664599 T6168 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1664604 T6188 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2e20bcf3 name:ZooKeeperConnection Watcher:127.0.0.1:61341 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1664605 T6168 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1664610 T6168 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1664614 T6190 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@31cf8d39 name:ZooKeeperConnection Watcher:127.0.0.1:61341/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1664615 T6168 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1664619 T6168 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 1664630 T6168 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 1664639 T6168 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 1664645 T6168 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:61344_vxp%2Ful
   [junit4]   2> 1664647 T6168 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:61344_vxp%2Ful
   [junit4]   2> 1664657 T6168 oascc.SolrZkClient.makePath makePath: /overseer_elect
   [junit4]   2> 1664662 T6168 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 1664677 T6168 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:61344_vxp%2Ful
   [junit4]   2> 1664678 T6168 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 1664686 T6168 oasc.Overseer.start Overseer (id=91211728477618179-127.0.0.1:61344_vxp%2Ful-n_0000000000) starting
   [junit4]   2> 1664695 T6168 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 1664706 T6192 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 1664707 T6168 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 1664707 T6192 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
   [junit4]   2> 1664713 T6168 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 1664719 T6168 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1664729 T6191 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 1664735 T6168 oasc.CorePropertiesLocator.discover Looking for core definitions underneath /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1391780525135
   [junit4]   2> 1664848 T6168 oasc.CorePropertiesLocator.discoverUnder Found core conf in /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1391780525135/conf/
   [junit4]   2> 1664855 T6168 oasc.CorePropertiesLocator.discover Found 1 core definitions
   [junit4]   2> 1664856 T6168 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0
   [junit4]   2> 1664856 T6168 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 1664858 T6168 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1664861 T6195 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3a2d934e name:ZooKeeperConnection Watcher:127.0.0.1:61341/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1664862 T6168 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1664865 T6168 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1664871 T6168 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:false
   [junit4]   2> 1665220 T6168 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 1
   [junit4]   2> 1665222 T6168 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 1665228 T6168 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:61348
   [junit4]   2> 1665230 T6168 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 1665230 T6168 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 1665231 T6168 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1391780525910
   [junit4]   2> 1665231 T6168 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1391780525910/'
   [junit4]   2> 1665271 T6168 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1391780525910/solr.xml
   [junit4]   2> 1665340 T6168 oasc.ConfigSolrXml.<init> Config-defined core root directory: 
   [junit4]   2> 1665341 T6168 oasc.CoreContainer.<init> New CoreContainer 777020426
   [junit4]   2> 1665342 T6168 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1391780525910/]
   [junit4]   2> 1665344 T6168 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 1665344 T6168 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 1665344 T6168 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 1665345 T6168 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 1665345 T6168 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 1665345 T6168 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 1665345 T6168 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 1665346 T6168 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 1665346 T6168 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 1665355 T6168 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 1665355 T6168 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 1665355 T6168 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 1665356 T6168 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:61341/solr
   [junit4]   2> 1665356 T6168 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 1665358 T6168 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1665362 T6206 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1fd7e447 name:ZooKeeperConnection Watcher:127.0.0.1:61341 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1665363 T6168 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1665368 T6168 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1665372 T6208 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@525c058c name:ZooKeeperConnection Watcher:127.0.0.1:61341/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1665372 T6168 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1665382 T6168 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1666393 T6168 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:61348_vxp%2Ful
   [junit4]   2> 1666396 T6168 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:61348_vxp%2Ful
   [junit4]   2> 1666404 T6190 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 1666405 T6195 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 1666405 T6208 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 1666422 T6168 oasc.CorePropertiesLocator.discover Looking for core definitions underneath /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1391780525910
   [junit4]   2> 1666571 T6168 oasc.CorePropertiesLocator.discoverUnder Found core conf in /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1391780525910/conf/
   [junit4]   2> 1666579 T6168 oasc.CorePropertiesLocator.discover Found 1 core definitions
   [junit4]   2> 1666580 T6168 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0
   [junit4]   2> 1666581 T6168 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 1666935 T6168 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 2
   [junit4]   2> 1666936 T6168 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 1666942 T6168 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:61351
   [junit4]   2> 1666944 T6168 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 1666944 T6168 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 1666945 T6168 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1391780527620
   [junit4]   2> 1666945 T6168 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1391780527620/'
   [junit4]   2> 1666977 T6168 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1391780527620/solr.xml
   [junit4]   2> 1667067 T6168 oasc.ConfigSolrXml.<init> Config-defined core root directory: 
   [junit4]   2> 1667069 T6168 oasc.CoreContainer.<init> New CoreContainer 1270089485
   [junit4]   2> 1667069 T6168 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1391780527620/]
   [junit4]   2> 1667071 T6168 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 1667071 T6168 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 1667072 T6168 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 1667072 T6168 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 1667072 T6168 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 1667072 T6168 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 1667073 T6168 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 1667073 T6168 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 1667073 T6168 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 1667083 T6168 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 1667084 T6168 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 1667085 T6168 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 1667085 T6168 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:61341/solr
   [junit4]   2> 1667086 T6168 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 1667088 T6168 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1667092 T6220 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@183b0d4f name:ZooKeeperConnection Watcher:127.0.0.1:61341 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1667093 T6168 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1667101 T6168 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1667105 T6222 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@202d03dd name:ZooKeeperConnection Watcher:127.0.0.1:61341/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1667106 T6168 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1667120 T6168 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1668134 T6168 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:61351_vxp%2Ful
   [junit4]   2> 1668138 T6168 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:61351_vxp%2Ful
   [junit4]   2> 1668154 T6195 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 1668155 T6222 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 1668156 T6208 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 1668156 T6190 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 1668169 T6168 oasc.CorePropertiesLocator.discover Looking for core definitions underneath /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1391780527620
   [junit4]   2> 1668274 T6168 oasc.CorePropertiesLocator.discoverUnder Found core conf in /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1391780527620/conf/
   [junit4]   2> 1668279 T6168 oasc.CorePropertiesLocator.discover Found 1 core definitions
   [junit4]   2> 1668280 T6168 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0
   [junit4]   2> 1668280 T6168 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 1668648 T6168 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 3
   [junit4]   2> 1668649 T6168 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 1668654 T6168 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:61354
   [junit4]   2> 1668655 T6168 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 1668656 T6168 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 1668656 T6168 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1391780529320
   [junit4]   2> 1668656 T6168 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1391780529320/'
   [junit4]   2> 1668684 T6168 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1391780529320/solr.xml
   [junit4]   2> 1668751 T6168 oasc.ConfigSolrXml.<init> Config-defined core root directory: 
   [junit4]   2> 1668751 T6168 oasc.CoreContainer.<init> New CoreContainer 1254751550
   [junit4]   2> 1668752 T6168 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1391780529320/]
   [junit4]   2> 1668753 T6168 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 1668753 T6168 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 1668754 T6168 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 1668754 T6168 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 1668754 T6168 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 1668754 T6168 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 1668755 T6168 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 1668755 T6168 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 1668755 T6168 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 1668764 T6168 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 1668765 T6168 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 1668765 T6168 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 1668765 T6168 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:61341/solr
   [junit4]   2> 1668766 T6168 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 1668767 T6168 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1668784 T6234 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@131117ce name:ZooKeeperConnection Watcher:127.0.0.1:61341 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1668785 T6168 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1668790 T6168 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1668794 T6236 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7a55c265 name:ZooKeeperConnection Watcher:127.0.0.1:61341/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1668794 T6168 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1668804 T6168 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1669814 T6168 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:61354_vxp%2Ful
   [junit4]   2> 1669819 T6168 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:61354_vxp%2Ful
   [junit4]   2> 1669831 T6208 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 1669833 T6190 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 1669833 T6222 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 1669833 T6195 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 1669833 T6236 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 1669851 T6168 oasc.CorePropertiesLocator.discover Looking for core definitions underneath /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1391780529320
   [junit4]   2> 1669957 T6168 oasc.CorePropertiesLocator.discoverUnder Found core conf in /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1391780529320/conf/
   [junit4]   2> 1669962 T6168 oasc.CorePropertiesLocator.discover Found 1 core definitions
   [junit4]   2> 1669964 T6168 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0
   [junit4]   2> 1669964 T6168 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 1670347 T6168 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 4
   [junit4]   2> 1670348 T6168 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 1670354 T6168 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:61357
   [junit4]   2> 1670355 T6168 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 1670356 T6168 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 1670357 T6168 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1391780531004
   [junit4]   2> 1670358 T6168 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1391780531004/'
   [junit4]   2> 1670403 T6168 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1391780531004/solr.xml
   [junit4]   2> 1670494 T6168 oasc.ConfigSolrXml.<init> Config-defined core root directory: 
   [junit4]   2> 1670496 T6168 oasc.CoreContainer.<init> New CoreContainer 1739742222
   [junit4]   2> 1670496 T6168 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1391780531004/]
   [junit4]   2> 1670498 T6168 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 1670499 T6168 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 1670500 T6168 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 1670500 T6168 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 1670501 T6168 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 1670501 T6168 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 1670502 T6168 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 1670502 T6168 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 1670502 T6168 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 1670517 T6168 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 1670517 T6168 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 1670517 T6168 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 1670518 T6168 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:61341/solr
   [junit4]   2> 1670518 T6168 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 1670520 T6168 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1670525 T6248 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6eb9d051 name:ZooKeeperConnection Watcher:127.0.0.1:61341 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1670526 T6168 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1670531 T6168 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1670537 T6250 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3e4f8268 name:ZooKeeperConnection Watcher:127.0.0.1:61341/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1670538 T6168 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1670550 T6168 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1671561 T6168 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:61357_vxp%2Ful
   [junit4]   2> 1671563 T6168 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:61357_vxp%2Ful
   [junit4]   2> 1671574 T6236 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 1671574 T6190 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 1671575 T6250 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 1671574 T6208 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 1671575 T6222 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 1671576 T6195 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 1671588 T6168 oasc.CorePropertiesLocator.discover Looking for core definitions underneath /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1391780531004
   [junit4]   2> 1671740 T6168 oasc.CorePropertiesLocator.discoverUnder Found core conf in /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1391780531004/conf/
   [junit4]   2> 1671748 T6168 oasc.CorePropertiesLocator.discover Found 1 core definitions
   [junit4]   2> 1671749 T6168 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0
   [junit4]   2> 1671750 T6168 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 1671847 T6203 oasha.CollectionsHandler.handleCreateAction Creating Collection : router.field=myOwnField&replicationFactor=2&action=CREATE&collection.configName=conf1&name=solrj_collection&version=2&router.name=compositeId&numShards=2&wt=javabin
   [junit4]   2> 1671849 T6190 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/collection-queue-work state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1671853 T6192 oasc.OverseerCollectionProcessor.run Overseer Collection Processor: Get the message id:/overseer/collection-queue-work/qn-0000000000 message:{
   [junit4]   2> 	  "operation":"createcollection",
   [junit4]   2> 	  "fromApi":"true",
   [junit4]   2> 	  "name":"solrj_collection",
   [junit4]   2> 	  "replicationFactor":"2",
   [junit4]   2> 	  "collection.configName":"conf1",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "router.field":"myOwnField",
   [junit4]   2> 	  "router.name":"compositeId"}
   [junit4]   2> 1671853 T6192 oasc.OverseerCollectionProcessor.processMessage WARN OverseerCollectionProcessor.processMessage : createcollection , {
   [junit4]   2> 	  "operation":"createcollection",
   [junit4]   2> 	  "fromApi":"true",
   [junit4]   2> 	  "name":"solrj_collection",
   [junit4]   2> 	  "replicationFactor":"2",
   [junit4]   2> 	  "collection.configName":"conf1",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "router.field":"myOwnField",
   [junit4]   2> 	  "router.name":"compositeId"}
   [junit4]   2> 1671854 T6192 oasc.OverseerCollectionProcessor.createConfNode creating collections conf node /collections/solrj_collection 
   [junit4]   2> 1671854 T6192 oascc.SolrZkClient.makePath makePath: /collections/solrj_collection
   [junit4]   2> 1671866 T6190 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1671871 T6191 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1671873 T6191 oasc.Overseer$ClusterStateUpdater.buildCollection building a new collection: solrj_collection
   [junit4]   2> 1671874 T6191 oasc.Overseer$ClusterStateUpdater.createCollection Create collection solrj_collection with shards [shard1, shard2]
   [junit4]   2> 1671881 T6190 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1671884 T6195 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
   [junit4]   2> 1671885 T6222 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
   [junit4]   2> 1671885 T6208 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
   [junit4]   2> 1671885 T6250 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
   [junit4]   2> 1671885 T6190 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
   [junit4]   2> 1671885 T6236 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
   [junit4]   2> 1671971 T6192 oasc.OverseerCollectionProcessor.createCollection going to create cores replicas shardNames [shard1, shard2] , repFactor : 2
   [junit4]   2> 1671971 T6192 oasc.OverseerCollectionProcessor.createCollection Creating shard solrj_collection_shard1_replica1 as part of slice shard1 of collection solrj_collection on 127.0.0.1:61344_vxp%2Ful
   [junit4]   2> 1671972 T6192 oasc.OverseerCollectionProcessor.createCollection Creating shard solrj_collection_shard1_replica2 as part of slice shard1 of collection solrj_collection on 127.0.0.1:61348_vxp%2Ful
   [junit4]   2> 1671972 T6192 oasc.OverseerCollectionProcessor.createCollection Creating shard solrj_collection_shard2_replica1 as part of slice shard2 of collection solrj_collection on 127.0.0.1:61357_vxp%2Ful
   [junit4]   2> 1671973 T6192 oasc.OverseerCollectionProcessor.createCollection Creating shard solrj_collection_shard2_replica2 as part of slice shard2 of collection solrj_collection on 127.0.0.1:61351_vxp%2Ful
   [junit4]   2> 1671989 T6213 oasc.ZkController.publish publishing core=solrj_collection_shard2_replica2 state=down
   [junit4]   2> 1671990 T6185 oasc.ZkController.publish publishing core=solrj_collection_shard1_replica1 state=down
   [junit4]   2> 1671992 T6204 oasc.ZkController.publish publishing core=solrj_collection_shard1_replica2 state=down
   [junit4]   2> 1671992 T6245 oasc.ZkController.publish publishing core=solrj_collection_shard2_replica1 state=down
   [junit4]   2> 1671996 T6190 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1671997 T6213 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 1671998 T6204 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 1671999 T6245 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 1671999 T6185 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 1672003 T6191 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1672005 T6191 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:61351/vxp/ul",
   [junit4]   2> 	  "core":"solrj_collection_shard2_replica2",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:61351_vxp%2Ful",
   [junit4]   2> 	  "shard":"shard2",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "shard_parent":null,
   [junit4]   2> 	  "collection":"solrj_collection",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 1672012 T6190 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1672016 T6191 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:61348/vxp/ul",
   [junit4]   2> 	  "core":"solrj_collection_shard1_replica2",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:61348_vxp%2Ful",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "shard_parent":null,
   [junit4]   2> 	  "collection":"solrj_collection",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 1672023 T6190 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1672031 T6191 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:61357/vxp/ul",
   [junit4]   2> 	  "core":"solrj_collection_shard2_replica1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:61357_vxp%2Ful",
   [junit4]   2> 	  "shard":"shard2",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "shard_parent":null,
   [junit4]   2> 	  "collection":"solrj_collection",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 1672039 T6190 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1672042 T6191 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:61344/vxp/ul",
   [junit4]   2> 	  "core":"solrj_collection_shard1_replica1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:61344_vxp%2Ful",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "shard_parent":null,
   [junit4]   2> 	  "collection":"solrj_collection",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 1672049 T6190 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1672156 T6208 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
   [junit4]   2> 1672156 T6250 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
   [junit4]   2> 1672157 T6222 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
   [junit4]   2> 1672157 T6190 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
   [junit4]   2> 1672156 T6236 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
   [junit4]   2> 1672156 T6195 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
   [junit4]   2> 1673000 T6213 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for solrj_collection_shard2_replica2
   [junit4]   2> 1673000 T6185 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for solrj_collection_shard1_replica1
   [junit4]   2> 1673000 T6204 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for solrj_collection_shard1_replica2
   [junit4]   2> 1673000 T6245 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for solrj_collection_shard2_replica1
   [junit4]   2> 1673006 T6204 oasc.CoreContainer.create Creating SolrCore 'solrj_collection_shard1_replica2' using instanceDir: ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1391780525910/solrj_collection_shard1_replica2
   [junit4]   2> 1673006 T6204 oasc.ZkController.createCollectionZkNode Check for collection zkNode:solrj_collection
   [junit4]   2> 1673007 T6245 oasc.CoreContainer.create Creating SolrCore 'solrj_collection_shard2_replica1' using instanceDir: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1391780531004/solrj_collection_shard2_replica1
   [junit4]   2> 1673008 T6245 oasc.ZkController.createCollectionZkNode Check for collection zkNode:solrj_collection
   [junit4]   2> 1673003 T6213 oasc.CoreContainer.create Creating SolrCore 'solrj_collection_shard2_replica2' using instanceDir: ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1391780527620/solrj_collection_shard2_replica2
   [junit4]   2> 1673009 T6213 oasc.ZkController.createCollectionZkNode Check for collection zkNode:solrj_collection
   [junit4]   2> 1673007 T6185 oasc.CoreContainer.create Creating SolrCore 'solrj_collection_shard1_replica1' using instanceDir: ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1391780525135/solrj_collection_shard1_replica1
   [junit4]   2> 1673011 T6185 oasc.ZkController.createCollectionZkNode Check for collection zkNode:solrj_collection
   [junit4]   2> 1673010 T6245 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 1673012 T6213 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 1673012 T6213 oascc.ZkStateReader.readConfigName Load collection config from:/collections/solrj_collection
   [junit4]   2> 1673013 T6185 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 1673014 T6185 oascc.ZkStateReader.readConfigName Load collection config from:/collections/solrj_collection
   [junit4]   2> 1673010 T6204 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 1673015 T6204 oascc.ZkStateReader.readConfigName Load collection config from:/collections/solrj_collection
   [junit4]   2> 1673012 T6245 oascc.ZkStateReader.readConfigName Load collection config from:/collections/solrj_collection
   [junit4]   2> 1673018 T6213 oascc.ZkStateReader.readConfigName path=/collections/solrj_collection configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 1673019 T6213 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1391780527620/solrj_collection_shard2_replica2/'
   [junit4]   2> 1673019 T6185 oascc.ZkStateReader.readConfigName path=/collections/solrj_collection configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 1673021 T6185 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1391780525135/solrj_collection_shard1_replica1/'
   [junit4]   2> 1673023 T6245 oascc.ZkStateReader.readConfigName path=/collections/solrj_collection configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 1673024 T6245 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1391780531004/solrj_collection_shard2_replica1/'
   [junit4]   2> 1673025 T6204 oascc.ZkStateReader.readConfigName path=/collections/solrj_collection configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 1673026 T6204 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1391780525910/solrj_collection_shard1_replica2/'
   [junit4]   2> 1673196 T6245 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_47
   [junit4]   2> 1673247 T6185 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_47
   [junit4]   2> 1673252 T6213 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_47
   [junit4]   2> 1673273 T6204 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_47
   [junit4]   2> 1673365 T6245 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 1673382 T6245 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 1673395 T6185 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 1673401 T6245 oass.IndexSchema.readSchema [solrj_collection_shard2_replica1] Schema name=test
   [junit4]   2> 1673412 T6185 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 1673428 T6204 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 1673435 T6185 oass.IndexSchema.readSchema [solrj_collection_shard1_replica1] Schema name=test
   [junit4]   2> 1673451 T6204 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 1673470 T6204 oass.IndexSchema.readSchema [solrj_collection_shard1_replica2] Schema name=test
   [junit4]   2> 1673500 T6213 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 1673506 T6213 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 1673542 T6213 oass.IndexSchema.readSchema [solrj_collection_shard2_replica2] Schema name=test
   [junit4]   2> 1675027 T6245 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 1675027 T6245 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 1675028 T6245 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 1675049 T6245 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 1675056 T6204 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 1675057 T6204 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 1675057 T6204 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 1675063 T6245 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 1675077 T6204 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 1675088 T6204 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 1675116 T6213 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 1675119 T6213 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 1675120 T6213 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 1675122 T6185 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 1675123 T6185 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 1675125 T6185 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 1675132 T6213 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 1675137 T6185 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 1675139 T6213 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 1675152 T6185 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 1675163 T6245 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1675174 T6245 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1675177 T6204 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1675186 T6204 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1675190 T6245 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1675194 T6245 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1675195 T6245 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1675195 T6245 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1675201 T6204 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1675202 T6245 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1675202 T6245 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1675202 T6245 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 1675203 T6245 oasc.SolrCore.<init> [solrj_collection_shard2_replica1] Opening new SolrCore at ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1391780531004/solrj_collection_shard2_replica1/, dataDir=../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1391780531004/solrj_collection_shard2_replica1/data/
   [junit4]   2> 1675203 T6245 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@128380df
   [junit4]   2> 1675204 T6245 oasc.CachingDirectoryFactory.get return new directory for ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1391780531004/solrj_collection_shard2_replica1/data
   [junit4]   2> 1675209 T6245 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1391780531004/solrj_collection_shard2_replica1/data/index/
   [junit4]   2> 1675211 T6245 oasc.SolrCore.initIndex WARN [solrj_collection_shard2_replica1] Solr index directory '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1391780531004/solrj_collection_shard2_replica1/data/index' doesn't exist. Creating new index...
   [junit4]   2> 1675206 T6204 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1675212 T6204 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1675212 T6204 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1675213 T6245 oasc.CachingDirectoryFactory.get return new directory for ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1391780531004/solrj_collection_shard2_replica1/data/index
   [junit4]   2> 1675214 T6245 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=39, maxMergeAtOnceExplicit=26, maxMergedSegmentMB=23.5849609375, floorSegmentMB=1.3037109375, forceMergeDeletesPctAllowed=3.504199246060984, segmentsPerTier=25.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.6200031015204741
   [junit4]   2> 1675218 T6204 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1675219 T6245 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@51e5504e lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@62f8fac8),segFN=segments_1,generation=1}
   [junit4]   2> 1675220 T6245 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1675219 T6204 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1675221 T6204 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 1675222 T6204 oasc.SolrCore.<init> [solrj_collection_shard1_replica2] Opening new SolrCore at ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1391780525910/solrj_collection_shard1_replica2/, dataDir=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1391780525910/solrj_collection_shard1_replica2/data/
   [junit4]   2> 1675223 T6204 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@128380df
   [junit4]   2> 1675226 T6245 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 1675227 T6204 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1391780525910/solrj_collection_shard1_replica2/data
   [junit4]   2> 1675227 T6204 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1391780525910/solrj_collection_shard1_replica2/data/index/
   [junit4]   2> 1675228 T6204 oasc.SolrCore.initIndex WARN [solrj_collection_shard1_replica2] Solr index directory './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1391780525910/solrj_collection_shard1_replica2/data/index' doesn't exist. Creating new index...
   [junit4]   2> 1675228 T6204 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1391780525910/solrj_collection_shard1_replica2/data/index
   [junit4]   2> 1675229 T6204 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=39, maxMergeAtOnceExplicit=26, maxMergedSegmentMB=23.5849609375, floorSegmentMB=1.3037109375, forceMergeDeletesPctAllowed=3.504199246060984, segmentsPerTier=25.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.6200031015204741
   [junit4]   2> 1675227 T6245 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 1675231 T6245 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 1675231 T6245 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1675232 T6245 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1675232 T6245 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 1675233 T6185 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1675234 T6245 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1675234 T6245 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1675234 T6245 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 1675235 T6245 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 1675236 T6245 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 1675236 T6245 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 1675236 T6245 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 1675237 T6245 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 1675237 T6245 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 1675238 T6245 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 1675239 T6213 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1675243 T6185 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1675248 T6245 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 1675249 T6204 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@37be80ae lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2570d9a3),segFN=segments_1,generation=1}
   [junit4]   2> 1675249 T6204 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1675250 T6213 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1675254 T6245 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 1675255 T6245 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 1675255 T6185 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1675256 T6245 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=1701445967, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
   [junit4]   2> 1675260 T6204 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 1675260 T6213 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1675260 T6204 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 1675262 T6185 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1675263 T6185 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1675263 T6185 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1675262 T6204 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 1675264 T6204 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1675265 T6204 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1675264 T6213 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1675266 T6213 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1675266 T6213 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1675263 T6245 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@51e5504e lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@62f8fac8),segFN=segments_1,generation=1}
   [junit4]   2> 1675267 T6245 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1675266 T6185 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1675268 T6185 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1675268 T6185 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 1675266 T6204 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 1675269 T6185 oasc.SolrCore.<init> [solrj_collection_shard1_replica1] Opening new SolrCore at ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1391780525135/solrj_collection_shard1_replica1/, dataDir=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1391780525135/solrj_collection_shard1_replica1/data/
   [junit4]   2> 1675268 T6213 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1675270 T6213 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1675268 T6245 oass.SolrIndexSearcher.<init> Opening Searcher@607ea007[solrj_collection_shard2_replica1] main
   [junit4]   2> 1675270 T6213 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 1675271 T6213 oasc.SolrCore.<init> [solrj_collection_shard2_replica2] Opening new SolrCore at ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1391780527620/solrj_collection_shard2_replica2/, dataDir=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1391780527620/solrj_collection_shard2_replica2/data/
   [junit4]   2> 1675272 T6213 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@128380df
   [junit4]   2> 1675270 T6185 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@128380df
   [junit4]   2> 1675269 T6204 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1675274 T6204 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1675274 T6204 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 1675275 T6204 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 1675274 T6213 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1391780527620/solrj_collection_shard2_replica2/data
   [junit4]   2> 1675274 T6185 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1391780525135/solrj_collection_shard1_replica1/data
   [junit4]   2> 1675278 T6213 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1391780527620/solrj_collection_shard2_replica2/data/index/
   [junit4]   2> 1675278 T6213 oasc.SolrCore.initIndex WARN [solrj_collection_shard2_replica2] Solr index directory './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1391780527620/solrj_collection_shard2_replica2/data/index' doesn't exist. Creating new index...
   [junit4]   2> 1675279 T6185 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1391780525135/solrj_collection_shard1_replica1/data/index/
   [junit4]   2> 1675281 T6185 oasc.SolrCore.initIndex WARN [solrj_collection_shard1_replica1] Solr index directory './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1391780525135/solrj_collection_shard1_replica1/data/index' doesn't exist. Creating new index...
   [junit4]   2> 1675280 T6213 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1391780527620/solrj_collection_shard2_replica2/data/index
   [junit4]   2> 1675279 T6256 oasc.SolrCore.registerSearcher [solrj_collection_shard2_replica1] Registered new searcher Searcher@607ea007[solrj_collection_shard2_replica1] main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 1675282 T6185 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1391780525135/solrj_collection_shard1_replica1/data/index
   [junit4]   2> 1675279 T6204 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 1675283 T6204 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 1675282 T6185 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=39, maxMergeAtOnceExplicit=26, maxMergedSegmentMB=23.5849609375, floorSegmentMB=1.3037109375, forceMergeDeletesPctAllowed=3.504199246060984, segmentsPerTier=25.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.6200031015204741
   [junit4]   2> 1675282 T6245 oasc.CoreContainer.registerCore registering core: solrj_collection_shard2_replica1
   [junit4]   2> 1675282 T6213 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=39, maxMergeAtOnceExplicit=26, maxMergedSegmentMB=23.5849609375, floorSegmentMB=1.3037109375, forceMergeDeletesPctAllowed=3.504199246060984, segmentsPerTier=25.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.6200031015204741
   [junit4]   2> 1675284 T6185 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@1659a329 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@e97eb89),segFN=segments_1,generation=1}
   [junit4]   2> 1675285 T6213 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@16ac91cf lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@3afc94af),segFN=segments_1,generation=1}
   [junit4]   2> 1675285 T6213 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1675284 T6245 oasc.ZkController.register Register replica - core:solrj_collection_shard2_replica1 address:http://127.0.0.1:61357/vxp/ul collection:solrj_collection shard:shard2
   [junit4]   2> 1675287 T6245 oascc.SolrZkClient.makePath makePath: /collections/solrj_collection/leader_elect/shard2/election
   [junit4]   2> 1675289 T6213 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 1675289 T6213 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 1675290 T6213 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 1675290 T6213 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1675290 T6213 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1675291 T6213 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 1675291 T6213 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1675292 T6213 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1675292 T6213 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 1675293 T6213 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 1675294 T6213 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 1675283 T6204 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 1675294 T6213 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 1675295 T6204 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 1675285 T6185 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1675296 T6204 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 1675297 T6204 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 1675295 T6213 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 1675299 T6213 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 1675299 T6204 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 1675301 T6185 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 1675302 T6185 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 1675302 T6185 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 1675303 T6185 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1675303 T6185 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1675304 T6185 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 1675304 T6204 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 1675305 T6204 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 1675299 T6213 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 1675304 T6185 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1675309 T6213 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 1675308 T6204 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=1701445967, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
   [junit4]   2> 1675311 T6213 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 1675312 T6204 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@37be80ae lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2570d9a3),segFN=segments_1,generation=1}
   [junit4]   2> 1675312 T6204 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1675312 T6204 oass.SolrIndexSearcher.<init> Opening Searcher@38faf3b5[solrj_collection_shard1_replica2] main
   [junit4]   2> 1675311 T6185 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1675331 T6185 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 1675332 T6258 oasc.SolrCore.registerSearcher [solrj_collection_shard1_replica2] Registered new searcher Searcher@38faf3b5[solrj_collection_shard1_replica2] main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 1675332 T6185 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 1675333 T6185 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 1675333 T6185 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 1675333 T6213 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 1675333 T6213 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 1675334 T6213 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=1701445967, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
   [junit4]   2> 1675334 T6213 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@16ac91cf lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@3afc94af),segFN=segments_1,generation=1}
   [junit4]   2> 1675334 T6213 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1675311 T6245 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
   [junit4]   2> 1675335 T6213 oass.SolrIndexSearcher.<init> Opening Searcher@67276f0b[solrj_collection_shard2_replica2] main
   [junit4]   2> 1675335 T6204 oasc.CoreContainer.registerCore registering core: solrj_collection_shard1_replica2
   [junit4]   2> 1675345 T6204 oasc.ZkController.register Register replica - core:solrj_collection_shard1_replica2 address:http://127.0.0.1:61348/vxp/ul collection:solrj_collection shard:shard1
   [junit4]   2> 1675333 T6185 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 1675348 T6185 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 1675349 T6190 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1675351 T6190 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1675351 T6190 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1675351 T6204 oascc.SolrZkClient.makePath makePath: /collections/solrj_collection/leader_elect/shard1/election
   [junit4]   2> 1675355 T6245 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up for shard shard2: total=2 found=1 timeoutin=179998
   [junit4]   2> 1675353 T6185 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 1675355 T6259 oasc.SolrCore.registerSearcher [solrj_collection_shard2_replica2] Registered new searcher Searcher@67276f0b[solrj_collection_shard2_replica2] main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 1675357 T6185 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 1675359 T6213 oasc.CoreContainer.registerCore registering core: solrj_collection_shard2_replica2
   [junit4]   2> 1675359 T6213 oasc.ZkController.register Register replica - core:solrj_collection_shard2_replica2 address:http://127.0.0.1:61351/vxp/ul collection:solrj_collection shard:shard2
   [junit4]   2> 1675359 T6185 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 1675361 T6191 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1675372 T6190 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1675372 T6185 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 1675373 T6185 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 1675375 T6185 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=1701445967, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
   [junit4]   2> 1675375 T6195 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
   [junit4]   2> 1675376 T6208 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
   [junit4]   2> 1675376 T6236 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... 

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

eperException.create(KeeperException.java:51)
   [junit4]   2> 		at org.apache.zookeeper.ZooKeeper.exists(ZooKeeper.java:1041)
   [junit4]   2> 		at org.apache.solr.common.cloud.SolrZkClient$3.execute(SolrZkClient.java:206)
   [junit4]   2> 		at org.apache.solr.common.cloud.SolrZkClient$3.execute(SolrZkClient.java:203)
   [junit4]   2> 		at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
   [junit4]   2> 		at org.apache.solr.common.cloud.SolrZkClient.exists(SolrZkClient.java:203)
   [junit4]   2> 		at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:414)
   [junit4]   2> 		at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:383)
   [junit4]   2> 		at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:370)
   [junit4]   2> 		at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:112)
   [junit4]   2> 		at org.apache.solr.cloud.ShardLeaderElectionContext.runLeaderProcess(ElectionContext.java:273)
   [junit4]   2> 		at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:164)
   [junit4]   2> 		at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:108)
   [junit4]   2> 		at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
   [junit4]   2> 		at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:137)
   [junit4]   2> 		at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
   [junit4]   2> 		at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
   [junit4]   2> 	
   [junit4]   2> 2057975 T6208 oasc.LeaderElector$1.process WARN  org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/awholynewcollection_0/leader_elect/shard1/election/91211728477618182-core_node1-n_0000000002
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
   [junit4]   2> 	at org.apache.zookeeper.ZooKeeper.delete(ZooKeeper.java:873)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$2.execute(SolrZkClient.java:174)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$2.execute(SolrZkClient.java:171)
   [junit4]   2> 	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient.delete(SolrZkClient.java:171)
   [junit4]   2> 	at org.apache.solr.cloud.ElectionContext.cancelElection(ElectionContext.java:67)
   [junit4]   2> 	at org.apache.solr.cloud.ShardLeaderElectionContext.runLeaderProcess(ElectionContext.java:293)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:164)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:108)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:137)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
   [junit4]   2> 
   [junit4]   2> 2057976 T6208 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
   [junit4]   2> 2057976 T6208 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> 2057976 T6208 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2057976 T6208 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2057977 T6208 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2057977 T6208 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> NOTE: test params are: codec=Lucene46: {}, docValues:{}, sim=DefaultSimilarity, locale=de_DE, timezone=Europe/Vilnius
   [junit4]   2> NOTE: Mac OS X 10.8.5 x86_64/Oracle Corporation 1.7.0_51 (64-bit)/cpus=2,threads=1,free=89625688,total=215760896
   [junit4]   2> NOTE: All tests run in this JVM: [TestDistribDocBasedVersion, SpellPossibilityIteratorTest, TestDistributedSearch, TestOmitPositions, TestRemoteStreaming, OverseerRolesTest, HdfsDirectoryTest, PreAnalyzedUpdateProcessorTest, SolrInfoMBeanTest, TestStressVersions, TestQuerySenderNoQuery, TestIndexingPerformance, BadCopyFieldTest, TestSolrCoreProperties, HdfsBasicDistributedZk2Test, DistributedDebugComponentTest, SimplePostToolTest, UUIDFieldTest, BinaryUpdateRequestHandlerTest, ZkSolrClientTest, ZkNodePropsTest, TestStressRecovery, PluginInfoTest, UnloadDistributedZkTest, TestCollationField, TestSolrJ, CircularListTest, TestReplicationHandler, SpatialFilterTest, LukeRequestHandlerTest, TestMultiCoreConfBootstrap, TestWordDelimiterFilterFactory, TestAnalyzeInfixSuggestions, TestDistributedMissingSort, TestCopyFieldCollectionResource, TestCollationKeyRangeQueries, TestManagedSchema, TestPhraseSuggestions, SOLR749Test, MigrateRouteKeyTest, DistributedSpellCheckComponentTest, SliceStateTest, SortByFunctionTest, SpellCheckComponentTest, DocValuesMissingTest, QueryResultKeyTest, LeaderElectionTest, FileBasedSpellCheckerTest, ZkControllerTest, PrimitiveFieldTypeTest, TestDocBasedVersionConstraints, TestSurroundQueryParser, CustomCollectionTest, DistanceFunctionTest, SolrRequestParserTest, DocValuesTest, TestQuerySenderListener, TestZkChroot, AssignTest, SimpleFacetsTest, DistributedQueryComponentCustomSortTest, TestRTGBase, TestCollapseQParserPlugin, TestImplicitCoreProperties, TestCloudManagedSchema, DeleteShardTest, TestOverriddenPrefixQueryForCustomFieldType, SuggesterTest, TestSort, TestExtendedDismaxParser, DistributedQueryElevationComponentTest, TestSolrIndexConfig, SearchHandlerTest, ExternalFileFieldSortTest, SpellCheckCollatorTest, FieldMutatingUpdateProcessorTest, ShardRoutingCustomTest, CoreContainerCoreInitFailuresTest, HdfsBasicDistributedZkTest, DistributedSuggestComponentTest, TestBadConfig, SolrXmlInZkTest, TestSchemaSimilarityResource, LegacyHTMLStripCharFilterTest, DocumentBuilderTest, TestRangeQuery, SampleTest, HdfsUnloadDistributedZkTest, TestAtomicUpdateErrorCases, TestReloadAndDeleteDocs, TestLFUCache, StressHdfsTest, TestLuceneMatchVersion, PrimUtilsTest, SpellingQueryConverterTest, MoreLikeThisHandlerTest, RequiredFieldsTest, DebugComponentTest, StatsComponentTest, PolyFieldTest, QueryEqualityTest, TestBinaryResponseWriter, XmlUpdateRequestHandlerTest, TestSchemaNameResource, TestShardHandlerFactory, TestSolrXml, TestInitQParser, TestComponentsName, TestXIncludeConfig, TestNRTOpen, TestRecoveryHdfs, AnalysisAfterCoreReloadTest, TestDocSet, ParsingFieldUpdateProcessorsTest, HdfsChaosMonkeySafeLeaderTest, HdfsCollectionsAPIDistributedZkTest, DirectSolrSpellCheckerTest, TestCSVLoader, TestSolrXmlPersistor, TestCodecSupport, TermVectorComponentDistributedTest, StatelessScriptUpdateProcessorFactoryTest, CurrencyFieldXmlFileTest, TestCoreDiscovery, TestCoreContainer, TestReversedWildcardFilterFactory, TestTrie, SolrIndexConfigTest, TestDefaultSearchFieldResource, TestQueryUtils, SuggestComponentTest, TestCustomSort, LeaderElectionIntegrationTest, TestFiltering, TestRecovery, JsonLoaderTest, ZkCLITest, ScriptEngineTest, SoftAutoCommitTest, BJQParserTest, NoCacheHeaderTest, TestElisionMultitermQuery, OverseerCollectionProcessorTest, MBeansHandlerTest, TestSearchPerf, HdfsSyncSliceTest, SynonymTokenizerTest, CurrencyFieldOpenExchangeTest, TestSweetSpotSimilarityFactory, BasicDistributedZk2Test, PeerSyncTest, DOMUtilTest, RegexBoostProcessorTest, OpenExchangeRatesOrgProviderTest, CopyFieldTest, TestDistributedGrouping, DateMathParserTest, TestJmxIntegration, TestManagedSchemaFieldResource, TestJoin, ChangedSchemaMergeTest, TestSchemaResource, TestFaceting, StandardRequestHandlerTest, ChaosMonkeyNothingIsSafeTest, SuggesterTSTTest, OpenCloseCoreStressTest, TestRandomFaceting, TestBinaryField, TestSolrQueryParser, BasicDistributedZkTest, ChaosMonkeySafeLeaderTest, CollectionsAPIDistributedZkTest]
   [junit4] Completed in 394.23s, 1 test, 1 failure <<< FAILURES!

[...truncated 546 lines...]
BUILD FAILED
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/build.xml:459: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/build.xml:439: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/build.xml:39: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/extra-targets.xml:37: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build.xml:189: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/common-build.xml:491: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/lucene/common-build.xml:1308: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/lucene/common-build.xml:941: There were test failures: 358 suites, 1554 tests, 1 failure, 40 ignored (6 assumptions)

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



Mime
View raw message