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 # 4163 - Failure
Date Sun, 21 Jul 2013 20:53:27 GMT
Build: https://builds.apache.org/job/Lucene-Solr-Tests-trunk-Java7/4163/

2 tests failed.
FAILED:  junit.framework.TestSuite.org.apache.solr.cloud.BasicDistributedZkTest

Error Message:
1 thread leaked from SUITE scope at org.apache.solr.cloud.BasicDistributedZkTest:     1) Thread[id=2759, name=recoveryCmdExecutor-1327-thread-1, state=RUNNABLE, group=TGRP-BasicDistributedZkTest]         at java.net.PlainSocketImpl.socketConnect(Native Method)         at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:339)         at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:200)         at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:182)         at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:391)         at java.net.Socket.connect(Socket.java:579)         at org.apache.http.conn.scheme.PlainSocketFactory.connectSocket(PlainSocketFactory.java:127)         at org.apache.http.impl.conn.DefaultClientConnectionOperator.openConnection(DefaultClientConnectionOperator.java:180)         at org.apache.http.impl.conn.ManagedClientConnectionImpl.open(ManagedClientConnectionImpl.java:294)         at org.apache.http.impl.client.DefaultRequestDirector.tryConnect(DefaultRequestDirector.java:645)         at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:480)         at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:906)         at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:805)         at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:784)         at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:365)         at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:180)         at org.apache.solr.cloud.SyncStrategy$1.run(SyncStrategy.java:291)         at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)         at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)         at java.lang.Thread.run(Thread.java:722)

Stack Trace:
com.carrotsearch.randomizedtesting.ThreadLeakError: 1 thread leaked from SUITE scope at org.apache.solr.cloud.BasicDistributedZkTest: 
   1) Thread[id=2759, name=recoveryCmdExecutor-1327-thread-1, state=RUNNABLE, group=TGRP-BasicDistributedZkTest]
        at java.net.PlainSocketImpl.socketConnect(Native Method)
        at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:339)
        at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:200)
        at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:182)
        at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:391)
        at java.net.Socket.connect(Socket.java:579)
        at org.apache.http.conn.scheme.PlainSocketFactory.connectSocket(PlainSocketFactory.java:127)
        at org.apache.http.impl.conn.DefaultClientConnectionOperator.openConnection(DefaultClientConnectionOperator.java:180)
        at org.apache.http.impl.conn.ManagedClientConnectionImpl.open(ManagedClientConnectionImpl.java:294)
        at org.apache.http.impl.client.DefaultRequestDirector.tryConnect(DefaultRequestDirector.java:645)
        at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:480)
        at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:906)
        at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:805)
        at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:784)
        at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:365)
        at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:180)
        at org.apache.solr.cloud.SyncStrategy$1.run(SyncStrategy.java:291)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
        at java.lang.Thread.run(Thread.java:722)
	at __randomizedtesting.SeedInfo.seed([CE9EC1F579D24215]:0)


FAILED:  junit.framework.TestSuite.org.apache.solr.cloud.BasicDistributedZkTest

Error Message:
There are still zombie threads that couldn't be terminated:    1) Thread[id=2759, name=recoveryCmdExecutor-1327-thread-1, state=RUNNABLE, group=TGRP-BasicDistributedZkTest]         at java.net.PlainSocketImpl.socketConnect(Native Method)         at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:339)         at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:200)         at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:182)         at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:391)         at java.net.Socket.connect(Socket.java:579)         at org.apache.http.conn.scheme.PlainSocketFactory.connectSocket(PlainSocketFactory.java:127)         at org.apache.http.impl.conn.DefaultClientConnectionOperator.openConnection(DefaultClientConnectionOperator.java:180)         at org.apache.http.impl.conn.ManagedClientConnectionImpl.open(ManagedClientConnectionImpl.java:294)         at org.apache.http.impl.client.DefaultRequestDirector.tryConnect(DefaultRequestDirector.java:645)         at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:480)         at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:906)         at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:805)         at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:784)         at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:365)         at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:180)         at org.apache.solr.cloud.SyncStrategy$1.run(SyncStrategy.java:291)         at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)         at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)         at java.lang.Thread.run(Thread.java:722)

Stack Trace:
com.carrotsearch.randomizedtesting.ThreadLeakError: There are still zombie threads that couldn't be terminated:
   1) Thread[id=2759, name=recoveryCmdExecutor-1327-thread-1, state=RUNNABLE, group=TGRP-BasicDistributedZkTest]
        at java.net.PlainSocketImpl.socketConnect(Native Method)
        at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:339)
        at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:200)
        at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:182)
        at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:391)
        at java.net.Socket.connect(Socket.java:579)
        at org.apache.http.conn.scheme.PlainSocketFactory.connectSocket(PlainSocketFactory.java:127)
        at org.apache.http.impl.conn.DefaultClientConnectionOperator.openConnection(DefaultClientConnectionOperator.java:180)
        at org.apache.http.impl.conn.ManagedClientConnectionImpl.open(ManagedClientConnectionImpl.java:294)
        at org.apache.http.impl.client.DefaultRequestDirector.tryConnect(DefaultRequestDirector.java:645)
        at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:480)
        at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:906)
        at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:805)
        at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:784)
        at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:365)
        at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:180)
        at org.apache.solr.cloud.SyncStrategy$1.run(SyncStrategy.java:291)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
        at java.lang.Thread.run(Thread.java:722)
	at __randomizedtesting.SeedInfo.seed([CE9EC1F579D24215]:0)




Build Log:
[...truncated 9651 lines...]
   [junit4] Suite: org.apache.solr.cloud.BasicDistributedZkTest
   [junit4]   2> 1239091 T2315 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /i_u/c
   [junit4]   2> 1239095 T2315 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/J0/./solrtest-BasicDistributedZkTest-1374439712923
   [junit4]   2> 1239097 T2315 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   2> 1239097 T2316 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 1239198 T2315 oasc.ZkTestServer.run start zk server on port:33125
   [junit4]   2> 1239199 T2315 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1239228 T2322 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3f174eb4 name:ZooKeeperConnection Watcher:127.0.0.1:33125 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1239229 T2315 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1239229 T2315 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 1239239 T2315 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1239241 T2324 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2905d969 name:ZooKeeperConnection Watcher:127.0.0.1:33125/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1239241 T2315 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1239241 T2315 oascc.SolrZkClient.makePath makePath: /collections/collection1
   [junit4]   2> 1239245 T2315 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
   [junit4]   2> 1239247 T2315 oascc.SolrZkClient.makePath makePath: /collections/control_collection
   [junit4]   2> 1239255 T2315 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
   [junit4]   2> 1239258 T2315 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> 1239258 T2315 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
   [junit4]   2> 1239271 T2315 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> 1239272 T2315 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
   [junit4]   2> 1239401 T2315 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> 1239403 T2315 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
   [junit4]   2> 1239406 T2315 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> 1239407 T2315 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
   [junit4]   2> 1239410 T2315 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> 1239411 T2315 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
   [junit4]   2> 1239414 T2315 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> 1239414 T2315 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
   [junit4]   2> 1239417 T2315 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> 1239418 T2315 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 1239421 T2315 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> 1239422 T2315 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
   [junit4]   2> 1239430 T2315 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> 1239431 T2315 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
   [junit4]   2> 1239717 T2315 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 1239724 T2315 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:16941
   [junit4]   2> 1239725 T2315 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 1239725 T2315 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 1239726 T2315 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/J0/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374439713263
   [junit4]   2> 1239727 T2315 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374439713263/'
   [junit4]   2> 1239765 T2315 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374439713263/solr.xml
   [junit4]   2> 1239857 T2315 oasc.CoreContainer.<init> New CoreContainer 1627881979
   [junit4]   2> 1239857 T2315 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374439713263/]
   [junit4]   2> 1239859 T2315 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 1239860 T2315 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 1239861 T2315 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 1239861 T2315 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 1239862 T2315 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 1239862 T2315 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 1239863 T2315 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 1239863 T2315 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 1239864 T2315 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 1239864 T2315 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
   [junit4]   2> 1239880 T2315 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 1239881 T2315 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:33125/solr
   [junit4]   2> 1239881 T2315 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 1239883 T2315 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1239885 T2335 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1e6faf02 name:ZooKeeperConnection Watcher:127.0.0.1:33125 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1239885 T2315 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1239888 T2315 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
   [junit4]   2> 1239895 T2315 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1239897 T2337 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@20e0b471 name:ZooKeeperConnection Watcher:127.0.0.1:33125/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1239897 T2315 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1239900 T2315 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 1239909 T2315 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 1239913 T2315 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 1239920 T2315 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:16941_i_u%2Fc
   [junit4]   2> 1239921 T2315 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:16941_i_u%2Fc
   [junit4]   2> 1239925 T2315 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 1239944 T2315 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 1239947 T2315 oasc.Overseer.start Overseer (id=90075281026580483-127.0.0.1:16941_i_u%2Fc-n_0000000000) starting
   [junit4]   2> 1239959 T2315 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 1239968 T2339 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 1239969 T2315 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 1239972 T2315 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 1239974 T2315 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1239976 T2338 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 1239982 T2340 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 1239982 T2340 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1239984 T2340 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 1241480 T2338 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1241482 T2338 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "core_node_name":"core_node1",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "collection":"control_collection",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:16941_i_u%2Fc",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:16941/i_u/c"}
   [junit4]   2> 1241482 T2338 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with numShards 1
   [junit4]   2> 1241482 T2338 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 1241499 T2337 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> 1241986 T2340 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 1241986 T2340 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374439713263/collection1
   [junit4]   2> 1241986 T2340 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
   [junit4]   2> 1241987 T2340 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 1241988 T2340 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
   [junit4]   2> 1241989 T2340 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374439713263/collection1/'
   [junit4]   2> 1241991 T2340 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374439713263/collection1/lib/README' to classloader
   [junit4]   2> 1241991 T2340 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374439713263/collection1/lib/classes/' to classloader
   [junit4]   2> 1242054 T2340 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 1242124 T2340 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 1242225 T2340 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 1242239 T2340 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 1242901 T2340 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 1242916 T2340 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 1242920 T2340 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 1242937 T2340 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1242942 T2340 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1242946 T2340 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1242947 T2340 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1242947 T2340 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1242948 T2340 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1242948 T2340 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1242949 T2340 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1242949 T2340 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 1242949 T2340 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374439713263/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZkTest-1374439712923/control/data/
   [junit4]   2> 1242950 T2340 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@71008045
   [junit4]   2> 1242951 T2340 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374439712923/control/data
   [junit4]   2> 1242951 T2340 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZkTest-1374439712923/control/data/index/
   [junit4]   2> 1242951 T2340 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZkTest-1374439712923/control/data/index' doesn't exist. Creating new index...
   [junit4]   2> 1242952 T2340 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374439712923/control/data/index
   [junit4]   2> 1242956 T2340 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@52d2fa63 lockFactory=org.apache.lucene.store.NativeFSLockFactory@506ad72f),segFN=segments_1,generation=1}
   [junit4]   2> 1242956 T2340 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1242961 T2340 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 1242962 T2340 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1242962 T2340 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1242963 T2340 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 1242964 T2340 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 1242964 T2340 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 1242964 T2340 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 1242965 T2340 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 1242965 T2340 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 1242980 T2340 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 1242987 T2340 oass.SolrIndexSearcher.<init> Opening Searcher@5713a4a2 main
   [junit4]   2> 1242988 T2340 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 1242989 T2340 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 1242992 T2341 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@5713a4a2 main{StandardDirectoryReader(segments_1:1)}
   [junit4]   2> 1242994 T2340 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 1242994 T2340 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:16941/i_u/c collection:control_collection shard:shard1
   [junit4]   2> 1242994 T2340 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=30000&socketTimeout=30000&retry=false
   [junit4]   2> 1243011 T2340 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
   [junit4]   2> 1243032 T2340 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 1243034 T2340 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 1243035 T2340 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> 1243035 T2340 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:16941/i_u/c/collection1/
   [junit4]   2> 1243035 T2340 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 1243035 T2340 oasc.SyncStrategy.syncToMe http://127.0.0.1:16941/i_u/c/collection1/ has no replicas
   [junit4]   2> 1243035 T2340 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:16941/i_u/c/collection1/ shard1
   [junit4]   2> 1243036 T2340 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
   [junit4]   2> 1244505 T2338 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1244535 T2337 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> 1244572 T2340 oasc.ZkController.register We are http://127.0.0.1:16941/i_u/c/collection1/ and leader is http://127.0.0.1:16941/i_u/c/collection1/
   [junit4]   2> 1244572 T2340 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:16941/i_u/c
   [junit4]   2> 1244572 T2340 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 1244572 T2340 oasc.ZkController.publish publishing core=collection1 state=active
   [junit4]   2> 1244573 T2340 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1244575 T2340 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1244576 T2315 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0
   [junit4]   2> 1244577 T2315 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 1244577 T2315 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> 1244590 T2315 oascsi.HttpClientUtil.createClient Creating new http client, config:
   [junit4]   2> 1244591 T2315 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1244594 T2344 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@48ab5a2b name:ZooKeeperConnection Watcher:127.0.0.1:33125/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1244594 T2315 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1244596 T2315 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1244598 T2315 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
   [junit4]   2> 1244884 T2315 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 1244887 T2315 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:52128
   [junit4]   2> 1244888 T2315 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 1244888 T2315 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 1244889 T2315 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/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374439718426
   [junit4]   2> 1244889 T2315 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374439718426/'
   [junit4]   2> 1244927 T2315 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374439718426/solr.xml
   [junit4]   2> 1245032 T2315 oasc.CoreContainer.<init> New CoreContainer 732526369
   [junit4]   2> 1245032 T2315 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374439718426/]
   [junit4]   2> 1245034 T2315 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 1245035 T2315 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 1245035 T2315 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 1245036 T2315 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 1245036 T2315 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 1245037 T2315 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 1245037 T2315 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 1245038 T2315 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 1245038 T2315 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 1245039 T2315 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
   [junit4]   2> 1245054 T2315 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 1245055 T2315 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:33125/solr
   [junit4]   2> 1245056 T2315 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 1245057 T2315 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1245059 T2355 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@844e790 name:ZooKeeperConnection Watcher:127.0.0.1:33125 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1245060 T2315 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1245062 T2315 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
   [junit4]   2> 1245073 T2315 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1245075 T2357 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@333230dc name:ZooKeeperConnection Watcher:127.0.0.1:33125/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1245075 T2315 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1245087 T2315 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1246040 T2338 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1246042 T2338 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "core_node_name":"core_node1",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "collection":"control_collection",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:16941_i_u%2Fc",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:16941/i_u/c"}
   [junit4]   2> 1246056 T2337 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> 1246056 T2344 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> 1246056 T2357 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> 1246091 T2315 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:52128_i_u%2Fc
   [junit4]   2> 1246093 T2315 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:52128_i_u%2Fc
   [junit4]   2> 1246095 T2357 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 1)
   [junit4]   2> 1246096 T2337 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 1246096 T2344 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 1246096 T2337 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 1246096 T2344 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 1246097 T2357 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 1246111 T2358 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 1246112 T2358 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1246113 T2358 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 1247561 T2338 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1247563 T2338 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "core_node_name":"core_node1",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:52128_i_u%2Fc",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:52128/i_u/c"}
   [junit4]   2> 1247563 T2338 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with numShards 2
   [junit4]   2> 1247563 T2338 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 1247584 T2337 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> 1247584 T2357 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> 1247584 T2344 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> 1248115 T2358 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 1248115 T2358 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374439718426/collection1
   [junit4]   2> 1248115 T2358 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 1248116 T2358 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 1248117 T2358 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 1248118 T2358 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374439718426/collection1/'
   [junit4]   2> 1248119 T2358 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374439718426/collection1/lib/README' to classloader
   [junit4]   2> 1248120 T2358 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374439718426/collection1/lib/classes/' to classloader
   [junit4]   2> 1248183 T2358 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 1248253 T2358 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 1248355 T2358 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 1248369 T2358 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 1248996 T2358 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 1249006 T2358 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 1249008 T2358 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 1249022 T2358 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1249025 T2358 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1249029 T2358 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1249030 T2358 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1249030 T2358 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1249030 T2358 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1249031 T2358 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1249031 T2358 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1249032 T2358 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 1249032 T2358 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374439718426/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZkTest-1374439712923/jetty1/
   [junit4]   2> 1249032 T2358 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@71008045
   [junit4]   2> 1249033 T2358 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374439712923/jetty1
   [junit4]   2> 1249033 T2358 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZkTest-1374439712923/jetty1/index/
   [junit4]   2> 1249033 T2358 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZkTest-1374439712923/jetty1/index' doesn't exist. Creating new index...
   [junit4]   2> 1249034 T2358 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374439712923/jetty1/index
   [junit4]   2> 1249036 T2358 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@4fb0374a lockFactory=org.apache.lucene.store.NativeFSLockFactory@73a118bc),segFN=segments_1,generation=1}
   [junit4]   2> 1249037 T2358 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1249041 T2358 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 1249041 T2358 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1249042 T2358 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1249042 T2358 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 1249043 T2358 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 1249043 T2358 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 1249043 T2358 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 1249043 T2358 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 1249044 T2358 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 1249054 T2358 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 1249059 T2358 oass.SolrIndexSearcher.<init> Opening Searcher@65f5d6e0 main
   [junit4]   2> 1249060 T2358 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 1249060 T2358 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 1249064 T2359 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@65f5d6e0 main{StandardDirectoryReader(segments_1:1)}
   [junit4]   2> 1249066 T2358 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 1249066 T2358 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:52128/i_u/c collection:collection1 shard:shard1
   [junit4]   2> 1249066 T2358 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=30000&socketTimeout=30000&retry=false
   [junit4]   2> 1249078 T2358 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 1249114 T2358 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 1249125 T2358 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 1249126 T2358 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> 1249126 T2358 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:52128/i_u/c/collection1/
   [junit4]   2> 1249126 T2358 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 1249126 T2358 oasc.SyncStrategy.syncToMe http://127.0.0.1:52128/i_u/c/collection1/ has no replicas
   [junit4]   2> 1249127 T2358 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:52128/i_u/c/collection1/ shard1
   [junit4]   2> 1249127 T2358 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 1250603 T2338 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1250619 T2337 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> 1250619 T2344 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> 1250619 T2357 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> 1250663 T2358 oasc.ZkController.register We are http://127.0.0.1:52128/i_u/c/collection1/ and leader is http://127.0.0.1:52128/i_u/c/collection1/
   [junit4]   2> 1250663 T2358 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:52128/i_u/c
   [junit4]   2> 1250663 T2358 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 1250663 T2358 oasc.ZkController.publish publishing core=collection1 state=active
   [junit4]   2> 1250664 T2358 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1250666 T2358 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1250667 T2315 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0
   [junit4]   2> 1250667 T2315 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 1250668 T2315 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> 1250954 T2315 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 1250957 T2315 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:58870
   [junit4]   2> 1250958 T2315 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 1250958 T2315 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 1250959 T2315 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/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374439724507
   [junit4]   2> 1250959 T2315 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374439724507/'
   [junit4]   2> 1250997 T2315 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374439724507/solr.xml
   [junit4]   2> 1251088 T2315 oasc.CoreContainer.<init> New CoreContainer 186115700
   [junit4]   2> 1251089 T2315 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374439724507/]
   [junit4]   2> 1251091 T2315 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 1251091 T2315 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 1251092 T2315 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 1251092 T2315 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 1251093 T2315 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 1251093 T2315 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 1251094 T2315 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 1251094 T2315 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 1251095 T2315 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 1251095 T2315 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
   [junit4]   2> 1251113 T2315 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 1251113 T2315 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:33125/solr
   [junit4]   2> 1251114 T2315 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 1251115 T2315 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1251118 T2371 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3b662051 name:ZooKeeperConnection Watcher:127.0.0.1:33125 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1251118 T2315 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1251130 T2315 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
   [junit4]   2> 1251141 T2315 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1251144 T2373 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5092067d name:ZooKeeperConnection Watcher:127.0.0.1:33125/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1251144 T2315 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1251150 T2315 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1252131 T2338 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1252133 T2338 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "core_node_name":"core_node1",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:52128_i_u%2Fc",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:52128/i_u/c"}
   [junit4]   2> 1252169 T2315 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:58870_i_u%2Fc
   [junit4]   2> 1252171 T2357 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> 1252171 T2344 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> 1252171 T2373 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> 1252171 T2337 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> 1252249 T2315 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:58870_i_u%2Fc
   [junit4]   2> 1252277 T2357 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 1252278 T2344 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 1252278 T2373 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 1252278 T2344 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 1252278 T2337 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 1252279 T2373 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 1252279 T2337 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 1252279 T2357 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 1252287 T2374 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 1252288 T2374 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1252290 T2374 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 1253753 T2338 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1253755 T2338 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "core_node_name":"core_node2",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:58870_i_u%2Fc",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:58870/i_u/c"}
   [junit4]   2> 1253755 T2338 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
   [junit4]   2> 1253755 T2338 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
   [junit4]   2> 1253781 T2357 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> 1253781 T2344 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> 1253781 T2337 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> 1253781 T2373 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> 1254292 T2374 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 1254292 T2374 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374439724507/collection1
   [junit4]   2> 1254292 T2374 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 1254293 T2374 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 1254294 T2374 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 1254295 T2374 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374439724507/collection1/'
   [junit4]   2> 1254296 T2374 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374439724507/collection1/lib/README' to classloader
   [junit4]   2> 1254297 T2374 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374439724507/collection1/lib/classes/' to classloader
   [junit4]   2> 1254354 T2374 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 1254433 T2374 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 1254534 T2374 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 1254547 T2374 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 1255173 T2374 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 1255187 T2374 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 1255191 T2374 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 1255207 T2374 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1255212 T2374 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1255217 T2374 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1255218 T2374 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1255218 T2374 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1255218 T2374 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1255219 T2374 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1255220 T2374 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1255220 T2374 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 1255220 T2374 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374439724507/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZkTest-1374439712923/jetty2/
   [junit4]   2> 1255221 T2374 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@71008045
   [junit4]   2> 1255222 T2374 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374439712923/jetty2
   [junit4]   2> 1255222 T2374 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZkTest-1374439712923/jetty2/index/
   [junit4]   2> 1255222 T2374 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZkTest-1374439712923/jetty2/index' doesn't exist. Creating new index...
   [junit4]   2> 1255223 T2374 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374439712923/jetty2/index
   [junit4]   2> 1255227 T2374 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@7d478a7f lockFactory=org.apache.lucene.store.NativeFSLockFactory@422426fb),segFN=segments_1,generation=1}
   [junit4]   2> 1255227 T2374 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1255233 T2374 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 1255233 T2374 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1255234 T2374 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1255235 T2374 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 1255236 T2374 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 1255236 T2374 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 1255236 T2374 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 1255237 T2374 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 1255238 T2374 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 1255254 T2374 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 1255261 T2374 oass.SolrIndexSearcher.<init> Opening Searcher@54c96476 main
   [junit4]   2> 1255263 T2374 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 1255263 T2374 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 1255268 T2375 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@54c96476 main{StandardDirectoryReader(segments_1:1)}
   [junit4]   2> 1255270 T2374 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 1255271 T2374 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:58870/i_u/c collection:collection1 shard:shard2
   [junit4]   2> 1255271 T2374 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=30000&socketTimeout=30000&retry=false
   [junit4]   2> 1255289 T2374 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
   [junit4]   2> 1255302 T2374 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
   [junit4]   2> 1255310 T2374 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 1255310 T2374 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> 1255311 T2374 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:58870/i_u/c/collection1/
   [junit4]   2> 1255311 T2374 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 1255311 T2374 oasc.SyncStrategy.syncToMe http://127.0.0.1:58870/i_u/c/collection1/ has no replicas
   [junit4]   2> 1255311 T2374 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:58870/i_u/c/collection1/ shard2
   [junit4]   2> 1255312 T2374 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
   [junit4]   2> 1256793 T2338 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1256804 T2337 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> 1256804 T2344 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> 1256804 T2373 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> 1256804 T2357 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> 1256855 T2374 oasc.ZkController.register We are http://127.0.0.1:58870/i_u/c/collection1/ and leader is http://127.0.0.1:58870/i_u/c/collection1/
   [junit4]   2> 1256855 T2374 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:58870/i_u/c
   [junit4]   2> 1256855 T2374 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 1256856 T2374 oasc.ZkController.publish publishing core=collection1 state=active
   [junit4]   2> 1256856 T2374 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1256858 T2374 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1256859 T2315 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0
   [junit4]   2> 1256860 T2315 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 1256860 T2315 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> 1257155 T2315 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 1257157 T2315 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:65079
   [junit4]   2> 1257158 T2315 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 1257159 T2315 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 1257159 T2315 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/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374439730697
   [junit4]   2> 1257160 T2315 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374439730697/'
   [junit4]   2> 1257198 T2315 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374439730697/solr.xml
   [junit4]   2> 1257288 T2315 oasc.CoreContainer.<init> New CoreContainer 131368618
   [junit4]   2> 1257289 T2315 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374439730697/]
   [junit4]   2> 1257291 T2315 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 1257291 T2315 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 1257292 T2315 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 1257292 T2315 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 1257293 T2315 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 1257293 T2315 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 1257294 T2315 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 1257294 T2315 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 1257295 T2315 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 1257295 T2315 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
   [junit4]   2> 1257311 T2315 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 1257311 T2315 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:33125/solr
   [junit4]   2> 1257312 T2315 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 1257313 T2315 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1257321 T2387 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7710ff84 name:ZooKeeperConnection Watcher:127.0.0.1:33125 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1257321 T2315 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1257337 T2315 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
   [junit4]   2> 1257348 T2315 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1257350 T2389 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@e501b2b name:ZooKeeperConnection Watcher:127.0.0.1:33125/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1257350 T2315 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1257362 T2315 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1258309 T2338 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1258311 T2338 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "core_node_name":"core_node2",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "shard":"shard2",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:58870_i_u%2Fc",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:58870/i_u/c"}
   [junit4]   2> 1258342 T2389 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> 1258342 T2344 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> 1258342 T2373 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> 1258342 T2337 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> 1258342 T2357 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> 1258365 T2315 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:65079_i_u%2Fc
   [junit4]   2> 1258367 T2315 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:65079_i_u%2Fc
   [junit4]   2> 1258374 T2357 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 1258374 T2344 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 1258375 T2389 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 1258375 T2337 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 1258375 T2389 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
   [junit4]   2> 1258375 T2344 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
   [junit4]   2> 1258375 T2373 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 1258375 T2337 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
   [junit4]   2> 1258376 T2373 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
   [junit4]   2> 1258376 T2357 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 1258385 T2390 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 1258385 T2390 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1258387 T2390 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 1259852 T2338 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1259854 T2338 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "core_node_name":"core_node3",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:65079_i_u%2Fc",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:65079/i_u/c"}
   [junit4]   2> 1259854 T2338 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
   [junit4]   2> 1259854 T2338 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 1259869 T2389 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> 1259869 T2344 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> 1259869 T2373 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> 1259869 T2337 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> 1259869 T2357 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> 1260389 T2390 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 1260389 T2390 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374439730697/collection1
   [junit4]   2> 1260389 T2390 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 1260390 T2390 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 1260391 T2390 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 1260392 T2390 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374439730697/collection1/'
   [junit4]   2> 1260393 T2390 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374439730697/collection1/lib/README' to classloader
   [junit4]   2> 1260394 T2390 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374439730697/collection1/lib/classes/' to classloader
   [junit4]   2> 1260457 T2390 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 1260525 T2390 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 1260626 T2390 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 1260639 T2390 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 1261322 T2390 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 1261337 T2390 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 1261341 T2390 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 1261357 T2390 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1261363 T2390 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1261382 T2390 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1261384 T2390 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1261384 T2390 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1261385 T2390 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1261386 T2390 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1261386 T2390 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1261386 T2390 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 1261387 T2390 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374439730697/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZkTest-1374439712923/jetty3/
   [junit4]   2> 1261387 T2390 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@71008045
   [junit4]   2> 1261388 T2390 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374439712923/jetty3
   [junit4]   2> 1261388 T2390 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZkTest-1374439712923/jetty3/index/
   [junit4]   2> 1261389 T2390 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZkTest-1374439712923/jetty3/index' doesn't exist. Creating new index...
   [junit4]   2> 1261389 T2390 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374439712923/jetty3/index
   [junit4]   2> 1261393 T2390 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@2868f2da lockFactory=org.apache.lucene.store.NativeFSLockFactory@3c7f058a),segFN=segments_1,generation=1}
   [junit4]   2> 1261394 T2390 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1261400 T2390 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 1261400 T2390 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1261401 T2390 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1261402 T2390 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 1261403 T2390 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 1261403 T2390 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 1261403 T2390 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 1261404 T2390 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 1261404 T2390 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 1261422 T2390 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 1261430 T2390 oass.SolrIndexSearcher.<init> Opening Searcher@374f5449 main
   [junit4]   2> 1261432 T2390 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 1261432 T2390 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 1261437 T2391 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@374f5449 main{StandardDirectoryReader(segments_1:1)}
   [junit4]   2> 1261440 T2390 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 1261440 T2390 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:65079/i_u/c collection:collection1 shard:shard1
   [junit4]   2> 1261440 T2390 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=30000&socketTimeout=30000&retry=false
   [junit4]   2> 1261462 T2390 oasc.ZkController.register We are http://127.0.0.1:65079/i_u/c/collection1/ and leader is http://127.0.0.1:52128/i_u/c/collection1/
   [junit4]   2> 1261462 T2390 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:65079/i_u/c
   [junit4]   2> 1261462 T2390 oasc.ZkController.checkRecovery Core needs to recover:collection1
   [junit4]   2> 1261463 T2390 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
   [junit4]   2> ASYNC  NEW_CORE C720 name=collection1 org.apache.solr.core.SolrCore@2a70f6c9 url=http://127.0.0.1:65079/i_u/c/collection1 node=127.0.0.1:65079_i_u%2Fc C720_STATE=coll:collection1 core:collection1 props:{state=down, core=collection1, node_name=127.0.0.1:65079_i_u%2Fc, base_url=http://127.0.0.1:65079/i_u/c}
   [junit4]   2> 1261463 T2392 C720 P65079 oasc.RecoveryStrategy.run Starting recovery process.  core=collection1 recoveringAfterStartup=true
   [junit4]   2> 1261464 T2392 C720 P65079 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
   [junit4]   2> 1261464 T2390 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1261464 T2392 C720 P65079 oasc.ZkController.publish publishing core=collection1 state=recovering
   [junit4]   2> 1261464 T2392 C720 P65079 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1261465 T2315 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0
   [junit4]   2> 1261466 T2315 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 1261466 T2392 C720 P65079 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> 1261467 T2315 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> 1261481 T2347 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: core_node3, state: recovering, checkLive: true, onlyIfLeader: true
   [junit4]   2> 1261794 T2315 oejs.Server.doStart jetty-8.1.10.v201303

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

   [junit4]   2> 	        at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:182)
   [junit4]   2> 	        at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:391)
   [junit4]   2> 	        at java.net.Socket.connect(Socket.java:579)
   [junit4]   2> 	        at org.apache.http.conn.scheme.PlainSocketFactory.connectSocket(PlainSocketFactory.java:127)
   [junit4]   2> 	        at org.apache.http.impl.conn.DefaultClientConnectionOperator.openConnection(DefaultClientConnectionOperator.java:180)
   [junit4]   2> 	        at org.apache.http.impl.conn.ManagedClientConnectionImpl.open(ManagedClientConnectionImpl.java:294)
   [junit4]   2> 	        at org.apache.http.impl.client.DefaultRequestDirector.tryConnect(DefaultRequestDirector.java:645)
   [junit4]   2> 	        at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:480)
   [junit4]   2> 	        at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:906)
   [junit4]   2> 	        at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:805)
   [junit4]   2> 	        at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:784)
   [junit4]   2> 	        at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:365)
   [junit4]   2> 	        at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:180)
   [junit4]   2> 	        at org.apache.solr.cloud.SyncStrategy$1.run(SyncStrategy.java:291)
   [junit4]   2> 	        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
   [junit4]   2> 	        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
   [junit4]   2> 	        at java.lang.Thread.run(Thread.java:722)
   [junit4]   2> NOTE: test params are: codec=CheapBastard, sim=RandomSimilarityProvider(queryNorm=true,coord=crazy): {}, locale=zh_CN, timezone=America/Chihuahua
   [junit4]   2> NOTE: FreeBSD 9.1-RELEASE-p3 amd64/Oracle Corporation 1.7.0_21 (64-bit)/cpus=16,threads=2,free=130353480,total=382730240
   [junit4]   2> NOTE: All tests run in this JVM: [IndexSchemaTest, DistributedQueryElevationComponentTest, TestJoin, SpellingQueryConverterTest, SolrInfoMBeanTest, StressHdfsTest, QueryEqualityTest, TermsComponentTest, TestSolrQueryParser, AssignTest, TestPHPSerializedResponseWriter, UnloadDistributedZkTest, TestDynamicFieldResource, TestSolrXmlPersistence, WordBreakSolrSpellCheckerTest, LegacyHTMLStripCharFilterTest, ClusterStateUpdateTest, TestTrie, ResourceLoaderTest, ZkCLITest, TestPropInjectDefaults, TestWriterPerf, SyncSliceTest, MoreLikeThisHandlerTest, TestLMDirichletSimilarityFactory, SynonymTokenizerTest, TestReplicationHandler, ShardRoutingTest, TestSearchPerf, SuggesterTest, TestFuzzyAnalyzedSuggestions, ZkControllerTest, MinimalSchemaTest, SystemInfoHandlerTest, ShowFileRequestHandlerTest, ChaosMonkeyNothingIsSafeTest, UpdateRequestProcessorFactoryTest, TestSolrCoreProperties, TestFieldTypeCollectionResource, DirectSolrConnectionTest, AutoCommitTest, BinaryUpdateRequestHandlerTest, AddSchemaFieldsUpdateProcessorFactoryTest, SimpleFacetsTest, TestSerializedLuceneMatchVersion, TestPluginEnable, TestSolrQueryParserResource, RAMDirectoryFactoryTest, BasicFunctionalityTest, TestSort, BasicDistributedZkTest]
   [junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=BasicDistributedZkTest -Dtests.seed=CE9EC1F579D24215 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=zh_CN -Dtests.timezone=America/Chihuahua -Dtests.file.encoding=US-ASCII
   [junit4] ERROR   0.00s J0 | BasicDistributedZkTest (suite) <<<
   [junit4]    > Throwable #1: com.carrotsearch.randomizedtesting.ThreadLeakError: 1 thread leaked from SUITE scope at org.apache.solr.cloud.BasicDistributedZkTest: 
   [junit4]    >    1) Thread[id=2759, name=recoveryCmdExecutor-1327-thread-1, state=RUNNABLE, group=TGRP-BasicDistributedZkTest]
   [junit4]    >         at java.net.PlainSocketImpl.socketConnect(Native Method)
   [junit4]    >         at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:339)
   [junit4]    >         at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:200)
   [junit4]    >         at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:182)
   [junit4]    >         at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:391)
   [junit4]    >         at java.net.Socket.connect(Socket.java:579)
   [junit4]    >         at org.apache.http.conn.scheme.PlainSocketFactory.connectSocket(PlainSocketFactory.java:127)
   [junit4]    >         at org.apache.http.impl.conn.DefaultClientConnectionOperator.openConnection(DefaultClientConnectionOperator.java:180)
   [junit4]    >         at org.apache.http.impl.conn.ManagedClientConnectionImpl.open(ManagedClientConnectionImpl.java:294)
   [junit4]    >         at org.apache.http.impl.client.DefaultRequestDirector.tryConnect(DefaultRequestDirector.java:645)
   [junit4]    >         at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:480)
   [junit4]    >         at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:906)
   [junit4]    >         at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:805)
   [junit4]    >         at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:784)
   [junit4]    >         at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:365)
   [junit4]    >         at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:180)
   [junit4]    >         at org.apache.solr.cloud.SyncStrategy$1.run(SyncStrategy.java:291)
   [junit4]    >         at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
   [junit4]    >         at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
   [junit4]    >         at java.lang.Thread.run(Thread.java:722)
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([CE9EC1F579D24215]:0)Throwable #2: com.carrotsearch.randomizedtesting.ThreadLeakError: There are still zombie threads that couldn't be terminated:
   [junit4]    >    1) Thread[id=2759, name=recoveryCmdExecutor-1327-thread-1, state=RUNNABLE, group=TGRP-BasicDistributedZkTest]
   [junit4]    >         at java.net.PlainSocketImpl.socketConnect(Native Method)
   [junit4]    >         at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:339)
   [junit4]    >         at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:200)
   [junit4]    >         at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:182)
   [junit4]    >         at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:391)
   [junit4]    >         at java.net.Socket.connect(Socket.java:579)
   [junit4]    >         at org.apache.http.conn.scheme.PlainSocketFactory.connectSocket(PlainSocketFactory.java:127)
   [junit4]    >         at org.apache.http.impl.conn.DefaultClientConnectionOperator.openConnection(DefaultClientConnectionOperator.java:180)
   [junit4]    >         at org.apache.http.impl.conn.ManagedClientConnectionImpl.open(ManagedClientConnectionImpl.java:294)
   [junit4]    >         at org.apache.http.impl.client.DefaultRequestDirector.tryConnect(DefaultRequestDirector.java:645)
   [junit4]    >         at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:480)
   [junit4]    >         at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:906)
   [junit4]    >         at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:805)
   [junit4]    >         at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:784)
   [junit4]    >         at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:365)
   [junit4]    >         at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:180)
   [junit4]    >         at org.apache.solr.cloud.SyncStrategy$1.run(SyncStrategy.java:291)
   [junit4]    >         at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
   [junit4]    >         at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
   [junit4]    >         at java.lang.Thread.run(Thread.java:722)
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([CE9EC1F579D24215]:0)
   [junit4] Completed on J0 in 225.28s, 1 test, 2 errors <<< FAILURES!

[...truncated 570 lines...]
BUILD FAILED
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/build.xml:389: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/build.xml:369: 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/solr/build.xml:181: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/common-build.xml:449: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/lucene/common-build.xml:1247: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/lucene/common-build.xml:890: There were test failures: 318 suites, 1342 tests, 2 suite-level errors, 698 ignored (5 assumptions)

Total time: 46 minutes 44 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