You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2013/10/23 18:25:41 UTC

[JENKINS] Lucene-Solr-trunk-MacOSX (64bit/jdk1.7.0) - Build # 940 - Failure!

Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-MacOSX/940/
Java: 64bit/jdk1.7.0 -XX:-UseCompressedOops -XX:+UseConcMarkSweepGC

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

Error Message:
deletealias the collection time out:60s

Stack Trace:
org.apache.solr.client.solrj.impl.HttpSolrServer$RemoteSolrException: deletealias the collection time out:60s
	at __randomizedtesting.SeedInfo.seed([1DD745653F4BA171:9C31CB7D4814C14D]:0)
	at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:464)
	at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:181)
	at org.apache.solr.cloud.AliasIntegrationTest.deleteAlias(AliasIntegrationTest.java:254)
	at org.apache.solr.cloud.AliasIntegrationTest.doTest(AliasIntegrationTest.java:227)
	at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:835)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
	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 10241 lines...]
   [junit4] Suite: org.apache.solr.cloud.AliasIntegrationTest
   [junit4]   2> 1699170 T3921 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
   [junit4]   2> 1699180 T3921 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
   [junit4]   2> Creating dataDir: /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./solrtest-AliasIntegrationTest-1382543256247
   [junit4]   2> 1699184 T3921 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   2> 1699186 T3922 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 1699286 T3921 oasc.ZkTestServer.run start zk server on port:50053
   [junit4]   2> 1699288 T3921 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1699295 T3928 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1ed322da name:ZooKeeperConnection Watcher:127.0.0.1:50053 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1699295 T3921 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1699296 T3921 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 1699306 T3921 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1699310 T3930 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5de0736b name:ZooKeeperConnection Watcher:127.0.0.1:50053/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1699311 T3921 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1699311 T3921 oascc.SolrZkClient.makePath makePath: /collections/collection1
   [junit4]   2> 1699320 T3921 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
   [junit4]   2> 1699327 T3921 oascc.SolrZkClient.makePath makePath: /collections/control_collection
   [junit4]   2> 1699333 T3921 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
   [junit4]   2> 1699341 T3921 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
   [junit4]   2> 1699341 T3921 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
   [junit4]   2> 1699352 T3921 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
   [junit4]   2> 1699353 T3921 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
   [junit4]   2> 1699361 T3921 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 1699361 T3921 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 1699370 T3921 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
   [junit4]   2> 1699371 T3921 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
   [junit4]   2> 1699380 T3921 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
   [junit4]   2> 1699381 T3921 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
   [junit4]   2> 1699392 T3921 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
   [junit4]   2> 1699394 T3921 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
   [junit4]   2> 1699404 T3921 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
   [junit4]   2> 1699405 T3921 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
   [junit4]   2> 1699415 T3921 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 1699416 T3921 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 1699430 T3921 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
   [junit4]   2> 1699431 T3921 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
   [junit4]   2> 1699446 T3921 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
   [junit4]   2> 1699448 T3921 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
   [junit4]   2> 1699896 T3921 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 1699901 T3921 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:50056
   [junit4]   2> 1699904 T3921 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 1699904 T3921 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 1699905 T3921 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.AliasIntegrationTest-controljetty-1382543256527
   [junit4]   2> 1699905 T3921 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.AliasIntegrationTest-controljetty-1382543256527/'
   [junit4]   2> 1699950 T3921 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.AliasIntegrationTest-controljetty-1382543256527/solr.xml
   [junit4]   2> 1700063 T3921 oasc.CoreContainer.<init> New CoreContainer 375888890
   [junit4]   2> 1700064 T3921 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.AliasIntegrationTest-controljetty-1382543256527/]
   [junit4]   2> 1700066 T3921 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 1700066 T3921 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 1700067 T3921 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 1700067 T3921 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 1700067 T3921 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 1700068 T3921 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 1700068 T3921 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 1700069 T3921 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 1700069 T3921 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 1700075 T3921 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 1700075 T3921 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 1700076 T3921 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:50053/solr
   [junit4]   2> 1700077 T3921 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 1700078 T3921 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1700083 T3941 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6b430a47 name:ZooKeeperConnection Watcher:127.0.0.1:50053 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1700083 T3921 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1700089 T3921 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1700092 T3943 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4a10f869 name:ZooKeeperConnection Watcher:127.0.0.1:50053/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1700093 T3921 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1700096 T3921 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 1700104 T3921 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 1700113 T3921 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 1700117 T3921 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:50056_
   [junit4]   2> 1700120 T3921 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:50056_
   [junit4]   2> 1700128 T3921 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 1700140 T3921 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 1700146 T3921 oasc.Overseer.start Overseer (id=90606354842058755-127.0.0.1:50056_-n_0000000000) starting
   [junit4]   2> 1700154 T3921 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 1700164 T3945 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 1700165 T3921 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 1700171 T3921 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 1700176 T3921 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1700184 T3944 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 1700192 T3946 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 1700192 T3946 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1700195 T3946 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 1701694 T3944 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1701696 T3944 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:50056",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:50056_",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "shard_parent":null,
   [junit4]   2> 	  "collection":"control_collection",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "core_node_name":"core_node1"}
   [junit4]   2> 1701696 T3944 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1]
   [junit4]   2> 1701697 T3944 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 1701707 T3943 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
   [junit4]   2> 1702197 T3946 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 1702197 T3946 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.AliasIntegrationTest-controljetty-1382543256527/collection1
   [junit4]   2> 1702198 T3946 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
   [junit4]   2> 1702201 T3946 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 1702201 T3946 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
   [junit4]   2> 1702205 T3946 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.AliasIntegrationTest-controljetty-1382543256527/collection1/'
   [junit4]   2> 1702207 T3946 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.AliasIntegrationTest-controljetty-1382543256527/collection1/lib/classes/' to classloader
   [junit4]   2> 1702208 T3946 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.AliasIntegrationTest-controljetty-1382543256527/collection1/lib/README' to classloader
   [junit4]   2> 1702333 T3946 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 1702443 T3946 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 1702446 T3946 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 1702459 T3946 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 1703336 T3946 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 1703347 T3946 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 1703352 T3946 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 1703383 T3946 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1703391 T3946 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1703398 T3946 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1703401 T3946 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1703402 T3946 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1703402 T3946 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1703414 T3946 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1703415 T3946 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1703415 T3946 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 1703416 T3946 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.AliasIntegrationTest-controljetty-1382543256527/collection1/, dataDir=./org.apache.solr.cloud.AliasIntegrationTest-1382543256245/control/data/
   [junit4]   2> 1703416 T3946 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@419f3ad2
   [junit4]   2> 1703417 T3946 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.AliasIntegrationTest-1382543256245/control/data
   [junit4]   2> 1703417 T3946 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.AliasIntegrationTest-1382543256245/control/data/index/
   [junit4]   2> 1703418 T3946 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.AliasIntegrationTest-1382543256245/control/data/index' doesn't exist. Creating new index...
   [junit4]   2> 1703418 T3946 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.AliasIntegrationTest-1382543256245/control/data/index
   [junit4]   2> 1703419 T3946 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=20, maxMergeAtOnceExplicit=13, maxMergedSegmentMB=60.4619140625, floorSegmentMB=0.640625, forceMergeDeletesPctAllowed=16.70118518360164, segmentsPerTier=32.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.4635091498232351
   [junit4]   2> 1703420 T3946 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@76f366f1 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2da46c1c),segFN=segments_1,generation=1}
   [junit4]   2> 1703421 T3946 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1703427 T3946 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 1703427 T3946 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 1703429 T3946 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 1703429 T3946 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1703429 T3946 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1703430 T3946 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 1703431 T3946 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1703431 T3946 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1703432 T3946 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 1703433 T3946 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 1703433 T3946 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 1703434 T3946 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 1703434 T3946 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 1703435 T3946 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 1703436 T3946 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 1703448 T3946 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 1703456 T3946 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 1703456 T3946 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 1703457 T3946 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=35, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
   [junit4]   2> 1703458 T3946 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@76f366f1 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2da46c1c),segFN=segments_1,generation=1}
   [junit4]   2> 1703458 T3946 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1703459 T3946 oass.SolrIndexSearcher.<init> Opening Searcher@33483cc4 main
   [junit4]   2> 1703464 T3947 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@33483cc4 main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 1703465 T3946 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 1703467 T3946 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:50056 collection:control_collection shard:shard1
   [junit4]   2> 1703469 T3946 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
   [junit4]   2> 1703486 T3946 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 1703492 T3946 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 1703493 T3946 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> 1703493 T3946 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:50056/collection1/
   [junit4]   2> 1703493 T3946 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 1703493 T3946 oasc.SyncStrategy.syncToMe http://127.0.0.1:50056/collection1/ has no replicas
   [junit4]   2> 1703494 T3946 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:50056/collection1/ shard1
   [junit4]   2> 1703494 T3946 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
   [junit4]   2> 1704729 T3944 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1704750 T3943 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
   [junit4]   2> 1704774 T3946 oasc.ZkController.register We are http://127.0.0.1:50056/collection1/ and leader is http://127.0.0.1:50056/collection1/
   [junit4]   2> 1704774 T3946 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:50056
   [junit4]   2> 1704775 T3946 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 1704775 T3946 oasc.ZkController.publish publishing core=collection1 state=active
   [junit4]   2> 1704775 T3946 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1704779 T3946 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1704782 T3921 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0
   [junit4]   2> 1704783 T3921 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 1704786 T3921 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1704790 T3950 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@512ea872 name:ZooKeeperConnection Watcher:127.0.0.1:50053/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1704791 T3921 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1704794 T3921 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1704802 T3921 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
   [junit4]   2> 1705386 T3921 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 1705393 T3921 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:50060
   [junit4]   2> 1705396 T3921 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 1705397 T3921 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 1705397 T3921 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.AliasIntegrationTest-jetty1-1382543261866
   [junit4]   2> 1705398 T3921 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.AliasIntegrationTest-jetty1-1382543261866/'
   [junit4]   2> 1705476 T3921 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.AliasIntegrationTest-jetty1-1382543261866/solr.xml
   [junit4]   2> 1705674 T3921 oasc.CoreContainer.<init> New CoreContainer 1322977953
   [junit4]   2> 1705675 T3921 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.AliasIntegrationTest-jetty1-1382543261866/]
   [junit4]   2> 1705679 T3921 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 1705680 T3921 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 1705680 T3921 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 1705681 T3921 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 1705681 T3921 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 1705682 T3921 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 1705682 T3921 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 1705682 T3921 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 1705683 T3921 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 1705690 T3921 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 1705690 T3921 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 1705691 T3921 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:50053/solr
   [junit4]   2> 1705692 T3921 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 1705695 T3921 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1705701 T3961 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@377c9e17 name:ZooKeeperConnection Watcher:127.0.0.1:50053 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1705702 T3921 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1705712 T3921 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1705718 T3963 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4e8cdd6c name:ZooKeeperConnection Watcher:127.0.0.1:50053/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1705718 T3921 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1705731 T3921 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1706269 T3944 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1706271 T3944 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:50056",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:50056_",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "shard_parent":null,
   [junit4]   2> 	  "collection":"control_collection",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "core_node_name":"core_node1"}
   [junit4]   2> 1706287 T3950 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
   [junit4]   2> 1706287 T3963 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
   [junit4]   2> 1706287 T3943 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
   [junit4]   2> 1706743 T3921 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:50060_
   [junit4]   2> 1706746 T3921 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:50060_
   [junit4]   2> 1706754 T3943 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 1706755 T3963 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 1706754 T3950 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 1706784 T3964 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 1706785 T3964 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1706789 T3964 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 1707803 T3944 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1707804 T3944 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:50060",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:50060_",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "shard_parent":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "core_node_name":"core_node1"}
   [junit4]   2> 1707805 T3944 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1]
   [junit4]   2> 1707805 T3944 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 1707814 T3963 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 1707815 T3943 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 1707815 T3950 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 1708794 T3964 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 1708794 T3964 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.AliasIntegrationTest-jetty1-1382543261866/collection1
   [junit4]   2> 1708795 T3964 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 1708797 T3964 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 1708797 T3964 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 1708803 T3964 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.AliasIntegrationTest-jetty1-1382543261866/collection1/'
   [junit4]   2> 1708806 T3964 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.AliasIntegrationTest-jetty1-1382543261866/collection1/lib/classes/' to classloader
   [junit4]   2> 1708807 T3964 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.AliasIntegrationTest-jetty1-1382543261866/collection1/lib/README' to classloader
   [junit4]   2> 1708951 T3964 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 1709097 T3964 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 1709100 T3964 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 1709116 T3964 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 1710285 T3964 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 1710300 T3964 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 1710306 T3964 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 1710356 T3964 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1710365 T3964 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1710374 T3964 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1710378 T3964 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1710378 T3964 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1710379 T3964 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1710382 T3964 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1710383 T3964 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1710383 T3964 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 1710384 T3964 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.AliasIntegrationTest-jetty1-1382543261866/collection1/, dataDir=./org.apache.solr.cloud.AliasIntegrationTest-1382543256245/jetty1/
   [junit4]   2> 1710384 T3964 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@419f3ad2
   [junit4]   2> 1710385 T3964 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.AliasIntegrationTest-1382543256245/jetty1
   [junit4]   2> 1710386 T3964 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.AliasIntegrationTest-1382543256245/jetty1/index/
   [junit4]   2> 1710386 T3964 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.AliasIntegrationTest-1382543256245/jetty1/index' doesn't exist. Creating new index...
   [junit4]   2> 1710387 T3964 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.AliasIntegrationTest-1382543256245/jetty1/index
   [junit4]   2> 1710387 T3964 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=20, maxMergeAtOnceExplicit=13, maxMergedSegmentMB=60.4619140625, floorSegmentMB=0.640625, forceMergeDeletesPctAllowed=16.70118518360164, segmentsPerTier=32.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.4635091498232351
   [junit4]   2> 1710389 T3964 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@44e551a3 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@28cf9149),segFN=segments_1,generation=1}
   [junit4]   2> 1710389 T3964 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1710398 T3964 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 1710399 T3964 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 1710400 T3964 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 1710421 T3964 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1710422 T3964 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1710422 T3964 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 1710423 T3964 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1710424 T3964 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1710424 T3964 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 1710425 T3964 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 1710427 T3964 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 1710427 T3964 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 1710428 T3964 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 1710429 T3964 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 1710430 T3964 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 1710445 T3964 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 1710452 T3964 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 1710452 T3964 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 1710455 T3964 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=35, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
   [junit4]   2> 1710456 T3964 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@44e551a3 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@28cf9149),segFN=segments_1,generation=1}
   [junit4]   2> 1710457 T3964 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1710457 T3964 oass.SolrIndexSearcher.<init> Opening Searcher@27f9a122 main
   [junit4]   2> 1710469 T3965 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@27f9a122 main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 1710474 T3964 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 1710475 T3964 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:50060 collection:collection1 shard:shard1
   [junit4]   2> 1710478 T3964 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 1710502 T3964 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 1710511 T3964 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 1710512 T3964 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> 1710512 T3964 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:50060/collection1/
   [junit4]   2> 1710513 T3964 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 1710513 T3964 oasc.SyncStrategy.syncToMe http://127.0.0.1:50060/collection1/ has no replicas
   [junit4]   2> 1710514 T3964 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:50060/collection1/ shard1
   [junit4]   2> 1710514 T3964 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 1710837 T3944 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1710860 T3950 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 1710860 T3963 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 1710860 T3943 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 1710899 T3964 oasc.ZkController.register We are http://127.0.0.1:50060/collection1/ and leader is http://127.0.0.1:50060/collection1/
   [junit4]   2> 1710900 T3964 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:50060
   [junit4]   2> 1710901 T3964 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 1710901 T3964 oasc.ZkController.publish publishing core=collection1 state=active
   [junit4]   2> 1710902 T3964 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1710909 T3964 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1710913 T3921 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0
   [junit4]   2> 1710914 T3921 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 1711566 T3921 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 1711573 T3921 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:50063
   [junit4]   2> 1711576 T3921 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 1711577 T3921 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 1711578 T3921 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.AliasIntegrationTest-jetty2-1382543267979
   [junit4]   2> 1711579 T3921 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.AliasIntegrationTest-jetty2-1382543267979/'
   [junit4]   2> 1711664 T3921 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.AliasIntegrationTest-jetty2-1382543267979/solr.xml
   [junit4]   2> 1711805 T3921 oasc.CoreContainer.<init> New CoreContainer 1618510931
   [junit4]   2> 1711806 T3921 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.AliasIntegrationTest-jetty2-1382543267979/]
   [junit4]   2> 1711808 T3921 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 1711808 T3921 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 1711809 T3921 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 1711809 T3921 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 1711809 T3921 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 1711810 T3921 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 1711810 T3921 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 1711810 T3921 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 1711810 T3921 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 1711815 T3921 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 1711816 T3921 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 1711816 T3921 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:50053/solr
   [junit4]   2> 1711817 T3921 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 1711818 T3921 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1711823 T3977 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3f49c02c name:ZooKeeperConnection Watcher:127.0.0.1:50053 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1711824 T3921 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1711837 T3921 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1711843 T3979 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7b872683 name:ZooKeeperConnection Watcher:127.0.0.1:50053/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1711844 T3921 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1711861 T3921 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1712384 T3944 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1712385 T3944 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:50060",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:50060_",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "shard_parent":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "core_node_name":"core_node1"}
   [junit4]   2> 1712395 T3979 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 1712395 T3950 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 1712395 T3943 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 1712396 T3963 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 1712873 T3921 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:50063_
   [junit4]   2> 1712875 T3921 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:50063_
   [junit4]   2> 1712882 T3979 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 1712882 T3943 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 1712882 T3963 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 1712882 T3950 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 1712899 T3980 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 1712899 T3980 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1712902 T3980 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 1713907 T3944 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1713911 T3944 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:50063",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:50063_",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "shard_parent":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "core_node_name":"core_node2"}
   [junit4]   2> 1713912 T3944 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=1
   [junit4]   2> 1713913 T3944 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 1713926 T3979 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 1713926 T3963 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 1713926 T3943 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 1713926 T3950 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 1714904 T3980 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 1714905 T3980 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.AliasIntegrationTest-jetty2-1382543267979/collection1
   [junit4]   2> 1714906 T3980 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 1714908 T3980 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 1714908 T3980 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 1714911 T3980 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.AliasIntegrationTest-jetty2-1382543267979/collection1/'
   [junit4]   2> 1714914 T3980 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.AliasIntegrationTest-jetty2-1382543267979/collection1/lib/classes/' to classloader
   [junit4]   2> 1714915 T3980 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.AliasIntegrationTest-jetty2-1382543267979/collection1/lib/README' to classloader
   [junit4]   2> 1715054 T3980 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 1715167 T3980 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 1715171 T3980 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 1715189 T3980 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 1716383 T3980 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 1716396 T3980 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 1716402 T3980 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 1716435 T3980 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1716442 T3980 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1716450 T3980 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1716453 T3980 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1716453 T3980 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1716453 T3980 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1716456 T3980 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1716456 T3980 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1716457 T3980 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 1716457 T3980 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.AliasIntegrationTest-jetty2-1382543267979/collection1/, dataDir=./org.apache.solr.cloud.AliasIntegrationTest-1382543256245/jetty2/
   [junit4]   2> 1716457 T3980 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@419f3ad2
   [junit4]   2> 1716459 T3980 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.AliasIntegrationTest-1382543256245/jetty2
   [junit4]   2> 1716459 T3980 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.AliasIntegrationTest-1382543256245/jetty2/index/
   [junit4]   2> 1716459 T3980 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.AliasIntegrationTest-1382543256245/jetty2/index' doesn't exist. Creating new index...
   [junit4]   2> 1716460 T3980 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.AliasIntegrationTest-1382543256245/jetty2/index
   [junit4]   2> 1716460 T3980 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=20, maxMergeAtOnceExplicit=13, maxMergedSegmentMB=60.4619140625, floorSegmentMB=0.640625, forceMergeDeletesPctAllowed=16.70118518360164, segmentsPerTier=32.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.4635091498232351
   [junit4]   2> 1716462 T3980 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@12f3fe60 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@64ad5095),segFN=segments_1,generation=1}
   [junit4]   2> 1716462 T3980 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1716471 T3980 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 1716472 T3980 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 1716473 T3980 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 1716474 T3980 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1716474 T3980 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1716475 T3980 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 1716477 T3980 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1716477 T3980 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1716478 T3980 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 1716480 T3980 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 1716481 T3980 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 1716481 T3980 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 1716481 T3980 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 1716483 T3980 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 1716484 T3980 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 1716498 T3980 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 1716506 T3980 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 1716507 T3980 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 1716508 T3980 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=35, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
   [junit4]   2> 1716508 T3980 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@12f3fe60 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@64ad5095),segFN=segments_1,generation=1}
   [junit4]   2> 1716508 T3980 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1716509 T3980 oass.SolrIndexSearcher.<init> Opening Searcher@46a9749 main
   [junit4]   2> 1716516 T3981 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@46a9749 main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 1716516 T3980 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 1716517 T3980 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:50063 collection:collection1 shard:shard1
   [junit4]   2> 1716525 T3980 oasc.ZkController.register We are http://127.0.0.1:50063/collection1/ and leader is http://127.0.0.1:50060/collection1/
   [junit4]   2> 1716525 T3980 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:50063
   [junit4]   2> 1716526 T3980 oasc.ZkController.checkRecovery Core needs to recover:collection1
   [junit4]   2> 1716526 T3980 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
   [junit4]   2> ASYNC  NEW_CORE C4058 name=collection1 org.apache.solr.core.SolrCore@2498ba2e url=http://127.0.0.1:50063/collection1 node=127.0.0.1:50063_ C4058_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:50063, core=collection1, node_name=127.0.0.1:50063_}
   [junit4]   2> 1716527 T3982 C4058 P50063 oasc.RecoveryStrategy.run Starting recovery process.  core=collection1 recoveringAfterStartup=true
   [junit4]   2> 1716528 T3982 C4058 P50063 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
   [junit4]   2> 1716528 T3980 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1716529 T3982 C4058 P50063 oasc.ZkController.publish publishing core=collection1 state=recovering
   [junit4]   2> 1716529 T3982 C4058 P50063 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1716531 T3921 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0
   [junit4]   2> 1716532 T3921 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 1716535 T3957 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: core_node2, state: recovering, checkLive: true, onlyIfLeader: true
   [junit4]   2> 1716918 T3921 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 1716922 T3921 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:50067
   [junit4]   2> 1716925 T3921 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 1716925 T3921 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 1716926 T3921 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.AliasIntegrationTest-jetty3-1382543273597
   [junit4]   2> 1716926 T3921 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.AliasIntegrationTest-jetty3-1382543273597/'
   [junit4]   2> 1716944 T3944 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1716946 T3944 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"recovering",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:50063",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:50063_",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "shard_parent":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "core_node_name":"core_node2"}
   [junit4]   2> 1716956 T3943 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 1716957 T3950 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 1716961 T3979 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 1716961 T3963 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 1716978 T3921 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.AliasIntegrationTest-jetty3-1382543273597/solr.xml
   [junit4]   2> 1717102 T3921 oasc.CoreContainer.<init> New CoreContainer 80107300
   [junit4]   2> 1717103 T3921 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.AliasIntegrationTest-jetty3-1382543273597/]
   [junit4]   2> 1717109 T3921 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 1717110 T3921 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 1717112 T3921 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 1717112 T3921 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 1717113 T3921 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 1717113 T3921 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 1717114 T3921 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 1717114 T3921 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 1717115 T3921 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 1717120 T3921 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 1717121 T3921 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 1717121 T3921 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:50053/solr
   [junit4]   2> 1717122 T3921 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 1717124 T3921 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1717128 T3994 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1d03a8e2 name:ZooKeeperConnection Watcher:127.0.0.1:50053 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1717128 T3921 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1717133 T3921 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1717137 T3996 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@22a3e8a6 name:ZooKeeperConnection Watcher:127.0.0.1:50053/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1717138 T3921 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1717147 T3921 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1717539 T3957 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: core_node2, state: recovering, checkLive: true, onlyIfLeader: true for: 1 seconds.
   [junit4]   2> 1717540 T3957 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={coreNodeName=core_node2&state=recovering&nodeName=127.0.0.1:50063_&action=PREPRECOVERY&checkLive=true&core=collection1&wt=javabin&onlyIfLeader=true&version=2} status=0 QTime=1005 
   [junit4]   2> 1718156 T3921 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:50067_
   [junit4]   2> 1718161 T3921 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:50067_
   [junit4]   2> 1718177 T3950 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 1718180 T3996 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 1718181 T3963 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 1718182 T3943 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 1718181 T3979 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 1718215 T3997 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 1718216 T3997 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1718221 T3997 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 1718472 T3944 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1718474 T3944 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:50067",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:50067_",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "shard_parent":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "core_node_name":"core_node3"}
   [junit4]   2> 1718474 T3944 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=1
   [junit4]   2> 1718474 T3944 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 1718484 T3943 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> 1718485 T3950 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> 1718485 T3963 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> 1718484 T3979 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> 1718485 T3996 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> 1719223 T3997 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 1719223 T3997 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.AliasIntegrationTest-jetty3-1382543273597/collection1
   [junit4]   2> 1719224 T3997 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 1719227 T3997 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 1719227 T3997 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 1719231 T3997 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.AliasIntegrationTest-jetty3-1382543273597/collection1/'
   [junit4]   2> 1719234 T3997 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.AliasIntegrationTest-jetty3-1382543273597/collection1/lib/classes/' to classloader
   [junit4]   2> 1719235 T3997 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.AliasIntegrationTest-jetty3-1382543273597/collection1/lib/README' to classloader
   [junit4]   2> 1719383 T3997 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 1719531 T3997 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 1719536 T3997 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> ASYNC  NEW_CORE C4059 name=collection1 org.apache.solr.core.SolrCore@2498ba2e url=http://127.0.0.1:50063/collection1 node=127.0.0.1:50063_ C4059_STATE=coll:collection1 core:collection1 props:{state=recovering, base_url=http://127.0.0.1:50063, core=collection1, node_name=127.0.0.1:50063_}
   [junit4]   2> 1719542 T3982 C4059 P50063 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:50060/collection1/ core=collection1 - recoveringAfterStartup=true
   [junit4]   2> 1719543 T3982 C4059 P50063 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:50063 START replicas=[http://127.0.0.1:50060/collection1/] nUpdates=100
   [junit4]   2> 1719544 T3982 C4059 P50063 oasu.PeerSync.sync WARN no frame of reference to tell if we've missed updates
   [junit4]   2> 1719545 T3982 C4059 P50063 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
   [junit4]   2> 1719545 T3982 C4059 P50063 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
   [junit4]   2> 1719546 T3982 C4059 P50063 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
   [junit4]   2> 1719546 T3982 C4059 P50063 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
   [junit4]   2> 1719547 T3982 C4059 P50063 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:50060/collection1/. core=collection1
   [junit4]   2> 1719567 T3997 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> ASYNC  NEW_CORE C4060 name=collection1 org.apache.solr.core.SolrCore@43dbea24 url=http://127.0.0.1:50060/collection1 node=127.0.0.1:50060_ C4060_STATE=coll:collection1 core:collection1 props:{state=active, base_url=http://127.0.0.1:50060, core=collection1, node_name=127.0.0.1:50060_, leader=true}
   [junit4]   2> 1719574 T3957 C4060 P50060 oasc.SolrCore.execute [collection1] webapp= path=/get params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=2 
   [junit4]   2> 1719579 T3954 C4060 P50060 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 1719581 T3954 C4060 P50060 oasu.DirectUpdateHandler2.commit No uncommitted changes. Skipping IW.commit.
   [junit4]   2> 1719583 T3954 C4060 P50060 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 1719584 T3954 C4060 P50060 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={waitSearcher=true&openSearcher=false&commit=true&wt=javabin&commit_end_point=true&version=2&softCommit=false} {commit=} 0 7
   [junit4]   2> 1719588 T3982 C4059 P50063 oash.ReplicationHandler.inform Commits will be reserved for  10000
   [junit4]   2> 1719589 T3982 C4059 P50063 oash.SnapPuller.<init>  No value set for 'pollInterval'. Timer Task not started.
   [junit4]   2> 1719597 T3958 C4060 P50060 oash.ReplicationHandler.inform Commits will be reserved for  10000
   [junit4]   2> 1719598 T3958 C4060 P50060 oasc.SolrCore.execute [collection1] webapp= path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=3 
   [junit4]   2> 1719599 T3982 C4059 P50063 oasc.RecoveryStrategy.replay No replay needed. core=collection1
   [junit4]   2> 1719600 T3982 C4059 P50063 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
   [junit4]   2> 1719601 T3982 C4059 P50063 oasc.ZkController.publish publishing core=collection1 state=active
   [junit4]   2> 1719601 T3982 C4059 P50063 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1719604 T3982 C4059 P50063 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
   [junit4]   2> 1720003 T3944 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1720005 T3944 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:50063",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:50063_",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "shard_parent":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "core_node_name":"core_node2"}
   [junit4]   2> 1720032 T3996 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> 1720032 T3943 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> 1720032 T3979 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> 1720032 T3963 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> 1720035 T3950 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> 1720971 T3997 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 1720985 T3997 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 1720990 T3997 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 1721022 T3997 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1721030 T3997 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1721038 T3997 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1721041 T3997 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1721041 T3997 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1721041 T3997 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1721044 T3997 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1721045 T3997 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1721045 T3997 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 1721046 T3997 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.AliasIntegrationTest-jetty3-1382543273597/collection1/, dataDir=./org.apache.solr.cloud.AliasIntegrationTest-1382543256245/jetty3/
   [junit4]   2> 1721046 T3997 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@419f3ad2
   [junit4]   2> 1721047 T3997 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.AliasIntegrationTest-1382543256245/jetty3
   [junit4]   2> 1721047 T3997 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.AliasIntegrationTest-1382543256245/jetty3/index/
   [junit4]   2> 1721048 T3997 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.AliasIntegrationTest-1382543256245/jetty3/index' doesn't exist. Creating new index...
   [junit4]   2> 1721048 T3997 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.AliasIntegrationTest-1382543256245/jetty3/index
   [junit4]   2> 1721049 T3997 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=20, maxMergeAtOnceExplicit=13, maxMergedSegmentMB=60.4619140625, floorSegmentMB=0.640625, forceMergeDeletesPctAllowed=16.70118518360164, segmentsPerTier=32.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.4635091498232351
   [junit4]   2> 1721050 T3997 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@61895f06 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@70469176),segFN=segments_1,generation=1}
   [junit4]   2> 1721050 T3997 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1721058 T3997 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 1721059 T3997 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 1721060 T3997 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 1721060 T3997 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1721060 T3997 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1721061 T3997 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 1721062 T3997 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1721062 T3997 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1721062 T3997 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 1721064 T3997 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 1721065 T3997 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 1721065 T3997 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 1721067 T3997 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 1721069 T3997 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 1721069 T3997 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 1721084 T3997 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 1721091 T3997 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 1721091 T3997 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 1721092 T3997 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=35, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
   [junit4]   2> 1721093 T3997 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@61895f06 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@70469176),segFN=segments_1,generation=1}
   [junit4]   2> 1721094 T3997 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1721094 T3997 oass.SolrIndexSearcher.<init> Opening Searcher@778199c9 main
   [junit4]   2> 1721119 T3999 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@778199c9 main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 1721123 T3997 oasc.CoreContainer.registerCore registering core: collection1
 

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

ry=0,errors=0,cumulative_adds=2,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0}
   [junit4]   2> 1804817 T3921 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
   [junit4]   2> 1804818 T3921 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
   [junit4]   2> 1804818 T3921 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
   [junit4]   2> 1804821 T3921 oasc.SolrCore.closeSearcher [collection2_shard1_replica1] Closing main searcher on request.
   [junit4]   2> 1804822 T3921 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
   [junit4]   2> 1804822 T3921 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.AliasIntegrationTest-jetty3-1382543273597/collection2_shard1_replica1/data [CachedDir<<refCount=0;path=./org.apache.solr.cloud.AliasIntegrationTest-jetty3-1382543273597/collection2_shard1_replica1/data;done=false>>]
   [junit4]   2> 1804823 T3921 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.AliasIntegrationTest-jetty3-1382543273597/collection2_shard1_replica1/data
   [junit4]   2> 1804823 T3921 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.AliasIntegrationTest-jetty3-1382543273597/collection2_shard1_replica1/data/index [CachedDir<<refCount=0;path=./org.apache.solr.cloud.AliasIntegrationTest-jetty3-1382543273597/collection2_shard1_replica1/data/index;done=false>>]
   [junit4]   2> 1804824 T3921 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.AliasIntegrationTest-jetty3-1382543273597/collection2_shard1_replica1/data/index
   [junit4]   2> 1804827 T4028 oasc.Overseer$ClusterStateUpdater.amILeader According to ZK I (id=90606354842058762-127.0.0.1:50067_-n_0000000003) am no longer a leader.
   [junit4]   2> 1804851 T3921 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/,null}
   [junit4]   2> 1804922 T3921 oas.SolrTestCaseJ4.tearDown ###Ending testDistribSearch
   [junit4]   2> 1804927 T3921 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:50053 50053
   [junit4]   1> client port:0.0.0.0/0.0.0.0:0
   [junit4]   1> -
   [junit4]   1> replica:core_node1 rstate:down live:true
   [junit4]   1> replica:core_node2 rstate:down live:true
   [junit4]   1> -
   [junit4]   1> replica:core_node1 rstate:down live:true
   [junit4]   1> replica:core_node2 rstate:down live:true
   [junit4]   1> -
   [junit4]   1> replica:core_node1 rstate:active live:true
   [junit4]   1> replica:core_node2 rstate:active live:true
   [junit4]   1> no one is recoverying
   [junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=AliasIntegrationTest -Dtests.method=testDistribSearch -Dtests.seed=1DD745653F4BA171 -Dtests.slow=true -Dtests.locale=it_CH -Dtests.timezone=America/Argentina/Tucuman -Dtests.file.encoding=UTF-8
   [junit4] ERROR    106s | AliasIntegrationTest.testDistribSearch <<<
   [junit4]    > Throwable #1: org.apache.solr.client.solrj.impl.HttpSolrServer$RemoteSolrException: deletealias the collection time out:60s
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([1DD745653F4BA171:9C31CB7D4814C14D]:0)
   [junit4]    > 	at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:464)
   [junit4]    > 	at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:181)
   [junit4]    > 	at org.apache.solr.cloud.AliasIntegrationTest.deleteAlias(AliasIntegrationTest.java:254)
   [junit4]    > 	at org.apache.solr.cloud.AliasIntegrationTest.doTest(AliasIntegrationTest.java:227)
   [junit4]    > 	at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:835)
   [junit4]    > 	at java.lang.Thread.run(Thread.java:744)
   [junit4]   2> 1805048 T3921 oas.SolrTestCaseJ4.deleteCore ###deleteCore
   [junit4]   2> 105887 T3920 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 1 leaked thread(s).
   [junit4]   2> 1806335 T3996 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> NOTE: test params are: codec=Lucene46: {timestamp=PostingsFormat(name=MockRandom), range_facet_l=PostingsFormat(name=MockRandom), id=PostingsFormat(name=Direct), range_facet_sl=PostingsFormat(name=NestedPulsing), a_t=PostingsFormat(name=MockRandom), text=PostingsFormat(name=NestedPulsing), range_facet_si=PostingsFormat(name=Asserting), _version_=PostingsFormat(name=MockRandom), other_tl1=PostingsFormat(name=MockRandom), multiDefault=PostingsFormat(name=Asserting), a_si=PostingsFormat(name=Asserting), intDefault=PostingsFormat(name=MockRandom)}, docValues:{timestamp=DocValuesFormat(name=Disk)}, sim=DefaultSimilarity, locale=it_CH, timezone=America/Argentina/Tucuman
   [junit4]   2> NOTE: Mac OS X 10.8.5 x86_64/Oracle Corporation 1.7.0_45 (64-bit)/cpus=2,threads=4,free=84000736,total=371134464
   [junit4]   2> NOTE: All tests run in this JVM: [SearchHandlerTest, TestArbitraryIndexDir, TestSweetSpotSimilarityFactory, TestComponentsName, TestSolrQueryParserDefaultOperatorResource, TestBM25SimilarityFactory, ShardRoutingTest, TermVectorComponentTest, PathHierarchyTokenizerFactoryTest, TestRandomMergePolicy, TestSchemaResource, TestPostingsSolrHighlighter, PeerSyncTest, DirectSolrSpellCheckerTest, TestReversedWildcardFilterFactory, TestNumberUtils, TestRTGBase, UpdateRequestProcessorFactoryTest, SpellPossibilityIteratorTest, HdfsUnloadDistributedZkTest, UpdateParamsTest, DirectUpdateHandlerTest, OutputWriterTest, TestCodecSupport, TestSolrJ, TestLFUCache, PreAnalyzedFieldTest, DistributedTermsComponentTest, CacheHeaderTest, HdfsBasicDistributedZkTest, TestSolrXmlPersistence, BinaryUpdateRequestHandlerTest, SuggesterWFSTTest, TestSerializedLuceneMatchVersion, PingRequestHandlerTest, LukeRequestHandlerTest, MultiTermTest, InfoHandlerTest, ResourceLoaderTest, ShowFileRequestHandlerTest, BJQParserTest, CSVRequestHandlerTest, TestSystemIdResolver, TestReplicationHandler, TestDocumentBuilder, AddBlockUpdateTest, FastVectorHighlighterTest, DebugComponentTest, RequestHandlersTest, FieldAnalysisRequestHandlerTest, LoggingHandlerTest, OverseerTest, TestCopyFieldCollectionResource, TestWordDelimiterFilterFactory, TestAnalyzeInfixSuggestions, MoreLikeThisHandlerTest, SolrCmdDistributorTest, HighlighterTest, SpatialFilterTest, RequiredFieldsTest, SpellingQueryConverterTest, TestGroupingSearch, TestNonNRTOpen, LeaderElectionIntegrationTest, SpellCheckCollatorTest, TestRangeQuery, TestFaceting, TestFastOutputStream, IndexBasedSpellCheckerTest, NotRequiredUniqueKeyTest, HdfsSyncSliceTest, TestStressRecovery, TestInfoStreamLogging, TestMergePolicyConfig, AddSchemaFieldsUpdateProcessorFactoryTest, SampleTest, TestLMJelinekMercerSimilarityFactory, TestReload, TestBadConfig, JSONWriterTest, TestFieldTypeCollectionResource, TestRandomFaceting, TestLRUCache, TestIBSimilarityFactory, TestXIncludeConfig, SystemInfoHandlerTest, TestStressVersions, TestLuceneMatchVersion, BlockDirectoryTest, ZkSolrClientTest, TestPseudoReturnFields, TestManagedSchema, OpenCloseCoreStressTest, TestShardHandlerFactory, TestFieldCollectionResource, NoCacheHeaderTest, SortByFunctionTest, TestStressReorder, TestBinaryField, AutoCommitTest, TestSearchPerf, PrimitiveFieldTypeTest, SolrInfoMBeanTest, ChaosMonkeyNothingIsSafeTest, FullSolrCloudDistribCmdsTest, HdfsRecoveryZkTest, SuggesterTest, TestSolrCoreProperties, TestRecovery, DateFieldTest, SyncSliceTest, EchoParamsTest, TestJoin, TestDynamicFieldResource, TestNoOpRegenerator, TestRemoteStreaming, DocValuesMissingTest, DocumentBuilderTest, SolrCoreCheckLockOnStartupTest, TestSolrXMLSerializer, ShardRoutingCustomTest, TestPerFieldSimilarity, RegexBoostProcessorTest, TestSchemaSimilarityResource, OpenExchangeRatesOrgProviderTest, TestSolrQueryParserResource, TestFoldingMultitermQuery, DirectSolrConnectionTest, DOMUtilTest, TestCSVResponseWriter, TestManagedSchemaFieldResource, ParsingFieldUpdateProcessorsTest, SolrRequestParserTest, DirectUpdateHandlerOptimizeTest, SolrIndexConfigTest, TestSolrDeletionPolicy2, TestCSVLoader, QueryResultKeyTest, TestJmxMonitoredMap, FileBasedSpellCheckerTest, AssignTest, CircularListTest, ZkControllerTest, TestPhraseSuggestions, IndexSchemaTest, DocumentAnalysisRequestHandlerTest, TestIndexingPerformance, TestFastLRUCache, SliceStateUpdateTest, ZkCLITest, SimpleFacetsTest, QueryEqualityTest, TestLMDirichletSimilarityFactory, QueryParsingTest, TestQuerySenderListener, DeleteShardTest, BasicFunctionalityTest, TestDefaultSimilarityFactory, AliasIntegrationTest]
   [junit4] Completed in 107.47s, 1 test, 1 error <<< FAILURES!

[...truncated 517 lines...]
BUILD FAILED
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/build.xml:422: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/build.xml:402: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/build.xml:39: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build.xml:189: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/common-build.xml:483: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/lucene/common-build.xml:1259: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/lucene/common-build.xml:902: There were test failures: 326 suites, 1449 tests, 1 error, 40 ignored (5 assumptions)

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



Re: [JENKINS] Lucene-Solr-trunk-MacOSX (64bit/jdk1.7.0) - Build # 941 - Still Failing!

Posted by Michael McCandless <lu...@mikemccandless.com>.
I committed a fix.

Mike McCandless

http://blog.mikemccandless.com


On Wed, Oct 23, 2013 at 6:31 PM, Policeman Jenkins Server
<je...@thetaphi.de> wrote:
> Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-MacOSX/941/
> Java: 64bit/jdk1.7.0 -XX:+UseCompressedOops -XX:+UseParallelGC
>
> 1 tests failed.
> FAILED:  org.apache.lucene.facet.search.OrdinalsCacheTest.testOrdinalsCacheWithThreads
>
> Error Message:
> expected:<804> but was:<76>
>
> Stack Trace:
> java.lang.AssertionError: expected:<804> but was:<76>
>         at __randomizedtesting.SeedInfo.seed([43A4DA7C47F23380:29D08C209C05426A]:0)
>         at org.junit.Assert.fail(Assert.java:93)
>         at org.junit.Assert.failNotEquals(Assert.java:647)
>         at org.junit.Assert.assertEquals(Assert.java:128)
>         at org.junit.Assert.assertEquals(Assert.java:472)
>         at org.junit.Assert.assertEquals(Assert.java:456)
>         at org.apache.lucene.facet.search.OrdinalsCacheTest.testOrdinalsCacheWithThreads(OrdinalsCacheTest.java:83)
>         at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
>         at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
>         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 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 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 7319 lines...]
>    [junit4] Suite: org.apache.lucene.facet.search.OrdinalsCacheTest
>    [junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=OrdinalsCacheTest -Dtests.method=testOrdinalsCacheWithThreads -Dtests.seed=43A4DA7C47F23380 -Dtests.slow=true -Dtests.locale=hu -Dtests.timezone=Australia/Darwin -Dtests.file.encoding=US-ASCII
>    [junit4] FAILURE 0.23s | OrdinalsCacheTest.testOrdinalsCacheWithThreads <<<
>    [junit4]    > Throwable #1: java.lang.AssertionError: expected:<804> but was:<76>
>    [junit4]    >        at __randomizedtesting.SeedInfo.seed([43A4DA7C47F23380:29D08C209C05426A]:0)
>    [junit4]    >        at org.apache.lucene.facet.search.OrdinalsCacheTest.testOrdinalsCacheWithThreads(OrdinalsCacheTest.java:83)
>    [junit4]    >        at java.lang.Thread.run(Thread.java:744)
>    [junit4]   2> NOTE: test params are: codec=Asserting, sim=DefaultSimilarity, locale=hu, timezone=Australia/Darwin
>    [junit4]   2> NOTE: Mac OS X 10.8.5 x86_64/Oracle Corporation 1.7.0_45 (64-bit)/cpus=2,threads=1,free=142441272,total=190840832
>    [junit4]   2> NOTE: All tests run in this JVM: [TestDirectoryTaxonomyWriter, FacetResultTest, TestTotalFacetCountsCache, TestTaxonomyCombined, TestSameRequestAccumulation, TestTopKResultsHandler, FloatToObjectMapTest, TestFacetArrays, EncodingTest, OversampleWithDepthTest, TestFacetsAccumulatorWithComplement, TestCategoryPath, SamplingWrapperTest, ObjectToIntMapTest, AssociationsFacetRequestTest, MultiCategoryListIteratorTest, TestDrillSideways, TestFacetsPayloadMigrationReader, TestLRUHashMap, AdaptiveAccumulatorTest, ObjectToFloatMapTest, FacetSearchParamsTest, IntToFloatMapTest, CountingFacetsAggregatorTest, OrdinalsCacheTest]
>    [junit4] Completed in 0.25s, 1 test, 1 failure <<< FAILURES!
>
> [...truncated 102 lines...]
> BUILD FAILED
> /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/build.xml:422: The following error occurred while executing this line:
> /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/build.xml:402: The following error occurred while executing this line:
> /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/build.xml:39: The following error occurred while executing this line:
> /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/lucene/build.xml:562: The following error occurred while executing this line:
> /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/lucene/common-build.xml:1916: The following error occurred while executing this line:
> /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/lucene/module-build.xml:60: The following error occurred while executing this line:
> /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/lucene/common-build.xml:1259: The following error occurred while executing this line:
> /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/lucene/common-build.xml:902: There were test failures: 56 suites, 246 tests, 1 failure
>
> Total time: 32 minutes 36 seconds
> Build step 'Invoke Ant' marked build as failure
> Description set: Java: 64bit/jdk1.7.0 -XX:+UseCompressedOops -XX:+UseParallelGC
> Archiving artifacts
> Recording test results
> Email was triggered for: Failure
> Sending email for trigger: Failure
>
>
>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: dev-unsubscribe@lucene.apache.org
> For additional commands, e-mail: dev-help@lucene.apache.org

---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@lucene.apache.org
For additional commands, e-mail: dev-help@lucene.apache.org


[JENKINS] Lucene-Solr-trunk-MacOSX (64bit/jdk1.7.0) - Build # 941 - Still Failing!

Posted by Policeman Jenkins Server <je...@thetaphi.de>.
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-MacOSX/941/
Java: 64bit/jdk1.7.0 -XX:+UseCompressedOops -XX:+UseParallelGC

1 tests failed.
FAILED:  org.apache.lucene.facet.search.OrdinalsCacheTest.testOrdinalsCacheWithThreads

Error Message:
expected:<804> but was:<76>

Stack Trace:
java.lang.AssertionError: expected:<804> but was:<76>
	at __randomizedtesting.SeedInfo.seed([43A4DA7C47F23380:29D08C209C05426A]:0)
	at org.junit.Assert.fail(Assert.java:93)
	at org.junit.Assert.failNotEquals(Assert.java:647)
	at org.junit.Assert.assertEquals(Assert.java:128)
	at org.junit.Assert.assertEquals(Assert.java:472)
	at org.junit.Assert.assertEquals(Assert.java:456)
	at org.apache.lucene.facet.search.OrdinalsCacheTest.testOrdinalsCacheWithThreads(OrdinalsCacheTest.java:83)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
	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 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 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 7319 lines...]
   [junit4] Suite: org.apache.lucene.facet.search.OrdinalsCacheTest
   [junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=OrdinalsCacheTest -Dtests.method=testOrdinalsCacheWithThreads -Dtests.seed=43A4DA7C47F23380 -Dtests.slow=true -Dtests.locale=hu -Dtests.timezone=Australia/Darwin -Dtests.file.encoding=US-ASCII
   [junit4] FAILURE 0.23s | OrdinalsCacheTest.testOrdinalsCacheWithThreads <<<
   [junit4]    > Throwable #1: java.lang.AssertionError: expected:<804> but was:<76>
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([43A4DA7C47F23380:29D08C209C05426A]:0)
   [junit4]    > 	at org.apache.lucene.facet.search.OrdinalsCacheTest.testOrdinalsCacheWithThreads(OrdinalsCacheTest.java:83)
   [junit4]    > 	at java.lang.Thread.run(Thread.java:744)
   [junit4]   2> NOTE: test params are: codec=Asserting, sim=DefaultSimilarity, locale=hu, timezone=Australia/Darwin
   [junit4]   2> NOTE: Mac OS X 10.8.5 x86_64/Oracle Corporation 1.7.0_45 (64-bit)/cpus=2,threads=1,free=142441272,total=190840832
   [junit4]   2> NOTE: All tests run in this JVM: [TestDirectoryTaxonomyWriter, FacetResultTest, TestTotalFacetCountsCache, TestTaxonomyCombined, TestSameRequestAccumulation, TestTopKResultsHandler, FloatToObjectMapTest, TestFacetArrays, EncodingTest, OversampleWithDepthTest, TestFacetsAccumulatorWithComplement, TestCategoryPath, SamplingWrapperTest, ObjectToIntMapTest, AssociationsFacetRequestTest, MultiCategoryListIteratorTest, TestDrillSideways, TestFacetsPayloadMigrationReader, TestLRUHashMap, AdaptiveAccumulatorTest, ObjectToFloatMapTest, FacetSearchParamsTest, IntToFloatMapTest, CountingFacetsAggregatorTest, OrdinalsCacheTest]
   [junit4] Completed in 0.25s, 1 test, 1 failure <<< FAILURES!

[...truncated 102 lines...]
BUILD FAILED
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/build.xml:422: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/build.xml:402: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/build.xml:39: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/lucene/build.xml:562: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/lucene/common-build.xml:1916: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/lucene/module-build.xml:60: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/lucene/common-build.xml:1259: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/lucene/common-build.xml:902: There were test failures: 56 suites, 246 tests, 1 failure

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