lucene-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Apache Jenkins Server <jenk...@builds.apache.org>
Subject [JENKINS] Lucene-Solr-Tests-trunk-Java7 - Build # 4555 - Still Failing
Date Sun, 29 Dec 2013 14:28:19 GMT
Build: https://builds.apache.org/job/Lucene-Solr-Tests-trunk-Java7/4555/

1 tests failed.
FAILED:  org.apache.solr.cloud.BasicDistributedZk2Test.testDistribSearch

Error Message:
No live SolrServers available to handle this request:[http://127.0.0.1:44959/collection1, http://127.0.0.1:51581/collection1]

Stack Trace:
org.apache.solr.client.solrj.SolrServerException: No live SolrServers available to handle this request:[http://127.0.0.1:44959/collection1, http://127.0.0.1:51581/collection1]
	at __randomizedtesting.SeedInfo.seed([4CA9CB3C9CA820FE:CD4F4524EBF740C2]:0)
	at org.apache.solr.client.solrj.impl.LBHttpSolrServer.request(LBHttpSolrServer.java:352)
	at org.apache.solr.client.solrj.impl.CloudSolrServer.request(CloudSolrServer.java:640)
	at org.apache.solr.client.solrj.request.QueryRequest.process(QueryRequest.java:90)
	at org.apache.solr.client.solrj.SolrServer.query(SolrServer.java:301)
	at org.apache.solr.cloud.AbstractFullDistribZkTestBase.queryServer(AbstractFullDistribZkTestBase.java:1325)
	at org.apache.solr.BaseDistributedSearchTestCase.query(BaseDistributedSearchTestCase.java:542)
	at org.apache.solr.BaseDistributedSearchTestCase.query(BaseDistributedSearchTestCase.java:521)
	at org.apache.solr.cloud.BasicDistributedZk2Test.brindDownShardIndexSomeDocsAndRecover(BasicDistributedZk2Test.java:305)
	at org.apache.solr.cloud.BasicDistributedZk2Test.doTest(BasicDistributedZk2Test.java:117)
	at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:849)
	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:724)
Caused by: org.apache.solr.client.solrj.impl.HttpSolrServer$RemoteSolrException: no servers hosting shard: 
	at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:495)
	at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:199)
	at org.apache.solr.client.solrj.impl.LBHttpSolrServer.request(LBHttpSolrServer.java:283)
	... 49 more




Build Log:
[...truncated 10452 lines...]
   [junit4] Suite: org.apache.solr.cloud.BasicDistributedZk2Test
   [junit4]   2> 1000141 T2505 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
   [junit4]   2> 1000146 T2505 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
   [junit4]   2> Creating dataDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1388325984703
   [junit4]   2> 1000147 T2505 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   2> 1000147 T2506 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 1000248 T2505 oasc.ZkTestServer.run start zk server on port:26871
   [junit4]   2> 1000248 T2505 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1000252 T2513 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1966a90d name:ZooKeeperConnection Watcher:127.0.0.1:26871 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1000252 T2505 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1000253 T2505 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 1000264 T2505 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1000266 T2516 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5c163f8a name:ZooKeeperConnection Watcher:127.0.0.1:26871/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1000267 T2505 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1000267 T2505 oascc.SolrZkClient.makePath makePath: /collections/collection1
   [junit4]   2> 1000277 T2505 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
   [junit4]   2> 1000280 T2505 oascc.SolrZkClient.makePath makePath: /collections/control_collection
   [junit4]   2> 1000283 T2505 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
   [junit4]   2> 1000291 T2505 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
   [junit4]   2> 1000292 T2505 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
   [junit4]   2> 1000304 T2505 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
   [junit4]   2> 1000305 T2505 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
   [junit4]   2> 1000410 T2505 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 1000411 T2505 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 1000414 T2505 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
   [junit4]   2> 1000415 T2505 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
   [junit4]   2> 1000424 T2505 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
   [junit4]   2> 1000425 T2505 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
   [junit4]   2> 1000428 T2505 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
   [junit4]   2> 1000429 T2505 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
   [junit4]   2> 1000432 T2505 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml
   [junit4]   2> 1000433 T2505 oascc.SolrZkClient.makePath makePath: /configs/conf1/enumsConfig.xml
   [junit4]   2> 1000436 T2505 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
   [junit4]   2> 1000436 T2505 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
   [junit4]   2> 1000440 T2505 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 1000441 T2505 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 1000446 T2505 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
   [junit4]   2> 1000447 T2505 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
   [junit4]   2> 1000452 T2505 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
   [junit4]   2> 1000452 T2505 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
   [junit4]   2> 1000749 T2505 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 1000754 T2505 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:32969
   [junit4]   2> 1000755 T2505 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 1000756 T2505 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 1000756 T2505 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1388325985018
   [junit4]   2> 1000757 T2505 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1388325985018/'
   [junit4]   2> 1000799 T2505 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1388325985018/solr.xml
   [junit4]   2> 1000898 T2505 oasc.CoreContainer.<init> New CoreContainer 1143748987
   [junit4]   2> 1000899 T2505 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1388325985018/]
   [junit4]   2> 1000901 T2505 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 1000902 T2505 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 1000902 T2505 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 1000903 T2505 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 1000903 T2505 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 1000904 T2505 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 1000904 T2505 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 1000905 T2505 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 1000905 T2505 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 1000923 T2505 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 1000923 T2505 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 1000924 T2505 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 1000925 T2505 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:26871/solr
   [junit4]   2> 1000925 T2505 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 1000926 T2505 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1000929 T2528 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@474ef943 name:ZooKeeperConnection Watcher:127.0.0.1:26871 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1000930 T2505 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1000941 T2505 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1000943 T2531 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@512c207d name:ZooKeeperConnection Watcher:127.0.0.1:26871/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1000943 T2505 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1000950 T2505 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 1000955 T2505 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 1000964 T2505 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 1000967 T2505 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:32969_
   [junit4]   2> 1000973 T2505 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:32969_
   [junit4]   2> 1000977 T2505 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 1000992 T2505 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 1001001 T2505 oasc.Overseer.start Overseer (id=90985331733823491-127.0.0.1:32969_-n_0000000000) starting
   [junit4]   2> 1001015 T2505 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 1001024 T2533 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 1001025 T2505 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 1001027 T2505 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 1001030 T2505 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1001032 T2532 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 1001039 T2534 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 1001040 T2534 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1001041 T2531 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1001041 T2534 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 1001043 T2532 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1001043 T2532 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:32969",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:32969_",
   [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":null}
   [junit4]   2> 1001044 T2532 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1]
   [junit4]   2> 1001044 T2532 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 1001047 T2531 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1001057 T2531 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> 1002043 T2534 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 1002043 T2534 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1388325985018/collection1
   [junit4]   2> 1002044 T2534 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
   [junit4]   2> 1002045 T2534 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 1002045 T2534 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
   [junit4]   2> 1002046 T2534 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1388325985018/collection1/'
   [junit4]   2> 1002048 T2534 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1388325985018/collection1/lib/classes/' to classloader
   [junit4]   2> 1002049 T2534 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1388325985018/collection1/lib/README' to classloader
   [junit4]   2> 1002114 T2534 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 1002177 T2534 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 1002280 T2534 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 1002301 T2534 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 1002972 T2534 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 1002985 T2534 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 1002989 T2534 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 1003006 T2534 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1003011 T2534 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1003016 T2534 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1003017 T2534 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1003017 T2534 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1003018 T2534 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1003019 T2534 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1003019 T2534 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1003019 T2534 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 1003020 T2534 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1388325985018/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1388325984702/control/data/
   [junit4]   2> 1003020 T2534 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@36f5c2cf
   [junit4]   2> 1003021 T2534 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1388325984702/control/data
   [junit4]   2> 1003021 T2534 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1388325984702/control/data/index/
   [junit4]   2> 1003022 T2534 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1388325984702/control/data/index' doesn't exist. Creating new index...
   [junit4]   2> 1003022 T2534 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1388325984702/control/data/index
   [junit4]   2> 1003023 T2534 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.MockRandomMergePolicy: org.apache.lucene.index.MockRandomMergePolicy@52cf6d14
   [junit4]   2> 1003024 T2534 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@400049 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@4ad0a5ee),segFN=segments_1,generation=1}
   [junit4]   2> 1003024 T2534 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1003029 T2534 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 1003029 T2534 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 1003030 T2534 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 1003030 T2534 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1003030 T2534 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1003031 T2534 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 1003031 T2534 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1003032 T2534 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1003032 T2534 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 1003033 T2534 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 1003033 T2534 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 1003034 T2534 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 1003034 T2534 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 1003035 T2534 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 1003035 T2534 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 1003036 T2534 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 1003036 T2534 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
   [junit4]   2> 1003054 T2534 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 1003060 T2534 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 1003061 T2534 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 1003061 T2534 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=35, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
   [junit4]   2> 1003062 T2534 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@400049 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@4ad0a5ee),segFN=segments_1,generation=1}
   [junit4]   2> 1003062 T2534 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1003063 T2534 oass.SolrIndexSearcher.<init> Opening Searcher@377b30f6 main
   [junit4]   2> 1003066 T2535 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@377b30f6 main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 1003069 T2534 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 1003070 T2505 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1
   [junit4]   2> 1003071 T2505 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 1003070 T2538 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:32969 collection:control_collection shard:shard1
   [junit4]   2> 1003072 T2538 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
   [junit4]   2> 1003074 T2505 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1003076 T2541 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1c24a2a5 name:ZooKeeperConnection Watcher:127.0.0.1:26871/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1003077 T2505 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1003087 T2505 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1003096 T2538 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 1003096 T2505 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:false
   [junit4]   2> 1003110 T2531 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1003111 T2538 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 1003111 T2538 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> ASYNC  NEW_CORE C725 name=collection1 org.apache.solr.core.SolrCore@34ae34a2 url=http://127.0.0.1:32969/collection1 node=127.0.0.1:32969_ C725_STATE=coll:control_collection core:collection1 props:{state=down, base_url=http://127.0.0.1:32969, core=collection1, node_name=127.0.0.1:32969_}
   [junit4]   2> 1003111 T2538 C725 P32969 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:32969/collection1/
   [junit4]   2> 1003112 T2538 C725 P32969 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 1003112 T2532 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1003112 T2538 C725 P32969 oasc.SyncStrategy.syncToMe http://127.0.0.1:32969/collection1/ has no replicas
   [junit4]   2> 1003113 T2538 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:32969/collection1/ shard1
   [junit4]   2> 1003113 T2538 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
   [junit4]   2> 1003116 T2531 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1003124 T2531 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> 1003124 T2541 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> 1003143 T2532 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1003147 T2531 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1003252 T2531 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> 1003252 T2541 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> 1003296 T2538 oasc.ZkController.register We are http://127.0.0.1:32969/collection1/ and leader is http://127.0.0.1:32969/collection1/
   [junit4]   2> 1003296 T2538 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:32969
   [junit4]   2> 1003296 T2538 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 1003296 T2538 oasc.ZkController.publish publishing core=collection1 state=active
   [junit4]   2> 1003297 T2538 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1003299 T2531 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1003299 T2531 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1003299 T2531 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1003299 T2538 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1003301 T2532 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1003301 T2532 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:32969",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:32969_",
   [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":"2",
   [junit4]   2> 	  "core_node_name":"core_node1"}
   [junit4]   2> 1003310 T2531 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1003415 T2531 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> 1003415 T2541 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> 1003466 T2505 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 1003469 T2505 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:44959
   [junit4]   2> 1003470 T2505 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 1003471 T2505 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 1003471 T2505 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1388325987652
   [junit4]   2> 1003472 T2505 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1388325987652/'
   [junit4]   2> 1003519 T2505 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1388325987652/solr.xml
   [junit4]   2> 1003619 T2505 oasc.CoreContainer.<init> New CoreContainer 425802072
   [junit4]   2> 1003620 T2505 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1388325987652/]
   [junit4]   2> 1003622 T2505 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 1003622 T2505 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 1003623 T2505 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 1003623 T2505 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 1003624 T2505 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 1003624 T2505 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 1003625 T2505 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 1003625 T2505 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 1003626 T2505 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 1003644 T2505 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 1003645 T2505 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 1003645 T2505 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 1003646 T2505 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:26871/solr
   [junit4]   2> 1003646 T2505 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 1003648 T2505 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1003651 T2553 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1c685d3b name:ZooKeeperConnection Watcher:127.0.0.1:26871 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1003651 T2505 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1003655 T2505 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1003662 T2556 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@43ab376a name:ZooKeeperConnection Watcher:127.0.0.1:26871/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1003662 T2505 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1003667 T2505 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1004671 T2505 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:44959_
   [junit4]   2> 1004673 T2505 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:44959_
   [junit4]   2> 1004677 T2541 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 1004677 T2556 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 1004677 T2531 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 1004688 T2557 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 1004688 T2557 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1004690 T2531 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1004690 T2557 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 1004690 T2531 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1004690 T2531 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1004692 T2532 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1004693 T2532 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:44959",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:44959_",
   [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":"2",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 1004693 T2532 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2]
   [junit4]   2> 1004693 T2532 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
   [junit4]   2> 1004696 T2531 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1004799 T2541 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> 1004799 T2531 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> 1004799 T2556 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> 1005691 T2557 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 1005691 T2557 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1388325987652/collection1
   [junit4]   2> 1005692 T2557 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 1005692 T2557 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 1005693 T2557 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 1005694 T2557 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1388325987652/collection1/'
   [junit4]   2> 1005696 T2557 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1388325987652/collection1/lib/README' to classloader
   [junit4]   2> 1005697 T2557 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1388325987652/collection1/lib/classes/' to classloader
   [junit4]   2> 1005765 T2557 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 1005831 T2557 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 1005934 T2557 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 1005949 T2557 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 1006712 T2557 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 1006726 T2557 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 1006730 T2557 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 1006748 T2557 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1006755 T2557 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1006761 T2557 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1006763 T2557 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1006763 T2557 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1006764 T2557 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1006765 T2557 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1006765 T2557 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1006766 T2557 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 1006766 T2557 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1388325987652/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1388325984702/jetty1/
   [junit4]   2> 1006767 T2557 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@36f5c2cf
   [junit4]   2> 1006768 T2557 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1388325984702/jetty1
   [junit4]   2> 1006768 T2557 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1388325984702/jetty1/index/
   [junit4]   2> 1006768 T2557 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1388325984702/jetty1/index' doesn't exist. Creating new index...
   [junit4]   2> 1006769 T2557 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1388325984702/jetty1/index
   [junit4]   2> 1006769 T2557 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.MockRandomMergePolicy: org.apache.lucene.index.MockRandomMergePolicy@573016bf
   [junit4]   2> 1006770 T2557 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@d075ded lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@c9d1277),segFN=segments_1,generation=1}
   [junit4]   2> 1006771 T2557 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1006777 T2557 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 1006778 T2557 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 1006778 T2557 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 1006778 T2557 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1006779 T2557 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1006779 T2557 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 1006780 T2557 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1006780 T2557 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1006780 T2557 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 1006781 T2557 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 1006782 T2557 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 1006782 T2557 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 1006783 T2557 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 1006783 T2557 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 1006784 T2557 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 1006785 T2557 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 1006786 T2557 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
   [junit4]   2> 1006808 T2557 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 1006816 T2557 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 1006816 T2557 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 1006817 T2557 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=35, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
   [junit4]   2> 1006818 T2557 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@d075ded lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@c9d1277),segFN=segments_1,generation=1}
   [junit4]   2> 1006818 T2557 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1006819 T2557 oass.SolrIndexSearcher.<init> Opening Searcher@467bdd7b main
   [junit4]   2> 1006824 T2558 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@467bdd7b main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 1006828 T2557 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 1006829 T2505 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1
   [junit4]   2> 1006829 T2505 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 1006829 T2561 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:44959 collection:collection1 shard:shard2
   [junit4]   2> 1006831 T2561 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
   [junit4]   2> 1006855 T2561 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
   [junit4]   2> 1006858 T2531 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1006859 T2561 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 1006859 T2531 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1006859 T2561 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> 1006860 T2531 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> ASYNC  NEW_CORE C726 name=collection1 org.apache.solr.core.SolrCore@414cc51 url=http://127.0.0.1:44959/collection1 node=127.0.0.1:44959_ C726_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:44959, core=collection1, node_name=127.0.0.1:44959_}
   [junit4]   2> 1006860 T2561 C726 P44959 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:44959/collection1/
   [junit4]   2> 1006861 T2561 C726 P44959 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 1006861 T2561 C726 P44959 oasc.SyncStrategy.syncToMe http://127.0.0.1:44959/collection1/ has no replicas
   [junit4]   2> 1006861 T2532 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1006862 T2561 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:44959/collection1/ shard2
   [junit4]   2> 1006862 T2561 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
   [junit4]   2> 1006866 T2531 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1006867 T2531 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> 1006868 T2541 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> 1006867 T2556 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> 1006873 T2532 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1006877 T2531 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1006981 T2531 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> 1006981 T2541 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> 1006981 T2556 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> 1007024 T2561 oasc.ZkController.register We are http://127.0.0.1:44959/collection1/ and leader is http://127.0.0.1:44959/collection1/
   [junit4]   2> 1007024 T2561 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:44959
   [junit4]   2> 1007024 T2561 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 1007025 T2561 oasc.ZkController.publish publishing core=collection1 state=active
   [junit4]   2> 1007025 T2561 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1007027 T2531 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1007027 T2531 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1007027 T2531 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1007027 T2561 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1007029 T2532 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1007030 T2532 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:44959",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:44959_",
   [junit4]   2> 	  "shard":"shard2",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "shard_parent":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":"core_node1"}
   [junit4]   2> 1007034 T2531 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1007142 T2531 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> 1007142 T2541 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> 1007142 T2556 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> 1007217 T2505 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 1007221 T2505 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:23508
   [junit4]   2> 1007222 T2505 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 1007222 T2505 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 1007223 T2505 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1388325991387
   [junit4]   2> 1007223 T2505 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1388325991387/'
   [junit4]   2> 1007277 T2505 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1388325991387/solr.xml
   [junit4]   2> 1007397 T2505 oasc.CoreContainer.<init> New CoreContainer 1797123293
   [junit4]   2> 1007398 T2505 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1388325991387/]
   [junit4]   2> 1007400 T2505 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 1007400 T2505 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 1007401 T2505 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 1007401 T2505 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 1007402 T2505 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 1007402 T2505 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 1007403 T2505 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 1007403 T2505 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 1007404 T2505 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 1007423 T2505 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 1007423 T2505 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 1007424 T2505 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 1007425 T2505 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:26871/solr
   [junit4]   2> 1007425 T2505 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 1007426 T2505 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1007429 T2573 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7bb786f5 name:ZooKeeperConnection Watcher:127.0.0.1:26871 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1007430 T2505 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1007433 T2505 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1007443 T2576 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6fa9f904 name:ZooKeeperConnection Watcher:127.0.0.1:26871/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1007443 T2505 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1007451 T2505 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1008456 T2505 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:23508_
   [junit4]   2> 1008483 T2505 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:23508_
   [junit4]   2> 1008488 T2541 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 1008488 T2556 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 1008488 T2576 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 1008488 T2531 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 1008504 T2577 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 1008505 T2577 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1008506 T2531 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1008506 T2577 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 1008506 T2531 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1008507 T2531 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1008508 T2532 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1008509 T2532 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:23508",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:23508_",
   [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":"2",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 1008510 T2532 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
   [junit4]   2> 1008510 T2532 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 1008513 T2531 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1008616 T2576 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> 1008616 T2556 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> 1008616 T2541 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> 1008616 T2531 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> 1009508 T2577 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 1009508 T2577 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1388325991387/collection1
   [junit4]   2> 1009508 T2577 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 1009509 T2577 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 1009510 T2577 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 1009511 T2577 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1388325991387/collection1/'
   [junit4]   2> 1009512 T2577 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1388325991387/collection1/lib/classes/' to classloader
   [junit4]   2> 1009513 T2577 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1388325991387/collection1/lib/README' to classloader
   [junit4]   2> 1009583 T2577 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 1009650 T2577 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 1009753 T2577 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 1009768 T2577 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 1010427 T2577 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 1010439 T2577 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 1010443 T2577 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 1010459 T2577 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1010464 T2577 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1010468 T2577 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1010470 T2577 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1010470 T2577 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1010470 T2577 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1010472 T2577 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1010472 T2577 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1010472 T2577 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 1010473 T2577 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1388325991387/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1388325984702/jetty2/
   [junit4]   2> 1010473 T2577 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@36f5c2cf
   [junit4]   2> 1010474 T2577 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1388325984702/jetty2
   [junit4]   2> 1010474 T2577 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1388325984702/jetty2/index/
   [junit4]   2> 1010475 T2577 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1388325984702/jetty2/index' doesn't exist. Creating new index...
   [junit4]   2> 1010475 T2577 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1388325984702/jetty2/index
   [junit4]   2> 1010476 T2577 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.MockRandomMergePolicy: org.apache.lucene.index.MockRandomMergePolicy@38391609
   [junit4]   2> 1010477 T2577 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@2387a6fb lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5a72e7ea),segFN=segments_1,generation=1}
   [junit4]   2> 1010477 T2577 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1010483 T2577 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 1010484 T2577 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 1010484 T2577 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 1010484 T2577 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1010485 T2577 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1010485 T2577 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 1010486 T2577 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1010486 T2577 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1010486 T2577 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 1010487 T2577 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 1010488 T2577 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 1010488 T2577 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 1010489 T2577 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 1010489 T2577 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 1010490 T2577 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 1010491 T2577 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 1010491 T2577 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
   [junit4]   2> 1010507 T2577 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 1010513 T2577 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 1010513 T2577 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 1010514 T2577 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=35, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
   [junit4]   2> 1010515 T2577 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@2387a6fb lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5a72e7ea),segFN=segments_1,generation=1}
   [junit4]   2> 1010516 T2577 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1010516 T2577 oass.SolrIndexSearcher.<init> Opening Searcher@4ee7792a main
   [junit4]   2> 1010522 T2578 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@4ee7792a main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 1010526 T2577 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 1010526 T2505 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1
   [junit4]   2> 1010527 T2505 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 1010526 T2581 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:23508 collection:collection1 shard:shard1
   [junit4]   2> 1010529 T2581 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 1010549 T2581 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 1010552 T2531 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1010552 T2531 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1010552 T2581 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 1010553 T2581 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> 1010552 T2531 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> ASYNC  NEW_CORE C727 name=collection1 org.apache.solr.core.SolrCore@3b0bcd60 url=http://127.0.0.1:23508/collection1 node=127.0.0.1:23508_ C727_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:23508, core=collection1, node_name=127.0.0.1:23508_}
   [junit4]   2> 1010553 T2581 C727 P23508 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:23508/collection1/
   [junit4]   2> 1010553 T2532 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1010553 T2581 C727 P23508 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 1010554 T2581 C727 P23508 oasc.SyncStrategy.syncToMe http://127.0.0.1:23508/collection1/ has no replicas
   [junit4]   2> 1010554 T2581 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:23508/collection1/ shard1
   [junit4]   2> 1010555 T2581 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 1010557 T2531 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1010558 T2531 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> 1010558 T2556 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> 1010558 T2541 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> 1010558 T2576 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> 1010562 T2532 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1010566 T2531 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1010669 T2576 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> 1010669 T2541 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> 1010669 T2556 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> 1010669 T2531 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> 1010714 T2581 oasc.ZkController.register We are http://127.0.0.1:23508/collection1/ and leader is http://127.0.0.1:23508/collection1/
   [junit4]   2> 1010714 T2581 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:23508
   [junit4]   2> 1010714 T2581 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 1010714 T2581 oasc.ZkController.publish publishing core=collection1 state=active
   [junit4]   2> 1010715 T2581 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1010716 T2531 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1010716 T2531 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1010716 T2581 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1010717 T2531 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1010718 T2532 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1010718 T2532 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:23508",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:23508_",
   [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":"2",
   [junit4]   2> 	  "core_node_name":"core_node2"}
   [junit4]   2> 1010727 T2531 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1010809 T2505 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 1010813 T2505 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:51581
   [junit4]   2> 1010813 T2505 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 1010814 T2505 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 1010814 T2505 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1388325995085
   [junit4]   2> 1010815 T2505 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1388325995085/'
   [junit4]   2> 1010829 T2531 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> 1010829 T2576 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> 1010829 T2556 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> 1010830 T2541 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> 1010856 T2505 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1388325995085/solr.xml
   [junit4]   2> 1010953 T2505 oasc.CoreContainer.<init> New CoreContainer 194518191
   [junit4]   2> 1010954 T2505 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1388325995085/]
   [junit4]   2> 1010956 T2505 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 1010957 T2505 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 1010957 T2505 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 1010958 T2505 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 1010958 T2505 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 1010959 T2505 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 1010959 T2505 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 1010960 T2505 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 1010960 T2505 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 1010979 T2505 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 1010979 T2505 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 1010980 T2505 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 1010980 T2505 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:26871/solr
   [junit4]   2> 1010981 T2505 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 1010982 T2505 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1010986 T2593 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@69e753f0 name:ZooKeeperConnection Watcher:127.0.0.1:26871 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1010986 T2505 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1010990 T2505 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1010996 T2596 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@64995a2e name:ZooKeeperConnection Watcher:127.0.0.1:26871/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1010996 T2505 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1011001 T2505 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1012005 T2505 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:51581_
   [junit4]   2> 1012007 T2505 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:51581_
   [junit4]   2> 1012012 T2556 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 1012012 T2576 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 1012012 T2541 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 1012012 T2596 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 1012012 T2531 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 1012026 T2597 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 1012027 T2597 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1012028 T2531 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1012028 T2597 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 1012029 T2531 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1012029 T2531 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1012031 T2532 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1012031 T2532 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:51581",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:51581_",
   [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":"2",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 1012032 T2532 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
   [junit4]   2> 1012032 T2532 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
   [junit4]   2> 1012035 T2531 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1012138 T2541 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> 1012138 T2576 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> 1012138 T2556 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> 1012138 T2531 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> 1012138 T2596 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> 1013030 T2597 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 1013030 T2597 oasc.CoreCont

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

  2> 1073547 T2617 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
   [junit4]   2> 1073548 T2617 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
   [junit4]   2> 1073548 T2617 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.BasicDistributedZk2Test-1388325984702/jetty4 [CachedDir<<refCount=0;path=./org.apache.solr.cloud.BasicDistributedZk2Test-1388325984702/jetty4;done=false>>]
   [junit4]   2> 1073548 T2617 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.BasicDistributedZk2Test-1388325984702/jetty4
   [junit4]   2> 1073549 T2617 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.BasicDistributedZk2Test-1388325984702/jetty4/index [CachedDir<<refCount=0;path=./org.apache.solr.cloud.BasicDistributedZk2Test-1388325984702/jetty4/index;done=false>>]
   [junit4]   2> 1073549 T2617 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.BasicDistributedZk2Test-1388325984702/jetty4/index
   [junit4]   2> 1073549 T2617 oasc.LeaderElector$1.process WARN  org.apache.solr.common.SolrException: org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer/queue
   [junit4]   2> 	at org.apache.solr.cloud.DistributedQueue.<init>(DistributedQueue.java:63)
   [junit4]   2> 	at org.apache.solr.cloud.Overseer.getInQueue(Overseer.java:1020)
   [junit4]   2> 	at org.apache.solr.cloud.ShardLeaderElectionContext.runLeaderProcess(ElectionContext.java:157)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:165)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:109)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:277)
   [junit4]   2> 	at org.apache.solr.cloud.ShardLeaderElectionContext.rejoinLeaderElection(ElectionContext.java:385)
   [junit4]   2> 	at org.apache.solr.cloud.ShardLeaderElectionContext.runLeaderProcess(ElectionContext.java:178)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:165)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:109)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:277)
   [junit4]   2> 	at org.apache.solr.cloud.ShardLeaderElectionContext.rejoinLeaderElection(ElectionContext.java:385)
   [junit4]   2> 	at org.apache.solr.cloud.ShardLeaderElectionContext.runLeaderProcess(ElectionContext.java:249)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:165)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:109)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:138)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
   [junit4]   2> Caused by: org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer/queue
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
   [junit4]   2> 	at org.apache.zookeeper.ZooKeeper.exists(ZooKeeper.java:1041)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$4.execute(SolrZkClient.java:222)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$4.execute(SolrZkClient.java:219)
   [junit4]   2> 	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:65)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient.exists(SolrZkClient.java:219)
   [junit4]   2> 	at org.apache.solr.common.cloud.ZkCmdExecutor.ensureExists(ZkCmdExecutor.java:92)
   [junit4]   2> 	at org.apache.solr.common.cloud.ZkCmdExecutor.ensureExists(ZkCmdExecutor.java:86)
   [junit4]   2> 	at org.apache.solr.cloud.DistributedQueue.<init>(DistributedQueue.java:61)
   [junit4]   2> 	... 18 more
   [junit4]   2> 
   [junit4]   2> 1073550 T2617 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> 1073551 T2617 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
   [junit4]   2> 1073551 T2617 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> 1073551 T2617 oasc.LeaderElector$1.process WARN  org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/election
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
   [junit4]   2> 	at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1468)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:256)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:253)
   [junit4]   2> 	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:65)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:253)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:93)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:138)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
   [junit4]   2> 
   [junit4]   2> NOTE: test params are: codec=CheapBastard, sim=RandomSimilarityProvider(queryNorm=false,coord=crazy): {}, locale=es_BO, timezone=Pacific/Efate
   [junit4]   2> NOTE: FreeBSD 9.1-RELEASE-p3 amd64/Oracle Corporation 1.7.0_25 (64-bit)/cpus=16,threads=1,free=112087720,total=490733568
   [junit4]   2> NOTE: All tests run in this JVM: [HardAutoCommitTest, TestDFRSimilarityFactory, NoCacheHeaderTest, TestCopyFieldCollectionResource, DirectSolrConnectionTest, QueryFacetTest, BadIndexSchemaTest, TestUtils, TestIndexingPerformance, AlternateDirectoryTest, TestZkChroot, TestFieldResource, SolrCmdDistributorTest, DocumentAnalysisRequestHandlerTest, TestBinaryResponseWriter, TestAddFieldRealTimeGet, TestNRTOpen, TestBinaryField, PreAnalyzedUpdateProcessorTest, DistributedSuggestComponentTest, TestCodecSupport, SolrPluginUtilsTest, TestCSVLoader, CoreContainerCoreInitFailuresTest, ConvertedLegacyTest, SpellCheckComponentTest, TestStressReorder, TestUniqueKeyFieldResource, TestSolr4Spatial, SignatureUpdateProcessorFactoryTest, TestSchemaNameResource, OutputWriterTest, ShardRoutingCustomTest, ConnectionManagerTest, AliasIntegrationTest, TestDistributedSearch, SolrRequestParserTest, TestRandomFaceting, TestFileDictionaryLookup, BlockCacheTest, TestAnalyzedSuggestions, TestDefaultSearchFieldResource, RAMDirectoryFactoryTest, NumericFieldsTest, TestRTGBase, StandardRequestHandlerTest, TestFuzzyAnalyzedSuggestions, ChaosMonkeySafeLeaderTest, AbstractAnalyticsStatsTest, CachingDirectoryFactoryTest, OpenCloseCoreStressTest, StressHdfsTest, BadCopyFieldTest, OpenExchangeRatesOrgProviderTest, DirectSolrSpellCheckerTest, TestFieldTypeResource, TestFastWriter, TestXIncludeConfig, TestFoldingMultitermQuery, TestCollationField, TestManagedSchemaFieldResource, TestHashPartitioner, TestLazyCores, TestIBSimilarityFactory, RequestHandlersTest, TestJmxIntegration, ChaosMonkeyNothingIsSafeTest, FieldFacetExtrasTest, HighlighterConfigTest, CurrencyFieldXmlFileTest, SpellingQueryConverterTest, DateFieldTest, TestSolrXmlPersistence, TestPhraseSuggestions, PathHierarchyTokenizerFactoryTest, DeleteInactiveReplicaTest, TestUpdate, TestStressUserVersions, TestImplicitCoreProperties, CurrencyFieldOpenExchangeTest, AddBlockUpdateTest, FileUtilsTest, DisMaxRequestHandlerTest, DistanceFunctionTest, BasicDistributedZk2Test]
   [junit4] Completed on J1 in 74.28s, 1 test, 1 error <<< FAILURES!

[...truncated 566 lines...]
BUILD FAILED
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/build.xml:453: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/build.xml:433: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/build.xml:39: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/extra-targets.xml:37: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build.xml:189: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/common-build.xml:491: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/lucene/common-build.xml:1304: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/lucene/common-build.xml:937: There were test failures: 358 suites, 1574 tests, 1 error, 35 ignored (6 assumptions)

Total time: 64 minutes 28 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure



Mime
View raw message