You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Apache Jenkins Server <je...@builds.apache.org> on 2013/07/23 04:43:43 UTC

[JENKINS] Lucene-Solr-Tests-4.x-Java6 - Build # 1820 - Failure

Build: https://builds.apache.org/job/Lucene-Solr-Tests-4.x-Java6/1820/

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=1958, name=recoveryCmdExecutor-1157-thread-1, state=RUNNABLE, group=TGRP-BasicDistributedZkTest]         at java.net.PlainSocketImpl.socketConnect(Native Method)         at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:327)         at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:193)         at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:180)         at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:384)         at java.net.Socket.connect(Socket.java:546)         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:1146)         at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)         at java.lang.Thread.run(Thread.java:679)

Stack Trace:
com.carrotsearch.randomizedtesting.ThreadLeakError: 1 thread leaked from SUITE scope at org.apache.solr.cloud.BasicDistributedZkTest: 
   1) Thread[id=1958, name=recoveryCmdExecutor-1157-thread-1, state=RUNNABLE, group=TGRP-BasicDistributedZkTest]
        at java.net.PlainSocketImpl.socketConnect(Native Method)
        at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:327)
        at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:193)
        at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:180)
        at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:384)
        at java.net.Socket.connect(Socket.java:546)
        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:1146)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
        at java.lang.Thread.run(Thread.java:679)
	at __randomizedtesting.SeedInfo.seed([1F239F44D9E6F380]: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=1958, name=recoveryCmdExecutor-1157-thread-1, state=RUNNABLE, group=TGRP-BasicDistributedZkTest]         at java.net.PlainSocketImpl.socketConnect(Native Method)         at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:327)         at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:193)         at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:180)         at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:384)         at java.net.Socket.connect(Socket.java:546)         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:1146)         at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)         at java.lang.Thread.run(Thread.java:679)

Stack Trace:
com.carrotsearch.randomizedtesting.ThreadLeakError: There are still zombie threads that couldn't be terminated:
   1) Thread[id=1958, name=recoveryCmdExecutor-1157-thread-1, state=RUNNABLE, group=TGRP-BasicDistributedZkTest]
        at java.net.PlainSocketImpl.socketConnect(Native Method)
        at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:327)
        at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:193)
        at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:180)
        at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:384)
        at java.net.Socket.connect(Socket.java:546)
        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:1146)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
        at java.lang.Thread.run(Thread.java:679)
	at __randomizedtesting.SeedInfo.seed([1F239F44D9E6F380]:0)




Build Log:
[...truncated 9319 lines...]
   [junit4] Suite: org.apache.solr.cloud.BasicDistributedZkTest
   [junit4]   2> 708934 T1477 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
   [junit4]   2> 708937 T1477 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
   [junit4]   2> Creating dataDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZkTest-1374546922719
   [junit4]   2> 708938 T1477 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   2> 708938 T1478 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 709039 T1477 oasc.ZkTestServer.run start zk server on port:32604
   [junit4]   2> 709040 T1477 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 709047 T1484 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@61d7499d name:ZooKeeperConnection Watcher:127.0.0.1:32604 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 709047 T1477 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 709047 T1477 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 709051 T1477 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 709061 T1486 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2112b320 name:ZooKeeperConnection Watcher:127.0.0.1:32604/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 709061 T1477 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 709062 T1477 oascc.SolrZkClient.makePath makePath: /collections/collection1
   [junit4]   2> 709066 T1477 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
   [junit4]   2> 709068 T1477 oascc.SolrZkClient.makePath makePath: /collections/control_collection
   [junit4]   2> 709071 T1477 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
   [junit4]   2> 709073 T1477 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
   [junit4]   2> 709074 T1477 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
   [junit4]   2> 709080 T1477 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
   [junit4]   2> 709081 T1477 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
   [junit4]   2> 709186 T1477 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
   [junit4]   2> 709187 T1477 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
   [junit4]   2> 709191 T1477 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
   [junit4]   2> 709191 T1477 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
   [junit4]   2> 709202 T1477 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
   [junit4]   2> 709203 T1477 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
   [junit4]   2> 709206 T1477 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
   [junit4]   2> 709207 T1477 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
   [junit4]   2> 709210 T1477 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 709211 T1477 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 709214 T1477 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
   [junit4]   2> 709215 T1477 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
   [junit4]   2> 709218 T1477 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
   [junit4]   2> 709219 T1477 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
   [junit4]   2> 709492 T1477 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 709496 T1477 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:39343
   [junit4]   2> 709497 T1477 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 709497 T1477 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 709498 T1477 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374546923005
   [junit4]   2> 709498 T1477 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374546923005/'
   [junit4]   2> 709538 T1477 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374546923005/solr.xml
   [junit4]   2> 709613 T1477 oasc.CoreContainer.<init> New CoreContainer 1200574017
   [junit4]   2> 709613 T1477 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374546923005/]
   [junit4]   2> 709615 T1477 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 709616 T1477 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 709616 T1477 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 709617 T1477 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 709617 T1477 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 709618 T1477 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 709618 T1477 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 709619 T1477 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 709619 T1477 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 709620 T1477 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
   [junit4]   2> 709636 T1477 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 709637 T1477 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:32604/solr
   [junit4]   2> 709638 T1477 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 709639 T1477 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 709642 T1497 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@59631383 name:ZooKeeperConnection Watcher:127.0.0.1:32604 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 709643 T1477 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 709653 T1477 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
   [junit4]   2> 709665 T1477 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 709667 T1499 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@786becbc name:ZooKeeperConnection Watcher:127.0.0.1:32604/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 709667 T1477 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 709670 T1477 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 709681 T1477 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 709686 T1477 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 709688 T1477 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:39343_
   [junit4]   2> 709696 T1477 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:39343_
   [junit4]   2> 709701 T1477 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 709715 T1477 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 709718 T1477 oasc.Overseer.start Overseer (id=90082307128295427-127.0.0.1:39343_-n_0000000000) starting
   [junit4]   2> 709729 T1477 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 709740 T1501 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 709741 T1477 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 709744 T1477 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 709751 T1477 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 709754 T1500 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 709760 T1502 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 709760 T1502 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 709761 T1502 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 711259 T1500 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 711260 T1500 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:39343_",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:39343"}
   [junit4]   2> 711261 T1500 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with numShards 1
   [junit4]   2> 711261 T1500 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 711277 T1499 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> 711765 T1502 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 711765 T1502 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374546923005/collection1
   [junit4]   2> 711765 T1502 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
   [junit4]   2> 711766 T1502 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 711766 T1502 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
   [junit4]   2> 711767 T1502 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374546923005/collection1/'
   [junit4]   2> 711769 T1502 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374546923005/collection1/lib/classes/' to classloader
   [junit4]   2> 711770 T1502 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374546923005/collection1/lib/README' to classloader
   [junit4]   2> 711826 T1502 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_45
   [junit4]   2> 711886 T1502 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 711988 T1502 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 712000 T1502 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 712640 T1502 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 712640 T1502 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 712641 T1502 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 712654 T1502 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 712658 T1502 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 712675 T1502 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 712680 T1502 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 712685 T1502 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 712686 T1502 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 712686 T1502 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 712687 T1502 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 712688 T1502 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 712688 T1502 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 712689 T1502 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 712689 T1502 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374546923005/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZkTest-1374546922719/control/data/
   [junit4]   2> 712689 T1502 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1a7b5617
   [junit4]   2> 712690 T1502 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374546922719/control/data
   [junit4]   2> 712690 T1502 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZkTest-1374546922719/control/data/index/
   [junit4]   2> 712691 T1502 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZkTest-1374546922719/control/data/index' doesn't exist. Creating new index...
   [junit4]   2> 712691 T1502 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374546922719/control/data/index
   [junit4]   2> 712696 T1502 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@70920080 lockFactory=org.apache.lucene.store.NativeFSLockFactory@34a775a0),segFN=segments_1,generation=1}
   [junit4]   2> 712696 T1502 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 712701 T1502 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 712701 T1502 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 712702 T1502 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 712702 T1502 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 712703 T1502 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 712703 T1502 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 712703 T1502 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 712704 T1502 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 712704 T1502 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 712714 T1502 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 712721 T1502 oass.SolrIndexSearcher.<init> Opening Searcher@41bb11e1 main
   [junit4]   2> 712723 T1502 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 712723 T1502 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 712726 T1503 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@41bb11e1 main{StandardDirectoryReader(segments_1:1)}
   [junit4]   2> 712728 T1502 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 712728 T1502 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:39343 collection:control_collection shard:shard1
   [junit4]   2> 712729 T1502 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=30000&socketTimeout=30000&retry=false
   [junit4]   2> 712747 T1502 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
   [junit4]   2> 712779 T1502 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 712795 T1502 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 712795 T1502 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> 712796 T1502 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:39343/collection1/
   [junit4]   2> 712796 T1502 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 712796 T1502 oasc.SyncStrategy.syncToMe http://127.0.0.1:39343/collection1/ has no replicas
   [junit4]   2> 712796 T1502 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:39343/collection1/ shard1
   [junit4]   2> 712797 T1502 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
   [junit4]   2> 714299 T1500 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 714320 T1499 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> 714351 T1502 oasc.ZkController.register We are http://127.0.0.1:39343/collection1/ and leader is http://127.0.0.1:39343/collection1/
   [junit4]   2> 714351 T1502 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:39343
   [junit4]   2> 714351 T1502 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 714351 T1502 oasc.ZkController.publish publishing core=collection1 state=active
   [junit4]   2> 714352 T1502 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 714354 T1502 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 714355 T1477 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1
   [junit4]   2> 714356 T1477 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 714356 T1477 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> 714369 T1477 oascsi.HttpClientUtil.createClient Creating new http client, config:
   [junit4]   2> 714371 T1477 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 714374 T1506 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4d3b6cf3 name:ZooKeeperConnection Watcher:127.0.0.1:32604/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 714374 T1477 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 714376 T1477 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 714378 T1477 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
   [junit4]   2> 714647 T1477 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 714650 T1477 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:28144
   [junit4]   2> 714650 T1477 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 714651 T1477 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 714651 T1477 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374546928161
   [junit4]   2> 714652 T1477 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374546928161/'
   [junit4]   2> 714692 T1477 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374546928161/solr.xml
   [junit4]   2> 714766 T1477 oasc.CoreContainer.<init> New CoreContainer 1977125704
   [junit4]   2> 714766 T1477 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374546928161/]
   [junit4]   2> 714768 T1477 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 714769 T1477 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 714769 T1477 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 714770 T1477 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 714770 T1477 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 714771 T1477 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 714771 T1477 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 714772 T1477 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 714772 T1477 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 714773 T1477 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
   [junit4]   2> 714788 T1477 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 714789 T1477 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:32604/solr
   [junit4]   2> 714790 T1477 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 714791 T1477 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 714794 T1517 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5ba06069 name:ZooKeeperConnection Watcher:127.0.0.1:32604 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 714795 T1477 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 714811 T1477 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
   [junit4]   2> 714822 T1477 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 714824 T1519 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@540f6193 name:ZooKeeperConnection Watcher:127.0.0.1:32604/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 714825 T1477 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 714836 T1477 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 715828 T1500 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 715829 T1500 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:39343_",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:39343"}
   [junit4]   2> 715848 T1499 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> 715848 T1477 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:28144_
   [junit4]   2> 715848 T1506 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> 715848 T1519 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> 715851 T1477 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:28144_
   [junit4]   2> 715859 T1519 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> 715859 T1499 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> 715860 T1506 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 715860 T1506 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> 715861 T1519 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 715861 T1499 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 715870 T1520 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 715870 T1520 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 715872 T1520 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 717360 T1500 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 717361 T1500 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:28144_",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:28144"}
   [junit4]   2> 717362 T1500 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with numShards 2
   [junit4]   2> 717362 T1500 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 717396 T1499 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> 717396 T1506 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> 717396 T1519 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> 717874 T1520 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 717874 T1520 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374546928161/collection1
   [junit4]   2> 717874 T1520 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 717875 T1520 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 717876 T1520 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 717877 T1520 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374546928161/collection1/'
   [junit4]   2> 717878 T1520 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374546928161/collection1/lib/classes/' to classloader
   [junit4]   2> 717879 T1520 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374546928161/collection1/lib/README' to classloader
   [junit4]   2> 717936 T1520 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_45
   [junit4]   2> 717996 T1520 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 718099 T1520 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 718111 T1520 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 718754 T1520 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 718754 T1520 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 718755 T1520 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 718768 T1520 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 718772 T1520 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 718789 T1520 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 718794 T1520 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 718798 T1520 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 718800 T1520 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 718800 T1520 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 718800 T1520 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 718801 T1520 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 718802 T1520 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 718802 T1520 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 718802 T1520 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374546928161/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZkTest-1374546922719/jetty1/
   [junit4]   2> 718803 T1520 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1a7b5617
   [junit4]   2> 718804 T1520 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374546922719/jetty1
   [junit4]   2> 718804 T1520 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZkTest-1374546922719/jetty1/index/
   [junit4]   2> 718804 T1520 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZkTest-1374546922719/jetty1/index' doesn't exist. Creating new index...
   [junit4]   2> 718804 T1520 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374546922719/jetty1/index
   [junit4]   2> 718808 T1520 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@2499c773 lockFactory=org.apache.lucene.store.NativeFSLockFactory@27382f59),segFN=segments_1,generation=1}
   [junit4]   2> 718808 T1520 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 718814 T1520 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 718814 T1520 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 718815 T1520 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 718815 T1520 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 718816 T1520 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 718816 T1520 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 718817 T1520 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 718817 T1520 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 718818 T1520 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 718827 T1520 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 718835 T1520 oass.SolrIndexSearcher.<init> Opening Searcher@3ccc8a63 main
   [junit4]   2> 718836 T1520 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 718836 T1520 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 718841 T1521 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@3ccc8a63 main{StandardDirectoryReader(segments_1:1)}
   [junit4]   2> 718843 T1520 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 718843 T1520 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:28144 collection:collection1 shard:shard1
   [junit4]   2> 718843 T1520 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=30000&socketTimeout=30000&retry=false
   [junit4]   2> 718861 T1520 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 718888 T1520 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 718898 T1520 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 718898 T1520 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> 718898 T1520 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:28144/collection1/
   [junit4]   2> 718898 T1520 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 718899 T1520 oasc.SyncStrategy.syncToMe http://127.0.0.1:28144/collection1/ has no replicas
   [junit4]   2> 718899 T1520 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:28144/collection1/ shard1
   [junit4]   2> 718899 T1520 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 718904 T1500 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 718930 T1499 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> 718930 T1506 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> 718930 T1519 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> 718970 T1520 oasc.ZkController.register We are http://127.0.0.1:28144/collection1/ and leader is http://127.0.0.1:28144/collection1/
   [junit4]   2> 718970 T1520 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:28144
   [junit4]   2> 718970 T1520 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 718970 T1520 oasc.ZkController.publish publishing core=collection1 state=active
   [junit4]   2> 718971 T1520 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 718973 T1520 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 718974 T1477 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1
   [junit4]   2> 718975 T1477 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 718975 T1477 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> 719262 T1477 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 719266 T1477 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:39320
   [junit4]   2> 719266 T1477 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 719267 T1477 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 719267 T1477 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374546932770
   [junit4]   2> 719268 T1477 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374546932770/'
   [junit4]   2> 719307 T1477 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374546932770/solr.xml
   [junit4]   2> 719381 T1477 oasc.CoreContainer.<init> New CoreContainer 89529075
   [junit4]   2> 719381 T1477 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374546932770/]
   [junit4]   2> 719383 T1477 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 719384 T1477 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 719384 T1477 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 719385 T1477 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 719385 T1477 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 719385 T1477 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 719386 T1477 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 719386 T1477 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 719387 T1477 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 719387 T1477 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
   [junit4]   2> 719405 T1477 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 719406 T1477 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:32604/solr
   [junit4]   2> 719406 T1477 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 719407 T1477 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 719410 T1533 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@58034a41 name:ZooKeeperConnection Watcher:127.0.0.1:32604 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 719411 T1477 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 719425 T1477 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
   [junit4]   2> 719438 T1477 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 719440 T1535 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5de41cab name:ZooKeeperConnection Watcher:127.0.0.1:32604/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 719440 T1477 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 719452 T1477 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 720446 T1500 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 720447 T1500 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:28144_",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:28144"}
   [junit4]   2> 720462 T1519 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> 720463 T1477 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:39320_
   [junit4]   2> 720462 T1535 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> 720462 T1499 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> 720462 T1506 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> 720466 T1477 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:39320_
   [junit4]   2> 720474 T1519 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> 720475 T1499 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> 720475 T1506 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 720475 T1535 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 720475 T1506 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> 720476 T1535 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> 720477 T1519 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 720477 T1499 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 720485 T1536 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 720485 T1536 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 720486 T1536 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 721977 T1500 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 721978 T1500 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:39320_",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:39320"}
   [junit4]   2> 721979 T1500 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
   [junit4]   2> 721979 T1500 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
   [junit4]   2> 721992 T1519 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> 721992 T1506 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> 721992 T1535 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> 721992 T1499 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> 722489 T1536 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 722489 T1536 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374546932770/collection1
   [junit4]   2> 722489 T1536 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 722490 T1536 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 722491 T1536 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 722492 T1536 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374546932770/collection1/'
   [junit4]   2> 722493 T1536 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374546932770/collection1/lib/classes/' to classloader
   [junit4]   2> 722494 T1536 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374546932770/collection1/lib/README' to classloader
   [junit4]   2> 722550 T1536 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_45
   [junit4]   2> 722611 T1536 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 722713 T1536 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 722725 T1536 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 723358 T1536 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 723358 T1536 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 723359 T1536 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 723372 T1536 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 723376 T1536 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 723393 T1536 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 723398 T1536 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 723403 T1536 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 723404 T1536 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 723404 T1536 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 723404 T1536 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 723406 T1536 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 723406 T1536 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 723406 T1536 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 723407 T1536 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374546932770/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZkTest-1374546922719/jetty2/
   [junit4]   2> 723407 T1536 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1a7b5617
   [junit4]   2> 723408 T1536 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374546922719/jetty2
   [junit4]   2> 723408 T1536 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZkTest-1374546922719/jetty2/index/
   [junit4]   2> 723408 T1536 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZkTest-1374546922719/jetty2/index' doesn't exist. Creating new index...
   [junit4]   2> 723409 T1536 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374546922719/jetty2/index
   [junit4]   2> 723413 T1536 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1210c9ed lockFactory=org.apache.lucene.store.NativeFSLockFactory@5df7e9bc),segFN=segments_1,generation=1}
   [junit4]   2> 723413 T1536 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 723418 T1536 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 723418 T1536 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 723419 T1536 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 723420 T1536 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 723420 T1536 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 723421 T1536 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 723421 T1536 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 723422 T1536 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 723422 T1536 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 723431 T1536 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 723438 T1536 oass.SolrIndexSearcher.<init> Opening Searcher@3bd22ff9 main
   [junit4]   2> 723439 T1536 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 723439 T1536 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 723444 T1537 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@3bd22ff9 main{StandardDirectoryReader(segments_1:1)}
   [junit4]   2> 723446 T1536 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 723446 T1536 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:39320 collection:collection1 shard:shard2
   [junit4]   2> 723446 T1536 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=30000&socketTimeout=30000&retry=false
   [junit4]   2> 723463 T1536 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
   [junit4]   2> 723509 T1536 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
   [junit4]   2> 723513 T1536 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 723513 T1536 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> 723513 T1536 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:39320/collection1/
   [junit4]   2> 723513 T1536 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 723514 T1536 oasc.SyncStrategy.syncToMe http://127.0.0.1:39320/collection1/ has no replicas
   [junit4]   2> 723514 T1536 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:39320/collection1/ shard2
   [junit4]   2> 723514 T1536 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
   [junit4]   2> 725015 T1500 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 725036 T1519 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> 725036 T1499 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> 725036 T1535 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> 725036 T1506 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> 725063 T1536 oasc.ZkController.register We are http://127.0.0.1:39320/collection1/ and leader is http://127.0.0.1:39320/collection1/
   [junit4]   2> 725063 T1536 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:39320
   [junit4]   2> 725063 T1536 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 725063 T1536 oasc.ZkController.publish publishing core=collection1 state=active
   [junit4]   2> 725064 T1536 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 725066 T1536 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 725067 T1477 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1
   [junit4]   2> 725068 T1477 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 725069 T1477 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> 725349 T1477 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 725351 T1477 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:34082
   [junit4]   2> 725352 T1477 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 725352 T1477 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 725353 T1477 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374546938863
   [junit4]   2> 725353 T1477 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374546938863/'
   [junit4]   2> 725393 T1477 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374546938863/solr.xml
   [junit4]   2> 725466 T1477 oasc.CoreContainer.<init> New CoreContainer 237233196
   [junit4]   2> 725467 T1477 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374546938863/]
   [junit4]   2> 725468 T1477 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 725469 T1477 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 725469 T1477 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 725470 T1477 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 725470 T1477 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 725471 T1477 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 725471 T1477 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 725472 T1477 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 725472 T1477 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 725473 T1477 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
   [junit4]   2> 725490 T1477 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 725491 T1477 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:32604/solr
   [junit4]   2> 725491 T1477 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 725493 T1477 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 725496 T1549 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@56590bf4 name:ZooKeeperConnection Watcher:127.0.0.1:32604 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 725496 T1477 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 725513 T1477 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
   [junit4]   2> 725524 T1477 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 725528 T1551 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6967e124 name:ZooKeeperConnection Watcher:127.0.0.1:32604/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 725528 T1477 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 725534 T1477 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 726538 T1477 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:34082_
   [junit4]   2> 726540 T1477 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:34082_
   [junit4]   2> 726543 T1499 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> 726543 T1519 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> 726544 T1535 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 726545 T1551 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 726544 T1506 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 726545 T1535 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> 726545 T1506 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> 726546 T1500 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 726546 T1519 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 726559 T1500 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:39320_",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:39320"}
   [junit4]   2> 726565 T1552 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 726565 T1552 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 726571 T1519 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> 726571 T1551 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> 726571 T1506 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> 726571 T1535 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> 726572 T1552 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 726581 T1499 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 726581 T1499 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> 728082 T1500 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 728084 T1500 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:34082_",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:34082"}
   [junit4]   2> 728084 T1500 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
   [junit4]   2> 728084 T1500 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 728134 T1499 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> 728134 T1535 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> 728134 T1551 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> 728134 T1506 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> 728134 T1519 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> 728575 T1552 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 728575 T1552 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374546938863/collection1
   [junit4]   2> 728575 T1552 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 728576 T1552 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 728576 T1552 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 728577 T1552 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374546938863/collection1/'
   [junit4]   2> 728579 T1552 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374546938863/collection1/lib/classes/' to classloader
   [junit4]   2> 728579 T1552 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374546938863/collection1/lib/README' to classloader
   [junit4]   2> 728644 T1552 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_45
   [junit4]   2> 728704 T1552 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 728807 T1552 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 728819 T1552 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 729449 T1552 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 729450 T1552 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 729451 T1552 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 729462 T1552 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 729466 T1552 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 729483 T1552 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 729487 T1552 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 729492 T1552 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 729493 T1552 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 729493 T1552 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 729494 T1552 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 729495 T1552 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 729495 T1552 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 729495 T1552 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 729496 T1552 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374546938863/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZkTest-1374546922719/jetty3/
   [junit4]   2> 729496 T1552 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1a7b5617
   [junit4]   2> 729497 T1552 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374546922719/jetty3
   [junit4]   2> 729497 T1552 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZkTest-1374546922719/jetty3/index/
   [junit4]   2> 729498 T1552 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZkTest-1374546922719/jetty3/index' doesn't exist. Creating new index...
   [junit4]   2> 729498 T1552 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374546922719/jetty3/index
   [junit4]   2> 729501 T1552 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@7dfb6e6d lockFactory=org.apache.lucene.store.NativeFSLockFactory@676e30ce),segFN=segments_1,generation=1}
   [junit4]   2> 729502 T1552 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 729506 T1552 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 729507 T1552 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 729507 T1552 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 729508 T1552 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 729509 T1552 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 729509 T1552 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 729509 T1552 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 729510 T1552 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 729510 T1552 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 729519 T1552 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 729526 T1552 oass.SolrIndexSearcher.<init> Opening Searcher@69004948 main
   [junit4]   2> 729527 T1552 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 729527 T1552 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 729532 T1553 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@69004948 main{StandardDirectoryReader(segments_1:1)}
   [junit4]   2> 729534 T1552 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 729534 T1552 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:34082 collection:collection1 shard:shard1
   [junit4]   2> 729534 T1552 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=30000&socketTimeout=30000&retry=false
   [junit4]   2> 729554 T1552 oasc.ZkController.register We are http://127.0.0.1:34082/collection1/ and leader is http://127.0.0.1:28144/collection1/
   [junit4]   2> 729554 T1552 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:34082
   [junit4]   2> 729554 T1552 oasc.ZkController.checkRecovery Core needs to recover:collection1
   [junit4]   2> 729555 T1552 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
   [junit4]   2> ASYNC  NEW_CORE C416 name=collection1 org.apache.solr.core.SolrCore@43269c4f url=http://127.0.0.1:34082/collection1 node=127.0.0.1:34082_ C416_STATE=coll:collection1 core:collection1 props:{state=down, core=collection1, node_name=127.0.0.1:34082_, base_url=http://127.0.0.1:34082}
   [junit4]   2> 729555 T1554 C416 P34082 oasc.RecoveryStrategy.run Starting recovery process.  core=collection1 recoveringAfterStartup=true
   [junit4]   2> 729556 T1554 C416 P34082 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
   [junit4]   2> 729556 T1552 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 729556 T1554 C416 P34082 oasc.ZkController.publish publishing core=collection1 state=recovering
   [junit4]   2> 729556 T1554 C416 P34082 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 729557 T1477 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1
   [junit4]   2> 729558 T1477 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 729558 T1554 C416 P34082 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> 729558 T1477 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> 729575 T1509 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: core_node3, state: recovering, checkLive: true, onlyIfLeader: true
   [junit4]   2> 729640 T1500 oascc.ZkStateReader.updateClusterState Updating cloud state f

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

: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:1146)
   [junit4]   2> 	        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
   [junit4]   2> 	        at java.lang.Thread.run(Thread.java:679)
   [junit4]   2> NOTE: test params are: codec=HighCompressionCompressingStoredFields(storedFieldsFormat=CompressingStoredFieldsFormat(compressionMode=HIGH_COMPRESSION, chunkSize=353), termVectorsFormat=CompressingTermVectorsFormat(compressionMode=HIGH_COMPRESSION, chunkSize=353)), sim=DefaultSimilarity, locale=hr, timezone=America/Nipigon
   [junit4]   2> NOTE: FreeBSD 9.1-RELEASE-p3 amd64/Sun Microsystems Inc. 1.6.0_32 (64-bit)/cpus=16,threads=2,free=186206528,total=463863808
   [junit4]   2> NOTE: All tests run in this JVM: [TestBinaryResponseWriter, TestFiltering, TestHashPartitioner, TestRecovery, ClusterStateTest, TestManagedSchemaFieldResource, FileUtilsTest, DistanceFunctionTest, NumericFieldsTest, TestQueryTypes, SolrCmdDistributorTest, HdfsLockFactoryTest, RequestHandlersTest, TestMergePolicyConfig, TestCollationKeyRangeQueries, HdfsCollectionsAPIDistributedZkTest, TestInfoStreamLogging, TestIndexSearcher, TestDFRSimilarityFactory, BasicDistributedZk2Test, RequiredFieldsTest, DocValuesMultiTest, TestJmxMonitoredMap, XmlUpdateRequestHandlerTest, HdfsBasicDistributedZkTest, TestDistributedGrouping, TestAtomicUpdateErrorCases, IndexSchemaRuntimeFieldTest, HdfsSyncSliceTest, URLClassifyProcessorTest, SignatureUpdateProcessorFactoryTest, TestPostingsSolrHighlighter, SolrPluginUtilsTest, TestLuceneMatchVersion, TestFieldCollectionResource, TestOmitPositions, HighlighterConfigTest, TestPartialUpdateDeduplication, HdfsChaosMonkeySafeLeaderTest, SuggesterTSTTest, TestRangeQuery, DirectSolrSpellCheckerTest, TestCoreDiscovery, StatsComponentTest, TestReload, TestSolrJ, TestReloadAndDeleteDocs, DOMUtilTest, ConvertedLegacyTest, TimeZoneUtilsTest, TestManagedSchema, UniqFieldsUpdateProcessorFactoryTest, CurrencyFieldXmlFileTest, JSONWriterTest, DisMaxRequestHandlerTest, ShardSplitTest, TestWordDelimiterFilterFactory, SortByFunctionTest, TestCollationField, FieldAnalysisRequestHandlerTest, PathHierarchyTokenizerFactoryTest, TestFastOutputStream, TestComponentsName, TestSuggestSpellingConverter, OutputWriterTest, TestPropInject, TestSchemaVersionResource, PreAnalyzedUpdateProcessorTest, SpellPossibilityIteratorTest, IndexBasedSpellCheckerTest, TestSchemaSimilarityResource, TestFoldingMultitermQuery, TestCSVResponseWriter, TestArbitraryIndexDir, TestJmxIntegration, BasicDistributedZkTest]
   [junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=BasicDistributedZkTest -Dtests.seed=1F239F44D9E6F380 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=hr -Dtests.timezone=America/Nipigon -Dtests.file.encoding=ISO-8859-1
   [junit4] ERROR   0.00s J1 | 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=1958, name=recoveryCmdExecutor-1157-thread-1, state=RUNNABLE, group=TGRP-BasicDistributedZkTest]
   [junit4]    >         at java.net.PlainSocketImpl.socketConnect(Native Method)
   [junit4]    >         at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:327)
   [junit4]    >         at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:193)
   [junit4]    >         at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:180)
   [junit4]    >         at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:384)
   [junit4]    >         at java.net.Socket.connect(Socket.java:546)
   [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:1146)
   [junit4]    >         at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
   [junit4]    >         at java.lang.Thread.run(Thread.java:679)
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([1F239F44D9E6F380]:0)Throwable #2: com.carrotsearch.randomizedtesting.ThreadLeakError: There are still zombie threads that couldn't be terminated:
   [junit4]    >    1) Thread[id=1958, name=recoveryCmdExecutor-1157-thread-1, state=RUNNABLE, group=TGRP-BasicDistributedZkTest]
   [junit4]    >         at java.net.PlainSocketImpl.socketConnect(Native Method)
   [junit4]    >         at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:327)
   [junit4]    >         at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:193)
   [junit4]    >         at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:180)
   [junit4]    >         at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:384)
   [junit4]    >         at java.net.Socket.connect(Socket.java:546)
   [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:1146)
   [junit4]    >         at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
   [junit4]    >         at java.lang.Thread.run(Thread.java:679)
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([1F239F44D9E6F380]:0)
   [junit4] Completed on J1 in 390.32s, 1 test, 2 errors <<< FAILURES!

[...truncated 486 lines...]
BUILD FAILED
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/build.xml:395: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/build.xml:375: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/build.xml:39: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build.xml:181: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/common-build.xml:449: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/lucene/common-build.xml:1250: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/lucene/common-build.xml:893: There were test failures: 319 suites, 1345 tests, 2 suite-level errors, 595 ignored (4 assumptions)

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



[JENKINS] Lucene-Solr-Tests-4.x-Java6 - Build # 1821 - Still Failing

Posted by Apache Jenkins Server <je...@builds.apache.org>.
Build: https://builds.apache.org/job/Lucene-Solr-Tests-4.x-Java6/1821/

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=2147, name=recoveryCmdExecutor-1118-thread-1, state=RUNNABLE, group=TGRP-BasicDistributedZkTest]         at java.net.PlainSocketImpl.socketConnect(Native Method)         at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:327)         at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:193)         at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:180)         at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:384)         at java.net.Socket.connect(Socket.java:546)         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:1146)         at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)         at java.lang.Thread.run(Thread.java:679)

Stack Trace:
com.carrotsearch.randomizedtesting.ThreadLeakError: 1 thread leaked from SUITE scope at org.apache.solr.cloud.BasicDistributedZkTest: 
   1) Thread[id=2147, name=recoveryCmdExecutor-1118-thread-1, state=RUNNABLE, group=TGRP-BasicDistributedZkTest]
        at java.net.PlainSocketImpl.socketConnect(Native Method)
        at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:327)
        at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:193)
        at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:180)
        at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:384)
        at java.net.Socket.connect(Socket.java:546)
        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:1146)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
        at java.lang.Thread.run(Thread.java:679)
	at __randomizedtesting.SeedInfo.seed([2C5FEAA2D105F2E5]: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=2147, name=recoveryCmdExecutor-1118-thread-1, state=RUNNABLE, group=TGRP-BasicDistributedZkTest]         at java.net.PlainSocketImpl.socketConnect(Native Method)         at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:327)         at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:193)         at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:180)         at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:384)         at java.net.Socket.connect(Socket.java:546)         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:1146)         at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)         at java.lang.Thread.run(Thread.java:679)

Stack Trace:
com.carrotsearch.randomizedtesting.ThreadLeakError: There are still zombie threads that couldn't be terminated:
   1) Thread[id=2147, name=recoveryCmdExecutor-1118-thread-1, state=RUNNABLE, group=TGRP-BasicDistributedZkTest]
        at java.net.PlainSocketImpl.socketConnect(Native Method)
        at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:327)
        at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:193)
        at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:180)
        at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:384)
        at java.net.Socket.connect(Socket.java:546)
        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:1146)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
        at java.lang.Thread.run(Thread.java:679)
	at __randomizedtesting.SeedInfo.seed([2C5FEAA2D105F2E5]:0)




Build Log:
[...truncated 9192 lines...]
   [junit4] Suite: org.apache.solr.cloud.BasicDistributedZkTest
   [junit4]   2> 977467 T1664 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /e_sfl/
   [junit4]   2> 977472 T1664 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
   [junit4]   2> Creating dataDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZkTest-1374570937980
   [junit4]   2> 977473 T1664 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   2> 977473 T1665 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 977574 T1664 oasc.ZkTestServer.run start zk server on port:33951
   [junit4]   2> 977575 T1664 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 977578 T1671 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@125fc746 name:ZooKeeperConnection Watcher:127.0.0.1:33951 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 977579 T1664 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 977579 T1664 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 977591 T1664 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 977592 T1673 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5bbe6d69 name:ZooKeeperConnection Watcher:127.0.0.1:33951/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 977593 T1664 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 977593 T1664 oascc.SolrZkClient.makePath makePath: /collections/collection1
   [junit4]   2> 977604 T1664 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
   [junit4]   2> 977606 T1664 oascc.SolrZkClient.makePath makePath: /collections/control_collection
   [junit4]   2> 977608 T1664 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
   [junit4]   2> 977618 T1664 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
   [junit4]   2> 977618 T1664 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
   [junit4]   2> 977632 T1664 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
   [junit4]   2> 977633 T1664 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
   [junit4]   2> 977736 T1664 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
   [junit4]   2> 977737 T1664 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
   [junit4]   2> 977740 T1664 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
   [junit4]   2> 977741 T1664 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
   [junit4]   2> 977743 T1664 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
   [junit4]   2> 977744 T1664 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
   [junit4]   2> 977752 T1664 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
   [junit4]   2> 977752 T1664 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
   [junit4]   2> 977755 T1664 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 977756 T1664 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 977758 T1664 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
   [junit4]   2> 977759 T1664 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
   [junit4]   2> 977766 T1664 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
   [junit4]   2> 977767 T1664 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
   [junit4]   2> 978070 T1664 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 978075 T1664 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:16065
   [junit4]   2> 978076 T1664 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 978076 T1664 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 978077 T1664 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374570938278
   [junit4]   2> 978077 T1664 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374570938278/'
   [junit4]   2> 978121 T1664 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374570938278/solr.xml
   [junit4]   2> 978204 T1664 oasc.CoreContainer.<init> New CoreContainer 1679591670
   [junit4]   2> 978205 T1664 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374570938278/]
   [junit4]   2> 978207 T1664 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 978207 T1664 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 978208 T1664 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 978208 T1664 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 978209 T1664 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 978209 T1664 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 978210 T1664 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 978210 T1664 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 978211 T1664 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 978211 T1664 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
   [junit4]   2> 978228 T1664 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 978229 T1664 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:33951/solr
   [junit4]   2> 978229 T1664 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 978230 T1664 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 978233 T1684 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@d6401d3 name:ZooKeeperConnection Watcher:127.0.0.1:33951 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 978234 T1664 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 978244 T1664 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
   [junit4]   2> 978255 T1664 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 978257 T1686 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@31ca9f31 name:ZooKeeperConnection Watcher:127.0.0.1:33951/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 978257 T1664 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 978260 T1664 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 978271 T1664 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 978275 T1664 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 978277 T1664 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:16065_e_sfl
   [junit4]   2> 978284 T1664 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:16065_e_sfl
   [junit4]   2> 978287 T1664 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 978304 T1664 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 978306 T1664 oasc.Overseer.start Overseer (id=90083880991784963-127.0.0.1:16065_e_sfl-n_0000000000) starting
   [junit4]   2> 978319 T1664 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 978331 T1688 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 978331 T1664 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 978333 T1664 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 978335 T1664 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 978338 T1687 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 978344 T1689 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 978344 T1689 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 978345 T1689 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 979842 T1687 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 979843 T1687 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:16065_e_sfl",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:16065/e_sfl"}
   [junit4]   2> 979843 T1687 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with numShards 1
   [junit4]   2> 979844 T1687 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 979860 T1686 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> 980348 T1689 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 980348 T1689 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374570938278/collection1
   [junit4]   2> 980348 T1689 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
   [junit4]   2> 980349 T1689 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 980350 T1689 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
   [junit4]   2> 980351 T1689 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374570938278/collection1/'
   [junit4]   2> 980352 T1689 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374570938278/collection1/lib/classes/' to classloader
   [junit4]   2> 980353 T1689 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374570938278/collection1/lib/README' to classloader
   [junit4]   2> 980413 T1689 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_45
   [junit4]   2> 980474 T1689 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 980576 T1689 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 980587 T1689 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 981246 T1689 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 981247 T1689 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 981248 T1689 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 981261 T1689 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 981265 T1689 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 981280 T1689 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 981285 T1689 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 981290 T1689 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 981291 T1689 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 981291 T1689 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 981292 T1689 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 981293 T1689 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 981293 T1689 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 981293 T1689 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 981294 T1689 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374570938278/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZkTest-1374570937980/control/data/
   [junit4]   2> 981294 T1689 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@d3c9557
   [junit4]   2> 981295 T1689 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374570937980/control/data
   [junit4]   2> 981295 T1689 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZkTest-1374570937980/control/data/index/
   [junit4]   2> 981296 T1689 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZkTest-1374570937980/control/data/index' doesn't exist. Creating new index...
   [junit4]   2> 981296 T1689 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374570937980/control/data/index
   [junit4]   2> 981301 T1689 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@3583ee8d lockFactory=org.apache.lucene.store.NativeFSLockFactory@1056af52),segFN=segments_1,generation=1}
   [junit4]   2> 981301 T1689 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 981305 T1689 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 981305 T1689 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 981306 T1689 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 981307 T1689 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 981307 T1689 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 981308 T1689 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 981308 T1689 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 981309 T1689 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 981309 T1689 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 981318 T1689 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 981326 T1689 oass.SolrIndexSearcher.<init> Opening Searcher@608a1b4e main
   [junit4]   2> 981327 T1689 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 981327 T1689 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 981331 T1690 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@608a1b4e main{StandardDirectoryReader(segments_1:1)}
   [junit4]   2> 981332 T1689 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 981333 T1689 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:16065/e_sfl collection:control_collection shard:shard1
   [junit4]   2> 981333 T1689 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=30000&socketTimeout=30000&retry=false
   [junit4]   2> 981349 T1689 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
   [junit4]   2> 981375 T1689 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 981378 T1689 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 981378 T1689 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> 981379 T1689 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:16065/e_sfl/collection1/
   [junit4]   2> 981379 T1689 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 981379 T1689 oasc.SyncStrategy.syncToMe http://127.0.0.1:16065/e_sfl/collection1/ has no replicas
   [junit4]   2> 981380 T1689 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:16065/e_sfl/collection1/ shard1
   [junit4]   2> 981380 T1689 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
   [junit4]   2> 982872 T1687 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 982889 T1686 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> 982923 T1689 oasc.ZkController.register We are http://127.0.0.1:16065/e_sfl/collection1/ and leader is http://127.0.0.1:16065/e_sfl/collection1/
   [junit4]   2> 982923 T1689 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:16065/e_sfl
   [junit4]   2> 982923 T1689 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 982924 T1689 oasc.ZkController.publish publishing core=collection1 state=active
   [junit4]   2> 982924 T1689 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 982926 T1689 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 982927 T1664 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1
   [junit4]   2> 982928 T1664 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 982928 T1664 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> 982940 T1664 oascsi.HttpClientUtil.createClient Creating new http client, config:
   [junit4]   2> 982941 T1664 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 982943 T1693 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4c2b880a name:ZooKeeperConnection Watcher:127.0.0.1:33951/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 982944 T1664 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 982946 T1664 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 982948 T1664 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
   [junit4]   2> 983255 T1664 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 983258 T1664 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:48767
   [junit4]   2> 983258 T1664 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 983259 T1664 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 983260 T1664 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374570943456
   [junit4]   2> 983260 T1664 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374570943456/'
   [junit4]   2> 983304 T1664 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374570943456/solr.xml
   [junit4]   2> 983395 T1664 oasc.CoreContainer.<init> New CoreContainer 343375132
   [junit4]   2> 983396 T1664 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374570943456/]
   [junit4]   2> 983398 T1664 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 983398 T1664 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 983399 T1664 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 983399 T1664 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 983400 T1664 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 983400 T1664 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 983401 T1664 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 983401 T1664 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 983402 T1664 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 983402 T1664 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
   [junit4]   2> 983420 T1664 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 983421 T1664 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:33951/solr
   [junit4]   2> 983422 T1664 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 983423 T1664 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 983426 T1704 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@30b6c3c3 name:ZooKeeperConnection Watcher:127.0.0.1:33951 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 983427 T1664 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 983441 T1664 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
   [junit4]   2> 983453 T1664 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 983455 T1706 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@345238b3 name:ZooKeeperConnection Watcher:127.0.0.1:33951/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 983455 T1664 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 983461 T1664 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 984403 T1687 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 984404 T1687 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:16065_e_sfl",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:16065/e_sfl"}
   [junit4]   2> 984418 T1686 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> 984418 T1706 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> 984418 T1693 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> 984464 T1664 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:48767_e_sfl
   [junit4]   2> 984466 T1664 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:48767_e_sfl
   [junit4]   2> 984469 T1706 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> 984469 T1693 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 984469 T1686 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 984469 T1693 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> 984470 T1686 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> 984470 T1706 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 984485 T1707 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 984485 T1707 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 984487 T1707 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 985923 T1687 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 985925 T1687 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:48767_e_sfl",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:48767/e_sfl"}
   [junit4]   2> 985925 T1687 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with numShards 2
   [junit4]   2> 985925 T1687 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 985972 T1693 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> 985972 T1706 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> 985972 T1686 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> 986489 T1707 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 986489 T1707 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374570943456/collection1
   [junit4]   2> 986489 T1707 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 986490 T1707 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 986491 T1707 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 986492 T1707 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374570943456/collection1/'
   [junit4]   2> 986493 T1707 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374570943456/collection1/lib/README' to classloader
   [junit4]   2> 986494 T1707 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374570943456/collection1/lib/classes/' to classloader
   [junit4]   2> 986556 T1707 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_45
   [junit4]   2> 986623 T1707 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 986724 T1707 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 986735 T1707 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 987356 T1707 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 987357 T1707 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 987358 T1707 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 987369 T1707 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 987373 T1707 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 987387 T1707 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 987392 T1707 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 987397 T1707 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 987398 T1707 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 987398 T1707 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 987399 T1707 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 987399 T1707 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 987400 T1707 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 987400 T1707 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 987400 T1707 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374570943456/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZkTest-1374570937980/jetty1/
   [junit4]   2> 987401 T1707 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@d3c9557
   [junit4]   2> 987402 T1707 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374570937980/jetty1
   [junit4]   2> 987402 T1707 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZkTest-1374570937980/jetty1/index/
   [junit4]   2> 987402 T1707 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZkTest-1374570937980/jetty1/index' doesn't exist. Creating new index...
   [junit4]   2> 987403 T1707 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374570937980/jetty1/index
   [junit4]   2> 987407 T1707 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@4a35d93f lockFactory=org.apache.lucene.store.NativeFSLockFactory@39b75a89),segFN=segments_1,generation=1}
   [junit4]   2> 987407 T1707 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 987412 T1707 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 987413 T1707 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 987413 T1707 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 987414 T1707 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 987415 T1707 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 987415 T1707 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 987415 T1707 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 987416 T1707 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 987416 T1707 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 987428 T1707 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 987436 T1707 oass.SolrIndexSearcher.<init> Opening Searcher@7452abeb main
   [junit4]   2> 987437 T1707 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 987438 T1707 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 987442 T1708 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@7452abeb main{StandardDirectoryReader(segments_1:1)}
   [junit4]   2> 987444 T1707 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 987444 T1707 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:48767/e_sfl collection:collection1 shard:shard1
   [junit4]   2> 987445 T1707 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=30000&socketTimeout=30000&retry=false
   [junit4]   2> 987464 T1707 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 987487 T1707 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 987497 T1707 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 987497 T1707 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> 987497 T1707 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:48767/e_sfl/collection1/
   [junit4]   2> 987497 T1707 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 987498 T1707 oasc.SyncStrategy.syncToMe http://127.0.0.1:48767/e_sfl/collection1/ has no replicas
   [junit4]   2> 987498 T1707 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:48767/e_sfl/collection1/ shard1
   [junit4]   2> 987498 T1707 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 988982 T1687 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 989001 T1686 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> 989001 T1706 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> 989001 T1693 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> 989042 T1707 oasc.ZkController.register We are http://127.0.0.1:48767/e_sfl/collection1/ and leader is http://127.0.0.1:48767/e_sfl/collection1/
   [junit4]   2> 989042 T1707 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:48767/e_sfl
   [junit4]   2> 989042 T1707 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 989042 T1707 oasc.ZkController.publish publishing core=collection1 state=active
   [junit4]   2> 989043 T1707 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 989044 T1707 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 989046 T1664 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1
   [junit4]   2> 989046 T1664 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 989047 T1664 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> 989226 T1664 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 989229 T1664 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:13806
   [junit4]   2> 989230 T1664 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 989230 T1664 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 989230 T1664 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374570949561
   [junit4]   2> 989231 T1664 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374570949561/'
   [junit4]   2> 989256 T1664 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374570949561/solr.xml
   [junit4]   2> 989314 T1664 oasc.CoreContainer.<init> New CoreContainer 905033885
   [junit4]   2> 989315 T1664 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374570949561/]
   [junit4]   2> 989316 T1664 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 989317 T1664 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 989317 T1664 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 989318 T1664 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 989318 T1664 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 989319 T1664 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 989319 T1664 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 989320 T1664 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 989320 T1664 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 989321 T1664 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
   [junit4]   2> 989336 T1664 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 989337 T1664 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:33951/solr
   [junit4]   2> 989337 T1664 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 989338 T1664 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 989341 T1720 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@108f6716 name:ZooKeeperConnection Watcher:127.0.0.1:33951 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 989342 T1664 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 989358 T1664 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
   [junit4]   2> 989368 T1664 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 989371 T1722 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3f08662f name:ZooKeeperConnection Watcher:127.0.0.1:33951/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 989371 T1664 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 989384 T1664 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 990387 T1664 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:13806_e_sfl
   [junit4]   2> 990389 T1664 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:13806_e_sfl
   [junit4]   2> 990459 T1706 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> 990460 T1693 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 990461 T1686 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 990461 T1693 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> 990461 T1722 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 990461 T1686 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> 990462 T1706 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 990469 T1723 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 990470 T1723 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 990485 T1723 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 990512 T1687 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 990513 T1687 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:48767_e_sfl",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:48767/e_sfl"}
   [junit4]   2> 990519 T1687 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:13806_e_sfl",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:13806/e_sfl"}
   [junit4]   2> 990520 T1687 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
   [junit4]   2> 990520 T1687 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
   [junit4]   2> 990561 T1706 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> 990561 T1722 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> 990561 T1686 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> 990561 T1693 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> 991487 T1723 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 991487 T1723 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374570949561/collection1
   [junit4]   2> 991487 T1723 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 991488 T1723 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 991488 T1723 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 991489 T1723 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374570949561/collection1/'
   [junit4]   2> 991490 T1723 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374570949561/collection1/lib/README' to classloader
   [junit4]   2> 991490 T1723 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374570949561/collection1/lib/classes/' to classloader
   [junit4]   2> 991528 T1723 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_45
   [junit4]   2> 991568 T1723 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 991670 T1723 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 991677 T1723 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 992144 T1723 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 992145 T1723 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 992146 T1723 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 992158 T1723 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 992162 T1723 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 992176 T1723 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 992180 T1723 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 992185 T1723 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 992186 T1723 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 992186 T1723 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 992186 T1723 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 992187 T1723 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 992188 T1723 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 992188 T1723 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 992188 T1723 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374570949561/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZkTest-1374570937980/jetty2/
   [junit4]   2> 992189 T1723 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@d3c9557
   [junit4]   2> 992190 T1723 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374570937980/jetty2
   [junit4]   2> 992190 T1723 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZkTest-1374570937980/jetty2/index/
   [junit4]   2> 992191 T1723 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZkTest-1374570937980/jetty2/index' doesn't exist. Creating new index...
   [junit4]   2> 992191 T1723 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374570937980/jetty2/index
   [junit4]   2> 992195 T1723 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@5023e78c lockFactory=org.apache.lucene.store.NativeFSLockFactory@4fa342e2),segFN=segments_1,generation=1}
   [junit4]   2> 992195 T1723 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 992200 T1723 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 992201 T1723 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 992202 T1723 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 992202 T1723 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 992203 T1723 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 992203 T1723 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 992204 T1723 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 992205 T1723 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 992205 T1723 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 992215 T1723 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 992222 T1723 oass.SolrIndexSearcher.<init> Opening Searcher@5e9adbb8 main
   [junit4]   2> 992223 T1723 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 992224 T1723 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 992228 T1724 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@5e9adbb8 main{StandardDirectoryReader(segments_1:1)}
   [junit4]   2> 992230 T1723 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 992231 T1723 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:13806/e_sfl collection:collection1 shard:shard2
   [junit4]   2> 992231 T1723 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=30000&socketTimeout=30000&retry=false
   [junit4]   2> 992248 T1723 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
   [junit4]   2> 992264 T1723 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
   [junit4]   2> 992272 T1723 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 992272 T1723 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> 992272 T1723 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:13806/e_sfl/collection1/
   [junit4]   2> 992273 T1723 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 992273 T1723 oasc.SyncStrategy.syncToMe http://127.0.0.1:13806/e_sfl/collection1/ has no replicas
   [junit4]   2> 992273 T1723 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:13806/e_sfl/collection1/ shard2
   [junit4]   2> 992273 T1723 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
   [junit4]   2> 993585 T1687 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 993610 T1706 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> 993610 T1722 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> 993610 T1693 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> 993610 T1686 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> 993664 T1723 oasc.ZkController.register We are http://127.0.0.1:13806/e_sfl/collection1/ and leader is http://127.0.0.1:13806/e_sfl/collection1/
   [junit4]   2> 993664 T1723 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:13806/e_sfl
   [junit4]   2> 993664 T1723 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 993664 T1723 oasc.ZkController.publish publishing core=collection1 state=active
   [junit4]   2> 993665 T1723 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 993667 T1723 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 993668 T1664 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1
   [junit4]   2> 993668 T1664 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 993669 T1664 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> 993944 T1664 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 993947 T1664 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:13813
   [junit4]   2> 993948 T1664 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 993949 T1664 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 993949 T1664 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374570954186
   [junit4]   2> 993950 T1664 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374570954186/'
   [junit4]   2> 993990 T1664 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374570954186/solr.xml
   [junit4]   2> 994067 T1664 oasc.CoreContainer.<init> New CoreContainer 1738100390
   [junit4]   2> 994068 T1664 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374570954186/]
   [junit4]   2> 994069 T1664 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 994070 T1664 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 994070 T1664 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 994071 T1664 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 994071 T1664 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 994072 T1664 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 994072 T1664 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 994073 T1664 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 994073 T1664 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 994074 T1664 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
   [junit4]   2> 994089 T1664 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 994090 T1664 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:33951/solr
   [junit4]   2> 994091 T1664 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 994092 T1664 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 994095 T1736 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1faa96d name:ZooKeeperConnection Watcher:127.0.0.1:33951 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 994096 T1664 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 994111 T1664 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
   [junit4]   2> 994121 T1664 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 994123 T1738 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@13c2f850 name:ZooKeeperConnection Watcher:127.0.0.1:33951/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 994123 T1664 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 994134 T1664 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 995123 T1687 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 995125 T1687 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:13806_e_sfl",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:13806/e_sfl"}
   [junit4]   2> 995138 T1738 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> 995138 T1686 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> 995138 T1664 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:13813_e_sfl
   [junit4]   2> 995138 T1722 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> 995138 T1693 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> 995138 T1706 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> 995141 T1664 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:13813_e_sfl
   [junit4]   2> 995150 T1706 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> 995152 T1693 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 995152 T1693 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> 995154 T1722 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 995154 T1722 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> 995154 T1686 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 995154 T1738 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 995155 T1738 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> 995154 T1686 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> 995157 T1706 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 995167 T1739 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 995167 T1739 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 995247 T1739 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 996643 T1687 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 996645 T1687 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:13813_e_sfl",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:13813/e_sfl"}
   [junit4]   2> 996645 T1687 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
   [junit4]   2> 996645 T1687 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 996658 T1738 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> 996658 T1706 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> 996658 T1722 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> 996658 T1693 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> 996658 T1686 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> 997249 T1739 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 997249 T1739 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374570954186/collection1
   [junit4]   2> 997249 T1739 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 997250 T1739 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 997250 T1739 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 997251 T1739 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374570954186/collection1/'
   [junit4]   2> 997253 T1739 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374570954186/collection1/lib/classes/' to classloader
   [junit4]   2> 997253 T1739 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374570954186/collection1/lib/README' to classloader
   [junit4]   2> 997309 T1739 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_45
   [junit4]   2> 997369 T1739 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 997470 T1739 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 997480 T1739 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 998105 T1739 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 998106 T1739 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 998107 T1739 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 998127 T1739 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 998132 T1739 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 998146 T1739 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 998151 T1739 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 998155 T1739 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 998156 T1739 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 998157 T1739 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 998157 T1739 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 998158 T1739 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 998158 T1739 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 998159 T1739 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 998159 T1739 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374570954186/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZkTest-1374570937980/jetty3/
   [junit4]   2> 998160 T1739 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@d3c9557
   [junit4]   2> 998161 T1739 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374570937980/jetty3
   [junit4]   2> 998161 T1739 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZkTest-1374570937980/jetty3/index/
   [junit4]   2> 998161 T1739 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZkTest-1374570937980/jetty3/index' doesn't exist. Creating new index...
   [junit4]   2> 998162 T1739 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374570937980/jetty3/index
   [junit4]   2> 998165 T1739 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@3da02761 lockFactory=org.apache.lucene.store.NativeFSLockFactory@c1e18f2),segFN=segments_1,generation=1}
   [junit4]   2> 998166 T1739 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 998171 T1739 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 998171 T1739 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 998172 T1739 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 998173 T1739 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 998174 T1739 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 998174 T1739 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 998174 T1739 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 998175 T1739 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 998175 T1739 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 998185 T1739 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 998192 T1739 oass.SolrIndexSearcher.<init> Opening Searcher@597b112 main
   [junit4]   2> 998193 T1739 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 998194 T1739 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 998199 T1740 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@597b112 main{StandardDirectoryReader(segments_1:1)}
   [junit4]   2> 998201 T1739 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 998201 T1739 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:13813/e_sfl collection:collection1 shard:shard1
   [junit4]   2> 998202 T1739 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=30000&socketTimeout=30000&retry=false
   [junit4]   2> 998247 T1739 oasc.ZkController.register We are http://127.0.0.1:13813/e_sfl/collection1/ and leader is http://127.0.0.1:48767/e_sfl/collection1/
   [junit4]   2> 998247 T1739 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:13813/e_sfl
   [junit4]   2> 998247 T1739 oasc.ZkController.checkRecovery Core needs to recover:collection1
   [junit4]   2> 998248 T1739 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
   [junit4]   2> ASYNC  NEW_CORE C194 name=collection1 org.apache.solr.core.SolrCore@31c4879e url=http://127.0.0.1:13813/e_sfl/collection1 node=127.0.0.1:13813_e_sfl C194_STATE=coll:collection1 core:collection1 props:{state=down, core=collection1, node_name=127.0.0.1:13813_e_sfl, base_url=http://127.0.0.1:13813/e_sfl}
   [junit4]   2> 998248 T1741 C194 P13813 oasc.RecoveryStrategy.run Starting recovery process.  core=collection1 recoveringAfterStartup=true
   [junit4]   2> 998249 T1739 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 998249 T1741 C194 P13813 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
   [junit4]   2> 998249 T1741 C194 P13813 oasc.ZkController.publish publishing core=collection1 state=recovering
   [junit4]   2> 998250 T1741 C194 P13813 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 998250 T1664 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1
   [junit4]   2> 998250 T1664 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 998251 T1741 C194 P13813 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> 998251 T1664 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> 998267 T1696 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: core_node3, state: recovering, checkLive: true, onlyIfLeader: true
   [junit4]   2> 998535 T1664 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 998538 T1664 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:13820
   [junit4]   2> 998539 T1664 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 998539 T1664 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 998540 T1664 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty4-1374570958775
   [junit4]   2> 998541 T1664 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/u

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

(name=Direct), id=Pulsing41(freqCutoff=19 minBlockSize=28 maxBlockSize=134), range_facet_sl=PostingsFormat(name=MockRandom), range_facet_si=PostingsFormat(name=TestBloomFilteredLucene41Postings), oddField_s=PostingsFormat(name=MockRandom), sequence_i=PostingsFormat(name=MockRandom), name=Pulsing41(freqCutoff=19 minBlockSize=28 maxBlockSize=134), foo_i=PostingsFormat(name=TestBloomFilteredLucene41Postings), regex_dup_B_s=PostingsFormat(name=Direct), multiDefault=PostingsFormat(name=TestBloomFilteredLucene41Postings), n_tf1=PostingsFormat(name=Direct), n_dt1=PostingsFormat(name=TestBloomFilteredLucene41Postings), genre_s=PostingsFormat(name=MockRandom), author_t=PostingsFormat(name=TestBloomFilteredLucene41Postings), range_facet_l=PostingsFormat(name=Direct), n_ti1=Pulsing41(freqCutoff=19 minBlockSize=28 maxBlockSize=134), text=PostingsFormat(name=MockRandom), _version_=PostingsFormat(name=Direct), val_i=Pulsing41(freqCutoff=19 minBlockSize=28 maxBlockSize=134), SubjectTerms_mfacet=PostingsFormat(name=Direct), series_t=PostingsFormat(name=TestBloomFilteredLucene41Postings), a_t=PostingsFormat(name=Direct), n_tdt1=PostingsFormat(name=Direct), regex_dup_A_s=PostingsFormat(name=MockRandom), price=PostingsFormat(name=MockRandom), other_tl1=PostingsFormat(name=Direct), n_l1=PostingsFormat(name=Direct), a_si=PostingsFormat(name=TestBloomFilteredLucene41Postings), inStock=PostingsFormat(name=MockRandom)}, docValues:{}, sim=DefaultSimilarity, locale=sl, timezone=America/Atikokan
   [junit4]   2> NOTE: FreeBSD 9.1-RELEASE-p3 amd64/Sun Microsystems Inc. 1.6.0_32 (64-bit)/cpus=16,threads=2,free=134918704,total=463667200
   [junit4]   2> NOTE: All tests run in this JVM: [UpdateParamsTest, TestRecovery, TestCloudManagedSchema, TestSystemIdResolver, RequestHandlersTest, HdfsChaosMonkeySafeLeaderTest, XsltUpdateRequestHandlerTest, AssignTest, TestOmitPositions, TestCSVLoader, SolrPluginUtilsTest, TestSerializedLuceneMatchVersion, TestDistributedSearch, TestRangeQuery, ClusterStateTest, TestZkChroot, SimplePostToolTest, TestJmxIntegration, BadIndexSchemaTest, DirectUpdateHandlerTest, TestSolrXMLSerializer, TestBM25SimilarityFactory, TestJmxMonitoredMap, IndexBasedSpellCheckerTest, OutputWriterTest, TestHashPartitioner, StandardRequestHandlerTest, TestIndexingPerformance, DocumentAnalysisRequestHandlerTest, TestInfoStreamLogging, ShardRoutingCustomTest, StatsComponentTest, JSONWriterTest, TestAnalyzedSuggestions, HdfsBasicDistributedZkTest, SuggesterTSTTest, BasicZkTest, RequiredFieldsTest, UniqFieldsUpdateProcessorFactoryTest, HdfsRecoveryZkTest, TestMultiCoreConfBootstrap, DeleteShardTest, FieldAnalysisRequestHandlerTest, TestPartialUpdateDeduplication, TestLMJelinekMercerSimilarityFactory, TestStressLucene, HighlighterTest, TestDynamicFieldResource, CopyFieldTest, BasicDistributedZk2Test, TestCoreDiscovery, TestCloudManagedSchemaAddField, TestElisionMultitermQuery, SolrIndexConfigTest, SuggesterWFSTTest, TestIndexSearcher, TestManagedSchemaFieldResource, CoreAdminCreateDiscoverTest, ConvertedLegacyTest, TestLuceneMatchVersion, QueryResultKeyTest, FileUtilsTest, PathHierarchyTokenizerFactoryTest, HardAutoCommitTest, URLClassifyProcessorTest, NotRequiredUniqueKeyTest, TestUpdate, TestDefaultSimilarityFactory, TestLazyCores, TestClassNameShortening, NoCacheHeaderTest, TestCodecSupport, TestPostingsSolrHighlighter, SampleTest, BasicDistributedZkTest]
   [junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=BasicDistributedZkTest -Dtests.seed=2C5FEAA2D105F2E5 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=sl -Dtests.timezone=America/Atikokan -Dtests.file.encoding=UTF-8
   [junit4] ERROR   0.00s J1 | 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=2147, name=recoveryCmdExecutor-1118-thread-1, state=RUNNABLE, group=TGRP-BasicDistributedZkTest]
   [junit4]    >         at java.net.PlainSocketImpl.socketConnect(Native Method)
   [junit4]    >         at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:327)
   [junit4]    >         at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:193)
   [junit4]    >         at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:180)
   [junit4]    >         at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:384)
   [junit4]    >         at java.net.Socket.connect(Socket.java:546)
   [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:1146)
   [junit4]    >         at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
   [junit4]    >         at java.lang.Thread.run(Thread.java:679)
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([2C5FEAA2D105F2E5]:0)Throwable #2: com.carrotsearch.randomizedtesting.ThreadLeakError: There are still zombie threads that couldn't be terminated:
   [junit4]    >    1) Thread[id=2147, name=recoveryCmdExecutor-1118-thread-1, state=RUNNABLE, group=TGRP-BasicDistributedZkTest]
   [junit4]    >         at java.net.PlainSocketImpl.socketConnect(Native Method)
   [junit4]    >         at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:327)
   [junit4]    >         at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:193)
   [junit4]    >         at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:180)
   [junit4]    >         at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:384)
   [junit4]    >         at java.net.Socket.connect(Socket.java:546)
   [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:1146)
   [junit4]    >         at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
   [junit4]    >         at java.lang.Thread.run(Thread.java:679)
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([2C5FEAA2D105F2E5]:0)
   [junit4] Completed on J1 in 419.89s, 1 test, 2 errors <<< FAILURES!

[...truncated 486 lines...]
BUILD FAILED
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/build.xml:395: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/build.xml:375: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/build.xml:39: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build.xml:181: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/common-build.xml:449: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/lucene/common-build.xml:1250: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/lucene/common-build.xml:893: There were test failures: 319 suites, 1345 tests, 2 suite-level errors, 608 ignored (5 assumptions)

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