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/25 03:04:15 UTC

[JENKINS] Lucene-Solr-Tests-4.x-Java7 - Build # 1440 - Failure

Build: https://builds.apache.org/job/Lucene-Solr-Tests-4.x-Java7/1440/

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

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

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


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

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

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




Build Log:
[...truncated 9326 lines...]
   [junit4] Suite: org.apache.solr.cloud.AliasIntegrationTest
   [junit4]   2> 22977 T38 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /v/hn
   [junit4]   2> 22985 T38 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
   [junit4]   2> Creating dataDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./solrtest-AliasIntegrationTest-1374712852315
   [junit4]   2> 22994 T38 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   2> 23002 T39 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 23304 T38 oasc.ZkTestServer.run start zk server on port:65381
   [junit4]   2> 23606 T38 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 23649 T40 oazs.NIOServerCnxn.doIO WARN Exception causing close of session 0x0 due to java.io.IOException: ZooKeeperServer not running
   [junit4]   2> 25717 T43 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4bc781ba name:ZooKeeperConnection Watcher:127.0.0.1:65381 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 25718 T38 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 25724 T38 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 25840 T38 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 25844 T47 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@14d7c58a name:ZooKeeperConnection Watcher:127.0.0.1:65381/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 25844 T38 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 25861 T38 oascc.SolrZkClient.makePath makePath: /collections/collection1
   [junit4]   2> 25868 T38 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
   [junit4]   2> 25873 T38 oascc.SolrZkClient.makePath makePath: /collections/control_collection
   [junit4]   2> 25879 T38 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
   [junit4]   2> 25885 T38 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
   [junit4]   2> 25922 T38 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
   [junit4]   2> 25939 T38 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
   [junit4]   2> 25939 T38 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
   [junit4]   2> 26047 T38 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
   [junit4]   2> 26048 T38 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
   [junit4]   2> 26054 T38 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
   [junit4]   2> 26055 T38 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
   [junit4]   2> 26061 T38 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
   [junit4]   2> 26063 T38 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
   [junit4]   2> 26069 T38 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
   [junit4]   2> 26070 T38 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
   [junit4]   2> 26076 T38 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 26077 T38 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 26083 T38 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
   [junit4]   2> 26084 T38 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
   [junit4]   2> 26090 T38 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
   [junit4]   2> 26091 T38 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
   [junit4]   2> 26439 T38 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 26449 T38 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:13412
   [junit4]   2> 26450 T38 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 26451 T38 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 26452 T38 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.AliasIntegrationTest-controljetty-1374712855428
   [junit4]   2> 26452 T38 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.AliasIntegrationTest-controljetty-1374712855428/'
   [junit4]   2> 26499 T38 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.AliasIntegrationTest-controljetty-1374712855428/solr.xml
   [junit4]   2> 26619 T38 oasc.CoreContainer.<init> New CoreContainer 1856259094
   [junit4]   2> 26620 T38 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.AliasIntegrationTest-controljetty-1374712855428/]
   [junit4]   2> 26622 T38 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 26623 T38 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 26624 T38 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 26625 T38 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 26625 T38 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 26626 T38 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 26627 T38 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 26628 T38 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 26628 T38 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 26629 T38 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
   [junit4]   2> 26650 T38 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:65381/solr
   [junit4]   2> 26690 T38 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 26692 T38 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 26713 T58 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@86f0f53 name:ZooKeeperConnection Watcher:127.0.0.1:65381 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 26714 T38 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 26726 T38 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
   [junit4]   2> 26750 T38 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 26753 T60 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@24022385 name:ZooKeeperConnection Watcher:127.0.0.1:65381/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 26754 T38 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 26774 T38 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 26796 T38 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 26822 T38 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 26826 T38 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:13412_v%2Fhn
   [junit4]   2> 26836 T38 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:13412_v%2Fhn
   [junit4]   2> 26844 T38 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 26884 T38 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 26890 T38 oasc.Overseer.start Overseer (id=90093181525164035-127.0.0.1:13412_v%2Fhn-n_0000000000) starting
   [junit4]   2> 26931 T38 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 26962 T62 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 26962 T38 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 26967 T38 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 26971 T38 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 27010 T61 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 27039 T63 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 27040 T63 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 27043 T63 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 28524 T61 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 28533 T61 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:13412_v%2Fhn",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:13412/v/hn"}
   [junit4]   2> 28534 T61 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with numShards 1
   [junit4]   2> 28576 T61 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 28621 T60 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> 29046 T63 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 29047 T63 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.AliasIntegrationTest-controljetty-1374712855428/collection1
   [junit4]   2> 29047 T63 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
   [junit4]   2> 29049 T63 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 29049 T63 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
   [junit4]   2> 29052 T63 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.AliasIntegrationTest-controljetty-1374712855428/collection1/'
   [junit4]   2> 29054 T63 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.AliasIntegrationTest-controljetty-1374712855428/collection1/lib/classes/' to classloader
   [junit4]   2> 29055 T63 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.AliasIntegrationTest-controljetty-1374712855428/collection1/lib/README' to classloader
   [junit4]   2> 29183 T63 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_45
   [junit4]   2> 29261 T63 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 29363 T63 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 29443 T63 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 30223 T63 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 30223 T63 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 30225 T63 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 30241 T63 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 30245 T63 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 30276 T63 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 30283 T63 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 30288 T63 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 30290 T63 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 30290 T63 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 30291 T63 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 30292 T63 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 30292 T63 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 30293 T63 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 30293 T63 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.AliasIntegrationTest-controljetty-1374712855428/collection1/, dataDir=./org.apache.solr.cloud.AliasIntegrationTest-1374712852315/control/data/
   [junit4]   2> 30294 T63 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@23d48279
   [junit4]   2> 30295 T63 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.AliasIntegrationTest-1374712852315/control/data
   [junit4]   2> 30295 T63 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.AliasIntegrationTest-1374712852315/control/data/index/
   [junit4]   2> 30296 T63 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.AliasIntegrationTest-1374712852315/control/data/index' doesn't exist. Creating new index...
   [junit4]   2> 30296 T63 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.AliasIntegrationTest-1374712852315/control/data/index
   [junit4]   2> 30301 T63 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=BaseDirectoryWrapper(RateLimitedDirectoryWrapper(org.apache.lucene.store.RAMDirectory@4c191dcf lockFactory=org.apache.lucene.store.NativeFSLockFactory@9ca617e)),segFN=segments_1,generation=1}
   [junit4]   2> 30302 T63 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 30387 T63 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 30388 T63 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 30389 T63 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 30390 T63 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 30391 T63 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 30391 T63 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 30392 T63 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 30392 T63 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 30393 T63 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 30413 T63 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 30421 T63 oass.SolrIndexSearcher.<init> Opening Searcher@1cd08da6 main
   [junit4]   2> 30423 T63 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 30423 T63 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 30430 T64 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1cd08da6 main{StandardDirectoryReader(segments_1:1)}
   [junit4]   2> 30434 T63 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 30434 T63 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:13412/v/hn collection:control_collection shard:shard1
   [junit4]   2> 30449 T63 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=30000&socketTimeout=30000&retry=false
   [junit4]   2> 30465 T63 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
   [junit4]   2> 30493 T63 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 30505 T63 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 30506 T63 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> 30513 T63 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:13412/v/hn/collection1/
   [junit4]   2> 30514 T63 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 30515 T63 oasc.SyncStrategy.syncToMe http://127.0.0.1:13412/v/hn/collection1/ has no replicas
   [junit4]   2> 30515 T63 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:13412/v/hn/collection1/ shard1
   [junit4]   2> 30516 T63 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
   [junit4]   2> 31633 T61 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 31655 T60 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> 31706 T63 oasc.ZkController.register We are http://127.0.0.1:13412/v/hn/collection1/ and leader is http://127.0.0.1:13412/v/hn/collection1/
   [junit4]   2> 31707 T63 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:13412/v/hn
   [junit4]   2> 31707 T63 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 31708 T63 oasc.ZkController.publish publishing core=collection1 state=active
   [junit4]   2> 31708 T63 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 31711 T63 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 31714 T38 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0
   [junit4]   2> 31715 T38 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 31850 T38 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> 31881 T38 oascsi.HttpClientUtil.createClient Creating new http client, config:
   [junit4]   2> 31890 T38 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 31893 T67 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4bb95ca4 name:ZooKeeperConnection Watcher:127.0.0.1:65381/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 31894 T38 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 31896 T38 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 31904 T38 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
   [junit4]   2> 32249 T38 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 32253 T38 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:42488
   [junit4]   2> 32254 T38 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 32255 T38 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 32256 T38 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.AliasIntegrationTest-jetty1-1374712861233
   [junit4]   2> 32257 T38 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.AliasIntegrationTest-jetty1-1374712861233/'
   [junit4]   2> 32298 T38 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.AliasIntegrationTest-jetty1-1374712861233/solr.xml
   [junit4]   2> 32407 T38 oasc.CoreContainer.<init> New CoreContainer 546299815
   [junit4]   2> 32408 T38 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.AliasIntegrationTest-jetty1-1374712861233/]
   [junit4]   2> 32411 T38 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 32411 T38 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 32412 T38 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 32413 T38 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 32414 T38 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 32414 T38 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 32415 T38 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 32416 T38 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 32417 T38 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 32417 T38 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
   [junit4]   2> 32438 T38 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:65381/solr
   [junit4]   2> 32439 T38 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 32440 T38 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 32444 T78 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5d3469f6 name:ZooKeeperConnection Watcher:127.0.0.1:65381 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 32444 T38 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 32448 T38 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
   [junit4]   2> 32466 T38 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 32469 T80 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@59fb6ce4 name:ZooKeeperConnection Watcher:127.0.0.1:65381/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 32470 T38 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 32479 T38 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 33168 T61 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 33171 T61 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:13412_v%2Fhn",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:13412/v/hn"}
   [junit4]   2> 33310 T80 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> 33310 T60 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> 33310 T67 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> 33486 T38 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:42488_v%2Fhn
   [junit4]   2> 33489 T38 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:42488_v%2Fhn
   [junit4]   2> 33494 T67 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 33494 T60 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 33494 T80 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 33495 T60 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> 33494 T67 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> 33495 T80 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> 33512 T81 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 33513 T81 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 33515 T81 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 34819 T61 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 34822 T61 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":"collection1",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:42488_v%2Fhn",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:42488/v/hn"}
   [junit4]   2> 34822 T61 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with numShards 1
   [junit4]   2> 34823 T61 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 34837 T60 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> 34837 T80 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> 34837 T67 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> 35518 T81 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 35518 T81 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.AliasIntegrationTest-jetty1-1374712861233/collection1
   [junit4]   2> 35519 T81 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 35521 T81 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 35521 T81 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 35523 T81 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.AliasIntegrationTest-jetty1-1374712861233/collection1/'
   [junit4]   2> 35525 T81 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.AliasIntegrationTest-jetty1-1374712861233/collection1/lib/README' to classloader
   [junit4]   2> 35526 T81 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.AliasIntegrationTest-jetty1-1374712861233/collection1/lib/classes/' to classloader
   [junit4]   2> 35603 T81 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_45
   [junit4]   2> 35700 T81 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 35802 T81 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 35870 T81 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 36640 T81 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 36640 T81 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 36642 T81 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 36658 T81 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 36661 T81 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 36694 T81 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 36700 T81 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 36706 T81 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 36708 T81 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 36708 T81 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 36708 T81 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 36710 T81 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 36711 T81 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 36711 T81 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 36711 T81 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.AliasIntegrationTest-jetty1-1374712861233/collection1/, dataDir=./org.apache.solr.cloud.AliasIntegrationTest-1374712852315/jetty1/
   [junit4]   2> 36712 T81 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@23d48279
   [junit4]   2> 36714 T81 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.AliasIntegrationTest-1374712852315/jetty1
   [junit4]   2> 36714 T81 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.AliasIntegrationTest-1374712852315/jetty1/index/
   [junit4]   2> 36714 T81 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.AliasIntegrationTest-1374712852315/jetty1/index' doesn't exist. Creating new index...
   [junit4]   2> 36715 T81 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.AliasIntegrationTest-1374712852315/jetty1/index
   [junit4]   2> 36718 T81 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=BaseDirectoryWrapper(RateLimitedDirectoryWrapper(org.apache.lucene.store.RAMDirectory@7e973909 lockFactory=org.apache.lucene.store.NativeFSLockFactory@6d97768d)),segFN=segments_1,generation=1}
   [junit4]   2> 36719 T81 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 36726 T81 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 36727 T81 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 36728 T81 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 36729 T81 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 36730 T81 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 36731 T81 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 36731 T81 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 36732 T81 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 36733 T81 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 36747 T81 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 36753 T81 oass.SolrIndexSearcher.<init> Opening Searcher@735b8caa main
   [junit4]   2> 36755 T81 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 36755 T81 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 36764 T82 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@735b8caa main{StandardDirectoryReader(segments_1:1)}
   [junit4]   2> 36768 T81 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 36768 T81 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:42488/v/hn collection:collection1 shard:shard1
   [junit4]   2> 36769 T81 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=30000&socketTimeout=30000&retry=false
   [junit4]   2> 36786 T81 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 36807 T81 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 36819 T81 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 36820 T81 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> 36820 T81 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:42488/v/hn/collection1/
   [junit4]   2> 36820 T81 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 36821 T81 oasc.SyncStrategy.syncToMe http://127.0.0.1:42488/v/hn/collection1/ has no replicas
   [junit4]   2> 36821 T81 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:42488/v/hn/collection1/ shard1
   [junit4]   2> 36822 T81 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 37849 T61 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 37887 T60 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> 37887 T80 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> 37887 T67 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> 37915 T81 oasc.ZkController.register We are http://127.0.0.1:42488/v/hn/collection1/ and leader is http://127.0.0.1:42488/v/hn/collection1/
   [junit4]   2> 37915 T81 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:42488/v/hn
   [junit4]   2> 37916 T81 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 37916 T81 oasc.ZkController.publish publishing core=collection1 state=active
   [junit4]   2> 37917 T81 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 37920 T81 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 37922 T38 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0
   [junit4]   2> 37924 T38 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 37925 T38 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> 38278 T38 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 38282 T38 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:35003
   [junit4]   2> 38283 T38 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 38284 T38 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 38285 T38 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.AliasIntegrationTest-jetty2-1374712867270
   [junit4]   2> 38286 T38 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.AliasIntegrationTest-jetty2-1374712867270/'
   [junit4]   2> 38341 T38 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.AliasIntegrationTest-jetty2-1374712867270/solr.xml
   [junit4]   2> 38460 T38 oasc.CoreContainer.<init> New CoreContainer 896136118
   [junit4]   2> 38461 T38 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.AliasIntegrationTest-jetty2-1374712867270/]
   [junit4]   2> 38463 T38 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 38464 T38 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 38465 T38 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 38465 T38 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 38466 T38 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 38467 T38 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 38467 T38 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 38468 T38 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 38469 T38 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 38470 T38 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
   [junit4]   2> 38494 T38 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:65381/solr
   [junit4]   2> 38495 T38 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 38496 T38 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 38502 T94 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1603f9aa name:ZooKeeperConnection Watcher:127.0.0.1:65381 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 38503 T38 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 38507 T38 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
   [junit4]   2> 38522 T38 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 38525 T96 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7ac7c9cc name:ZooKeeperConnection Watcher:127.0.0.1:65381/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 38525 T38 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 38539 T38 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 39400 T61 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 39403 T61 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":"collection1",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:42488_v%2Fhn",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:42488/v/hn"}
   [junit4]   2> 39438 T96 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> 39438 T80 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> 39438 T67 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> 39438 T60 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> 39546 T38 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:35003_v%2Fhn
   [junit4]   2> 39552 T38 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:35003_v%2Fhn
   [junit4]   2> 39557 T60 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 39557 T96 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 39557 T67 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 39557 T60 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> 39557 T80 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 39558 T67 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> 39558 T96 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> 39559 T80 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> 39570 T97 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 39571 T97 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 39573 T97 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 40947 T61 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 40950 T61 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "core_node_name":"core_node2",
   [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":"collection1",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:35003_v%2Fhn",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:35003/v/hn"}
   [junit4]   2> 40950 T61 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=1
   [junit4]   2> 40951 T61 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 40960 T60 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> 40960 T80 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> 40960 T96 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> 40960 T67 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> 41576 T97 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 41576 T97 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.AliasIntegrationTest-jetty2-1374712867270/collection1
   [junit4]   2> 41577 T97 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 41578 T97 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 41579 T97 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 41581 T97 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.AliasIntegrationTest-jetty2-1374712867270/collection1/'
   [junit4]   2> 41583 T97 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.AliasIntegrationTest-jetty2-1374712867270/collection1/lib/classes/' to classloader
   [junit4]   2> 41585 T97 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.AliasIntegrationTest-jetty2-1374712867270/collection1/lib/README' to classloader
   [junit4]   2> 41661 T97 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_45
   [junit4]   2> 41746 T97 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 41849 T97 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 41891 T97 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 42748 T97 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 42748 T97 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 42752 T97 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 42776 T97 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 42781 T97 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 42821 T97 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 42829 T97 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 42835 T97 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 42837 T97 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 42837 T97 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 42838 T97 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 42840 T97 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 42840 T97 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 42841 T97 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 42841 T97 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.AliasIntegrationTest-jetty2-1374712867270/collection1/, dataDir=./org.apache.solr.cloud.AliasIntegrationTest-1374712852315/jetty2/
   [junit4]   2> 42842 T97 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@23d48279
   [junit4]   2> 42844 T97 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.AliasIntegrationTest-1374712852315/jetty2
   [junit4]   2> 42844 T97 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.AliasIntegrationTest-1374712852315/jetty2/index/
   [junit4]   2> 42844 T97 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.AliasIntegrationTest-1374712852315/jetty2/index' doesn't exist. Creating new index...
   [junit4]   2> 42845 T97 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.AliasIntegrationTest-1374712852315/jetty2/index
   [junit4]   2> 42850 T97 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=BaseDirectoryWrapper(RateLimitedDirectoryWrapper(org.apache.lucene.store.RAMDirectory@37f62c6f lockFactory=org.apache.lucene.store.NativeFSLockFactory@63282cef)),segFN=segments_1,generation=1}
   [junit4]   2> 42851 T97 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 42861 T97 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 42862 T97 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 42863 T97 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 42864 T97 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 42866 T97 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 42866 T97 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 42867 T97 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 42868 T97 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 42869 T97 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 42891 T97 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 42902 T97 oass.SolrIndexSearcher.<init> Opening Searcher@76536b78 main
   [junit4]   2> 42903 T97 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 42904 T97 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 42915 T98 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@76536b78 main{StandardDirectoryReader(segments_1:1)}
   [junit4]   2> 42921 T97 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 42921 T97 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:35003/v/hn collection:collection1 shard:shard1
   [junit4]   2> 42922 T97 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=30000&socketTimeout=30000&retry=false
   [junit4]   2> 42952 T97 oasc.ZkController.register We are http://127.0.0.1:35003/v/hn/collection1/ and leader is http://127.0.0.1:42488/v/hn/collection1/
   [junit4]   2> 42952 T97 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:35003/v/hn
   [junit4]   2> 42953 T97 oasc.ZkController.checkRecovery Core needs to recover:collection1
   [junit4]   2> 42953 T97 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
   [junit4]   2> ASYNC  NEW_CORE C4 name=collection1 org.apache.solr.core.SolrCore@63c6ec18 url=http://127.0.0.1:35003/v/hn/collection1 node=127.0.0.1:35003_v%2Fhn C4_STATE=coll:collection1 core:collection1 props:{state=down, core=collection1, node_name=127.0.0.1:35003_v%2Fhn, base_url=http://127.0.0.1:35003/v/hn}
   [junit4]   2> 42959 T99 C4 P35003 oasc.RecoveryStrategy.run Starting recovery process.  core=collection1 recoveringAfterStartup=true
   [junit4]   2> 42959 T97 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 42960 T99 C4 P35003 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
   [junit4]   2> 42961 T99 C4 P35003 oasc.ZkController.publish publishing core=collection1 state=recovering
   [junit4]   2> 42961 T99 C4 P35003 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 42962 T38 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0
   [junit4]   2> 42962 T38 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 42963 T38 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> 42996 T99 C4 P35003 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> 43347 T38 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 43351 T38 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:29786
   [junit4]   2> 43352 T38 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 43353 T38 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 43353 T38 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.AliasIntegrationTest-jetty3-1374712872307
   [junit4]   2> 43354 T38 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.AliasIntegrationTest-jetty3-1374712872307/'
   [junit4]   2> 43409 T38 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.AliasIntegrationTest-jetty3-1374712872307/solr.xml
   [junit4]   2> 43549 T38 oasc.CoreContainer.<init> New CoreContainer 2011441115
   [junit4]   2> 43550 T38 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.AliasIntegrationTest-jetty3-1374712872307/]
   [junit4]   2> 43552 T38 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 43553 T38 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 43554 T38 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 43554 T38 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 43555 T38 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 43556 T38 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 43556 T38 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 43557 T38 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 43558 T38 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 43558 T38 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
   [junit4]   2> 43578 T38 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:65381/solr
   [junit4]   2> 43579 T38 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 43580 T38 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 43586 T111 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7aea369a name:ZooKeeperConnection Watcher:127.0.0.1:65381 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 43586 T38 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 43589 T38 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
   [junit4]   2> 43599 T38 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 43601 T113 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@65a8f181 name:ZooKeeperConnection Watcher:127.0.0.1:65381/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 43602 T38 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 43614 T38 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 43970 T61 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 43973 T61 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "core_node_name":"core_node2",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "state":"recovering",
   [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:35003_v%2Fhn",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:35003/v/hn"}
   [junit4]   2> 43995 T113 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> 43995 T80 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> 43995 T96 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> 43995 T60 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> 43995 T67 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> 44090 T70 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: core_node2, state: recovering, checkLive: true, onlyIfLeader: true
   [junit4]   2> 44091 T70 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: core_node2, state: recovering, checkLive: true, onlyIfLeader: true for: 0 seconds.
   [junit4]   2> 44092 T70 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={coreNodeName=core_node2&state=recovering&nodeName=127.0.0.1:35003_v%252Fhn&action=PREPRECOVERY&checkLive=true&core=collection1&wt=javabin&onlyIfLeader=true&version=2} status=0 QTime=6 
   [junit4]   2> 44620 T38 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:29786_v%2Fhn
   [junit4]   2> 44651 T38 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:29786_v%2Fhn
   [junit4]   2> 44655 T113 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 44656 T96 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 44656 T67 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 44657 T96 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> 44656 T80 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 44656 T113 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> 44656 T60 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 44658 T80 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> 44657 T67 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> 44660 T60 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> 44674 T114 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 44675 T114 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 44677 T114 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 45502 T61 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 45505 T61 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "core_node_name":"core_node3",
   [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":"collection1",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:29786_v%2Fhn",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:29786/v/hn"}
   [junit4]   2> 45507 T61 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=1
   [junit4]   2> 45507 T61 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 45521 T113 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> 45522 T96 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> 45522 T80 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> 45521 T60 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> 45521 T67 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> 45678 T114 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 45679 T114 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.AliasIntegrationTest-jetty3-1374712872307/collection1
   [junit4]   2> 45680 T114 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 45681 T114 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 45682 T114 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 45684 T114 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.AliasIntegrationTest-jetty3-1374712872307/collection1/'
   [junit4]   2> 45687 T114 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.AliasIntegrationTest-jetty3-1374712872307/collection1/lib/README' to classloader
   [junit4]   2> 45689 T114 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.AliasIntegrationTest-jetty3-1374712872307/collection1/lib/classes/' to classloader
   [junit4]   2> 45819 T114 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_45
   [junit4]   2> 45901 T114 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 46004 T114 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 46044 T114 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> ASYNC  NEW_CORE C5 name=collection1 org.apache.solr.core.SolrCore@63c6ec18 url=http://127.0.0.1:35003/v/hn/collection1 node=127.0.0.1:35003_v%2Fhn C5_STATE=coll:collection1 core:collection1 props:{state=recovering, core=collection1, node_name=127.0.0.1:35003_v%2Fhn, base_url=http://127.0.0.1:35003/v/hn}
   [junit4]   2> 46160 T99 C5 P35003 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:42488/v/hn/collection1/ core=collection1 - recoveringAfterStartup=true
   [junit4]   2> 46178 T99 C5 P35003 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&connTimeout=30000&socketTimeout=30000&retry=false
   [junit4]   2> 46217 T99 C5 P35003 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:35003/v/hn START replicas=[http://127.0.0.1:42488/v/hn/collection1/] nUpdates=100
   [junit4]   2> 46235 T99 C5 P35003 oasu.PeerSync.sync WARN no frame of reference to tell of we've missed updates
   [junit4]   2> 46236 T99 C5 P35003 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
   [junit4]   2> 46236 T99 C5 P35003 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
   [junit4]   2> 46237 T99 C5 P35003 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
   [junit4]   2> 46237 T99 C5 P35003 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
   [junit4]   2> 46238 T99 C5 P35003 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:42488/v/hn/collection1/. core=collection1
   [junit4]   2> 46238 T99 C5 P35003 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> ASYNC  NEW_CORE C6 name=collection1 org.apache.solr.core.SolrCore@77dadfb3 url=http://127.0.0.1:42488/v/hn/collection1 node=127.0.0.1:42488_v%2Fhn C6_STATE=coll:collection1 core:collection1 props:{state=active, core=collection1, node_name=127.0.0.1:42488_v%2Fhn, base_url=http://127.0.0.1:42488/v/hn, leader=true}
   [junit4]   2> 46314 T72 C6 P42488 oasc.SolrCore.execute [collection1] webapp=/v/hn path=/get params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=12 
   [junit4]   2> 46363 T71 C6 P42488 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 46367 T71 C6 P42488 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=BaseDirectoryWrapper(RateLimitedDirectoryWrapper(org.apache.lucene.store.RAMDirectory@7e973909 lockFactory=org.apache.lucene.store.NativeFSLockFactory@6d97768d)),segFN=segments_1,generation=1}
   [junit4]   2> 46367 T71 C6 P42488 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 46368 T71 C6 P42488 oasu.DirectUpdateHandler2.commit No uncommitted changes. Skipping IW.commit.
   [junit4]   2> 46369 T71 C6 P42488 oass.SolrIndexSearcher.<init> Opening Searcher@14e5e48c realtime
   [junit4]   2> 46370 T71 C6 P42488 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 46370 T71 C6 P42488 oasup.LogUpdateProcessor.finish [collection1] webapp=/v/hn path=/update params={waitSearcher=true&openSearcher=false&commit=true&wt=javabin&commit_end_point=true&version=2&softCommit=false} {commit=} 0 67
   [junit4]   2> 46372 T99 C5 P35003 oash.ReplicationHandler.inform Commits will be reserved for  10000
   [junit4]   2> 46373 T99 C5 P35003 oascsi.HttpClientUtil.createClient Creating new http client, config:connTimeout=5000&socketTimeout=20000&allowCompression=false&maxConnections=10000&maxConnectionsPerHost=10000
   [junit4]   2> 46407 T99 C5 P35003 oash.SnapPuller.<init>  No value set for 'pollInterval'. Timer Task not started.
   [junit4]   2> 46502 T73 C6 P42488 oash.ReplicationHandler.inform Commits will be reserved for  10000
   [junit4]   2> 46503 T73 C6 P42488 oasc.SolrCore.execute [collection1] webapp=/v/hn path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=92 
   [junit4]   2> 46505 T99 C5 P35003 oasc.RecoveryStrategy.replay No replay needed. core=collection1
   [junit4]   2> 46506 T99 C5 P35003 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
   [junit4]   2> 46506 T99 C5 P35003 oasc.ZkController.publish publishing core=collection1 state=active
   [junit4]   2> 46507 T99 C5 P35003 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 46509 T99 C5 P35003 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
   [junit4]   2> 46851 T114 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 46852 T114 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 46853 T114 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 46870 T114 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 46874 T114 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 46905 T114 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 46924 T114 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 46929 T114 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 46931 T114 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 46931 T114 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 46932 T114 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 46933 T114 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 46933 T114 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 46934 T114 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 46934 T114 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.AliasIntegrationTest-jetty3-1374712872307/collection1/, dataDir=./org.apache.solr.cloud.AliasIntegrationTest-1374712852315/jetty3/
   [junit4]   2> 46935 T114 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@23d48279
   [junit4]   2> 46936 T114 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.AliasIntegrationTest-1374712852315/jetty3
   [junit4]   2> 46936 T114 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.AliasIntegrationTest-1374712852315/jetty3/index/
   [junit4]   2> 46936 T114 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.AliasIntegrationTest-1374712852315/jetty3/index' doesn't exist. Creating new index...
   [junit4]   2> 46937 T114 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.AliasIntegrationTest-1374712852315/jetty3/index
   [junit4]   2> 46941 T114 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=BaseDirectoryWrapper(RateLimitedDirectoryWrapper(org.apache.lucene.store.RAMDirectory@7bf89b42 lockFactory=org.apache.lucene.store.NativeFSLockFactory@37e64c3a)),segFN=segments_1,generation=1}
   [junit4]   2> 46942 T114 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 46950 T114 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 46950 T114 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 46951 T114 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 46952 T114 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 46953 T114 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 46953 T114 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 46959 T114 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 46960 T114 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 46961 T114 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 46974 T114 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 46981 T114 oass.SolrIndexSearcher.<init> Opening Searcher@392bf3aa main
   [junit4]   2> 46983 T114 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 

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

r.request(HttpSolrServer.java:180)
   [junit4]   2> 	        at org.apache.solr.cloud.SyncStrategy$1.run(SyncStrategy.java:291)
   [junit4]   2> 	        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
   [junit4]   2> 	        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
   [junit4]   2> 	        at java.lang.Thread.run(Thread.java:722)
   [junit4]   2> 122954 T37 ccr.ThreadLeakControl.tryToInterruptAll Starting to interrupt leaked threads:
   [junit4]   2> 	   1) Thread[id=183, name=recoveryCmdExecutor-49-thread-1, state=RUNNABLE, group=TGRP-AliasIntegrationTest]
   [junit4]   2> 125961 T37 ccr.ThreadLeakControl.tryToInterruptAll SEVERE There are still zombie threads that couldn't be terminated:
   [junit4]   2> 	   1) Thread[id=183, name=recoveryCmdExecutor-49-thread-1, state=RUNNABLE, group=TGRP-AliasIntegrationTest]
   [junit4]   2> 	        at java.net.PlainSocketImpl.socketConnect(Native Method)
   [junit4]   2> 	        at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:339)
   [junit4]   2> 	        at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:200)
   [junit4]   2> 	        at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:182)
   [junit4]   2> 	        at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:391)
   [junit4]   2> 	        at java.net.Socket.connect(Socket.java:579)
   [junit4]   2> 	        at org.apache.http.conn.scheme.PlainSocketFactory.connectSocket(PlainSocketFactory.java:127)
   [junit4]   2> 	        at org.apache.http.impl.conn.DefaultClientConnectionOperator.openConnection(DefaultClientConnectionOperator.java:180)
   [junit4]   2> 	        at org.apache.http.impl.conn.ManagedClientConnectionImpl.open(ManagedClientConnectionImpl.java:294)
   [junit4]   2> 	        at org.apache.http.impl.client.DefaultRequestDirector.tryConnect(DefaultRequestDirector.java:645)
   [junit4]   2> 	        at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:480)
   [junit4]   2> 	        at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:906)
   [junit4]   2> 	        at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:805)
   [junit4]   2> 	        at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:784)
   [junit4]   2> 	        at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:365)
   [junit4]   2> 	        at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:180)
   [junit4]   2> 	        at org.apache.solr.cloud.SyncStrategy$1.run(SyncStrategy.java:291)
   [junit4]   2> 	        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
   [junit4]   2> 	        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
   [junit4]   2> 	        at java.lang.Thread.run(Thread.java:722)
   [junit4]   2> NOTE: test params are: codec=Lucene3x, sim=DefaultSimilarity, locale=ar_SA, timezone=GB-Eire
   [junit4]   2> NOTE: FreeBSD 9.1-RELEASE-p3 amd64/Oracle Corporation 1.7.0_21 (64-bit)/cpus=16,threads=2,free=48373376,total=175112192
   [junit4]   2> NOTE: All tests run in this JVM: [SolrPluginUtilsTest, NumericFieldsTest, TestDynamicFieldResource, AliasIntegrationTest]
   [junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=AliasIntegrationTest -Dtests.seed=3F7679C7E4926DB9 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=ar_SA -Dtests.timezone=GB-Eire -Dtests.file.encoding=US-ASCII
   [junit4] ERROR   0.00s J0 | AliasIntegrationTest (suite) <<<
   [junit4]    > Throwable #1: com.carrotsearch.randomizedtesting.ThreadLeakError: 1 thread leaked from SUITE scope at org.apache.solr.cloud.AliasIntegrationTest: 
   [junit4]    >    1) Thread[id=183, name=recoveryCmdExecutor-49-thread-1, state=RUNNABLE, group=TGRP-AliasIntegrationTest]
   [junit4]    >         at java.net.PlainSocketImpl.socketConnect(Native Method)
   [junit4]    >         at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:339)
   [junit4]    >         at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:200)
   [junit4]    >         at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:182)
   [junit4]    >         at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:391)
   [junit4]    >         at java.net.Socket.connect(Socket.java:579)
   [junit4]    >         at org.apache.http.conn.scheme.PlainSocketFactory.connectSocket(PlainSocketFactory.java:127)
   [junit4]    >         at org.apache.http.impl.conn.DefaultClientConnectionOperator.openConnection(DefaultClientConnectionOperator.java:180)
   [junit4]    >         at org.apache.http.impl.conn.ManagedClientConnectionImpl.open(ManagedClientConnectionImpl.java:294)
   [junit4]    >         at org.apache.http.impl.client.DefaultRequestDirector.tryConnect(DefaultRequestDirector.java:645)
   [junit4]    >         at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:480)
   [junit4]    >         at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:906)
   [junit4]    >         at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:805)
   [junit4]    >         at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:784)
   [junit4]    >         at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:365)
   [junit4]    >         at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:180)
   [junit4]    >         at org.apache.solr.cloud.SyncStrategy$1.run(SyncStrategy.java:291)
   [junit4]    >         at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
   [junit4]    >         at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
   [junit4]    >         at java.lang.Thread.run(Thread.java:722)
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([3F7679C7E4926DB9]:0)Throwable #2: com.carrotsearch.randomizedtesting.ThreadLeakError: There are still zombie threads that couldn't be terminated:
   [junit4]    >    1) Thread[id=183, name=recoveryCmdExecutor-49-thread-1, state=RUNNABLE, group=TGRP-AliasIntegrationTest]
   [junit4]    >         at java.net.PlainSocketImpl.socketConnect(Native Method)
   [junit4]    >         at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:339)
   [junit4]    >         at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:200)
   [junit4]    >         at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:182)
   [junit4]    >         at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:391)
   [junit4]    >         at java.net.Socket.connect(Socket.java:579)
   [junit4]    >         at org.apache.http.conn.scheme.PlainSocketFactory.connectSocket(PlainSocketFactory.java:127)
   [junit4]    >         at org.apache.http.impl.conn.DefaultClientConnectionOperator.openConnection(DefaultClientConnectionOperator.java:180)
   [junit4]    >         at org.apache.http.impl.conn.ManagedClientConnectionImpl.open(ManagedClientConnectionImpl.java:294)
   [junit4]    >         at org.apache.http.impl.client.DefaultRequestDirector.tryConnect(DefaultRequestDirector.java:645)
   [junit4]    >         at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:480)
   [junit4]    >         at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:906)
   [junit4]    >         at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:805)
   [junit4]    >         at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:784)
   [junit4]    >         at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:365)
   [junit4]    >         at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:180)
   [junit4]    >         at org.apache.solr.cloud.SyncStrategy$1.run(SyncStrategy.java:291)
   [junit4]    >         at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
   [junit4]    >         at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
   [junit4]    >         at java.lang.Thread.run(Thread.java:722)
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([3F7679C7E4926DB9]:0)
   [junit4] Completed on J0 in 126.13s, 1 test, 2 errors <<< FAILURES!

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

Total time: 46 minutes 9 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-Java7 - Build # 1441 - Still Failing

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

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

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

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




Build Log:
[...truncated 9792 lines...]
   [junit4] Suite: org.apache.solr.cloud.BasicDistributedZkTest
   [junit4]   2> 984274 T3118 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
   [junit4]   2> 984281 T3118 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
   [junit4]   2> Creating dataDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./solrtest-BasicDistributedZkTest-1374729182841
   [junit4]   2> 984282 T3118 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   2> 984283 T3119 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 984384 T3118 oasc.ZkTestServer.run start zk server on port:33022
   [junit4]   2> 984385 T3118 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 984390 T3125 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@61d82ee9 name:ZooKeeperConnection Watcher:127.0.0.1:33022 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 984391 T3118 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 984391 T3118 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 984414 T3118 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 984422 T3127 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@14181c44 name:ZooKeeperConnection Watcher:127.0.0.1:33022/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 984422 T3118 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 984423 T3118 oascc.SolrZkClient.makePath makePath: /collections/collection1
   [junit4]   2> 984435 T3118 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
   [junit4]   2> 984438 T3118 oascc.SolrZkClient.makePath makePath: /collections/control_collection
   [junit4]   2> 984441 T3118 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
   [junit4]   2> 984449 T3118 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
   [junit4]   2> 984450 T3118 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
   [junit4]   2> 984464 T3118 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
   [junit4]   2> 984465 T3118 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
   [junit4]   2> 984568 T3118 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
   [junit4]   2> 984569 T3118 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
   [junit4]   2> 984572 T3118 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
   [junit4]   2> 984573 T3118 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
   [junit4]   2> 984576 T3118 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
   [junit4]   2> 984577 T3118 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
   [junit4]   2> 984580 T3118 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
   [junit4]   2> 984581 T3118 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
   [junit4]   2> 984584 T3118 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 984585 T3118 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 984587 T3118 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
   [junit4]   2> 984588 T3118 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
   [junit4]   2> 984596 T3118 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
   [junit4]   2> 984596 T3118 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
   [junit4]   2> 984873 T3118 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 984881 T3118 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:15462
   [junit4]   2> 984881 T3118 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 984882 T3118 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 984883 T3118 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374729183160
   [junit4]   2> 984883 T3118 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374729183160/'
   [junit4]   2> 984924 T3118 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374729183160/solr.xml
   [junit4]   2> 985014 T3118 oasc.CoreContainer.<init> New CoreContainer 1607797023
   [junit4]   2> 985015 T3118 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374729183160/]
   [junit4]   2> 985017 T3118 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 985018 T3118 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 985018 T3118 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 985019 T3118 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 985019 T3118 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 985020 T3118 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 985020 T3118 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 985021 T3118 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 985021 T3118 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 985022 T3118 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
   [junit4]   2> 985039 T3118 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:33022/solr
   [junit4]   2> 985040 T3118 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 985041 T3118 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 985044 T3138 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4b47da1a name:ZooKeeperConnection Watcher:127.0.0.1:33022 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 985045 T3118 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 985055 T3118 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
   [junit4]   2> 985067 T3118 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 985069 T3140 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6d7b60f5 name:ZooKeeperConnection Watcher:127.0.0.1:33022/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 985069 T3118 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 985072 T3118 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 985080 T3118 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 985084 T3118 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 985091 T3118 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:15462_
   [junit4]   2> 985092 T3118 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:15462_
   [junit4]   2> 985096 T3118 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 985112 T3118 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 985115 T3118 oasc.Overseer.start Overseer (id=90094251727126531-127.0.0.1:15462_-n_0000000000) starting
   [junit4]   2> 985129 T3118 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 985141 T3142 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 985142 T3118 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 985144 T3118 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 985147 T3118 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 985149 T3141 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 985155 T3143 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 985156 T3143 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 985157 T3143 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 986653 T3141 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 986655 T3141 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:15462_",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:15462"}
   [junit4]   2> 986655 T3141 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with numShards 1
   [junit4]   2> 986655 T3141 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 986670 T3140 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> 987159 T3143 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 987159 T3143 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374729183160/collection1
   [junit4]   2> 987159 T3143 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
   [junit4]   2> 987160 T3143 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 987161 T3143 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
   [junit4]   2> 987162 T3143 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374729183160/collection1/'
   [junit4]   2> 987163 T3143 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374729183160/collection1/lib/README' to classloader
   [junit4]   2> 987164 T3143 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374729183160/collection1/lib/classes/' to classloader
   [junit4]   2> 987222 T3143 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_45
   [junit4]   2> 987284 T3143 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 987386 T3143 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 987398 T3143 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 988052 T3143 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 988053 T3143 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 988054 T3143 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 988066 T3143 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 988070 T3143 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 988084 T3143 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 988090 T3143 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 988094 T3143 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 988095 T3143 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 988096 T3143 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 988096 T3143 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 988097 T3143 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 988097 T3143 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 988098 T3143 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 988098 T3143 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374729183160/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZkTest-1374729182840/control/data/
   [junit4]   2> 988098 T3143 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@38839ad7
   [junit4]   2> 988099 T3143 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374729182840/control/data
   [junit4]   2> 988100 T3143 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZkTest-1374729182840/control/data/index/
   [junit4]   2> 988100 T3143 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZkTest-1374729182840/control/data/index' doesn't exist. Creating new index...
   [junit4]   2> 988100 T3143 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374729182840/control/data/index
   [junit4]   2> 988105 T3143 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@71c71252 lockFactory=org.apache.lucene.store.NativeFSLockFactory@60a43180),segFN=segments_1,generation=1}
   [junit4]   2> 988106 T3143 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 988111 T3143 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 988111 T3143 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 988112 T3143 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 988113 T3143 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 988113 T3143 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 988114 T3143 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 988114 T3143 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 988115 T3143 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 988115 T3143 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 988132 T3143 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 988139 T3143 oass.SolrIndexSearcher.<init> Opening Searcher@5aa25013 main
   [junit4]   2> 988141 T3143 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 988141 T3143 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 988145 T3144 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@5aa25013 main{StandardDirectoryReader(segments_1:1)}
   [junit4]   2> 988147 T3143 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 988147 T3143 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:15462 collection:control_collection shard:shard1
   [junit4]   2> 988147 T3143 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=30000&socketTimeout=30000&retry=false
   [junit4]   2> 988163 T3143 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
   [junit4]   2> 988181 T3143 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 988184 T3143 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 988184 T3143 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> 988185 T3143 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:15462/collection1/
   [junit4]   2> 988185 T3143 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 988185 T3143 oasc.SyncStrategy.syncToMe http://127.0.0.1:15462/collection1/ has no replicas
   [junit4]   2> 988186 T3143 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:15462/collection1/ shard1
   [junit4]   2> 988186 T3143 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
   [junit4]   2> 989682 T3141 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 989705 T3140 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> 989722 T3143 oasc.ZkController.register We are http://127.0.0.1:15462/collection1/ and leader is http://127.0.0.1:15462/collection1/
   [junit4]   2> 989722 T3143 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:15462
   [junit4]   2> 989722 T3143 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 989722 T3143 oasc.ZkController.publish publishing core=collection1 state=active
   [junit4]   2> 989723 T3143 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 989725 T3143 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 989726 T3118 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0
   [junit4]   2> 989726 T3118 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 989727 T3118 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> 989737 T3118 oascsi.HttpClientUtil.createClient Creating new http client, config:
   [junit4]   2> 989738 T3118 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 989740 T3147 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@9b2848 name:ZooKeeperConnection Watcher:127.0.0.1:33022/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 989741 T3118 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 989743 T3118 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 989745 T3118 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
   [junit4]   2> 990028 T3118 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 990031 T3118 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:59751
   [junit4]   2> 990032 T3118 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 990033 T3118 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 990033 T3118 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374729188305
   [junit4]   2> 990034 T3118 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374729188305/'
   [junit4]   2> 990074 T3118 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374729188305/solr.xml
   [junit4]   2> 990165 T3118 oasc.CoreContainer.<init> New CoreContainer 890053653
   [junit4]   2> 990166 T3118 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374729188305/]
   [junit4]   2> 990168 T3118 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 990169 T3118 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 990169 T3118 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 990170 T3118 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 990170 T3118 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 990171 T3118 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 990171 T3118 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 990172 T3118 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 990172 T3118 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 990173 T3118 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
   [junit4]   2> 990189 T3118 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:33022/solr
   [junit4]   2> 990189 T3118 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 990190 T3118 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 990193 T3158 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1f7aad4a name:ZooKeeperConnection Watcher:127.0.0.1:33022 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 990194 T3118 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 990211 T3118 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
   [junit4]   2> 990221 T3118 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 990223 T3160 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@611d473b name:ZooKeeperConnection Watcher:127.0.0.1:33022/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 990224 T3118 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 990233 T3118 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 991219 T3141 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 991221 T3141 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:15462_",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:15462"}
   [junit4]   2> 991235 T3140 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> 991236 T3160 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> 991236 T3147 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> 991238 T3118 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:59751_
   [junit4]   2> 991245 T3118 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:59751_
   [junit4]   2> 991247 T3160 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> 991247 T3140 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 991247 T3147 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 991248 T3140 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> 991248 T3147 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> 991248 T3160 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 991256 T3161 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 991257 T3161 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 991258 T3161 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 992741 T3141 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 992743 T3141 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:59751_",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:59751"}
   [junit4]   2> 992743 T3141 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with numShards 2
   [junit4]   2> 992743 T3141 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 992758 T3140 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> 992758 T3160 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> 992758 T3147 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> 993260 T3161 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 993260 T3161 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374729188305/collection1
   [junit4]   2> 993260 T3161 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 993261 T3161 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 993261 T3161 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 993262 T3161 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374729188305/collection1/'
   [junit4]   2> 993264 T3161 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374729188305/collection1/lib/classes/' to classloader
   [junit4]   2> 993265 T3161 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374729188305/collection1/lib/README' to classloader
   [junit4]   2> 993324 T3161 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_45
   [junit4]   2> 993388 T3161 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 993489 T3161 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 993501 T3161 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 994158 T3161 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 994159 T3161 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 994160 T3161 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 994172 T3161 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 994177 T3161 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 994191 T3161 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 994196 T3161 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 994200 T3161 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 994201 T3161 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 994202 T3161 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 994202 T3161 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 994203 T3161 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 994203 T3161 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 994204 T3161 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 994204 T3161 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374729188305/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZkTest-1374729182840/jetty1/
   [junit4]   2> 994204 T3161 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@38839ad7
   [junit4]   2> 994205 T3161 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374729182840/jetty1
   [junit4]   2> 994206 T3161 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZkTest-1374729182840/jetty1/index/
   [junit4]   2> 994206 T3161 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZkTest-1374729182840/jetty1/index' doesn't exist. Creating new index...
   [junit4]   2> 994206 T3161 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374729182840/jetty1/index
   [junit4]   2> 994210 T3161 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@792b7657 lockFactory=org.apache.lucene.store.NativeFSLockFactory@7d193c43),segFN=segments_1,generation=1}
   [junit4]   2> 994211 T3161 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 994217 T3161 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 994217 T3161 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 994218 T3161 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 994219 T3161 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 994220 T3161 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 994220 T3161 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 994220 T3161 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 994221 T3161 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 994222 T3161 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 994238 T3161 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 994246 T3161 oass.SolrIndexSearcher.<init> Opening Searcher@b5d0c93 main
   [junit4]   2> 994247 T3161 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 994247 T3161 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 994252 T3162 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@b5d0c93 main{StandardDirectoryReader(segments_1:1)}
   [junit4]   2> 994255 T3161 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 994255 T3161 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:59751 collection:collection1 shard:shard1
   [junit4]   2> 994255 T3161 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=30000&socketTimeout=30000&retry=false
   [junit4]   2> 994273 T3161 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 994290 T3161 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 994302 T3161 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 994302 T3161 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> 994302 T3161 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:59751/collection1/
   [junit4]   2> 994303 T3161 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 994303 T3161 oasc.SyncStrategy.syncToMe http://127.0.0.1:59751/collection1/ has no replicas
   [junit4]   2> 994303 T3161 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:59751/collection1/ shard1
   [junit4]   2> 994304 T3161 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 995765 T3141 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 995785 T3140 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> 995785 T3160 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> 995785 T3147 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> 995798 T3161 oasc.ZkController.register We are http://127.0.0.1:59751/collection1/ and leader is http://127.0.0.1:59751/collection1/
   [junit4]   2> 995798 T3161 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:59751
   [junit4]   2> 995798 T3161 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 995798 T3161 oasc.ZkController.publish publishing core=collection1 state=active
   [junit4]   2> 995799 T3161 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 995800 T3161 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 995801 T3118 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0
   [junit4]   2> 995802 T3118 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 995803 T3118 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> 996095 T3118 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 996098 T3118 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:19072
   [junit4]   2> 996099 T3118 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 996099 T3118 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 996100 T3118 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374729194373
   [junit4]   2> 996100 T3118 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374729194373/'
   [junit4]   2> 996141 T3118 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374729194373/solr.xml
   [junit4]   2> 996231 T3118 oasc.CoreContainer.<init> New CoreContainer 1967178683
   [junit4]   2> 996232 T3118 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374729194373/]
   [junit4]   2> 996234 T3118 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 996234 T3118 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 996235 T3118 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 996235 T3118 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 996236 T3118 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 996236 T3118 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 996237 T3118 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 996237 T3118 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 996238 T3118 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 996238 T3118 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
   [junit4]   2> 996255 T3118 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:33022/solr
   [junit4]   2> 996256 T3118 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 996257 T3118 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 996260 T3174 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4aad613d name:ZooKeeperConnection Watcher:127.0.0.1:33022 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 996261 T3118 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 996278 T3118 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
   [junit4]   2> 996288 T3118 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 996290 T3176 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@67fa8d86 name:ZooKeeperConnection Watcher:127.0.0.1:33022/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 996290 T3118 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 996301 T3118 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 997290 T3141 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 997292 T3141 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:59751_",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:59751"}
   [junit4]   2> 997306 T3140 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> 997306 T3118 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:19072_
   [junit4]   2> 997306 T3160 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> 997306 T3147 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> 997306 T3176 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> 997315 T3118 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:19072_
   [junit4]   2> 997318 T3176 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> 997318 T3160 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> 997318 T3140 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 997318 T3147 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 997318 T3140 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> 997319 T3147 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> 997320 T3176 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 997320 T3160 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 997327 T3177 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 997328 T3177 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 997329 T3177 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 998817 T3141 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 998819 T3141 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:19072_",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:19072"}
   [junit4]   2> 998819 T3141 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
   [junit4]   2> 998819 T3141 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
   [junit4]   2> 998838 T3140 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> 998838 T3160 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> 998838 T3147 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> 998838 T3176 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> 999331 T3177 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 999331 T3177 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374729194373/collection1
   [junit4]   2> 999331 T3177 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 999332 T3177 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 999333 T3177 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 999334 T3177 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374729194373/collection1/'
   [junit4]   2> 999335 T3177 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374729194373/collection1/lib/README' to classloader
   [junit4]   2> 999336 T3177 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374729194373/collection1/lib/classes/' to classloader
   [junit4]   2> 999394 T3177 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_45
   [junit4]   2> 999456 T3177 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 999558 T3177 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 999570 T3177 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 1000225 T3177 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 1000226 T3177 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 1000227 T3177 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 1000240 T3177 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 1000244 T3177 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 1000258 T3177 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1000263 T3177 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1000267 T3177 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1000269 T3177 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1000269 T3177 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1000269 T3177 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1000270 T3177 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1000271 T3177 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1000271 T3177 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 1000272 T3177 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374729194373/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZkTest-1374729182840/jetty2/
   [junit4]   2> 1000272 T3177 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@38839ad7
   [junit4]   2> 1000273 T3177 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374729182840/jetty2
   [junit4]   2> 1000273 T3177 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZkTest-1374729182840/jetty2/index/
   [junit4]   2> 1000274 T3177 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZkTest-1374729182840/jetty2/index' doesn't exist. Creating new index...
   [junit4]   2> 1000274 T3177 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374729182840/jetty2/index
   [junit4]   2> 1000278 T3177 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@6420bc96 lockFactory=org.apache.lucene.store.NativeFSLockFactory@3956de9a),segFN=segments_1,generation=1}
   [junit4]   2> 1000278 T3177 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1000284 T3177 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 1000285 T3177 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1000286 T3177 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1000286 T3177 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 1000287 T3177 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 1000287 T3177 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 1000288 T3177 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 1000289 T3177 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 1000289 T3177 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 1000306 T3177 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 1000313 T3177 oass.SolrIndexSearcher.<init> Opening Searcher@26a00af main
   [junit4]   2> 1000314 T3177 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 1000315 T3177 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 1000319 T3178 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@26a00af main{StandardDirectoryReader(segments_1:1)}
   [junit4]   2> 1000322 T3177 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 1000322 T3177 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:19072 collection:collection1 shard:shard2
   [junit4]   2> 1000323 T3177 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=30000&socketTimeout=30000&retry=false
   [junit4]   2> 1000340 T3177 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
   [junit4]   2> 1000359 T3177 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
   [junit4]   2> 1000367 T3177 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 1000368 T3177 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> 1000368 T3177 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:19072/collection1/
   [junit4]   2> 1000368 T3177 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 1000369 T3177 oasc.SyncStrategy.syncToMe http://127.0.0.1:19072/collection1/ has no replicas
   [junit4]   2> 1000369 T3177 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:19072/collection1/ shard2
   [junit4]   2> 1000369 T3177 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
   [junit4]   2> 1001861 T3141 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1001879 T3140 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> 1001879 T3147 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> 1001879 T3160 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> 1001879 T3176 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> 1001913 T3177 oasc.ZkController.register We are http://127.0.0.1:19072/collection1/ and leader is http://127.0.0.1:19072/collection1/
   [junit4]   2> 1001913 T3177 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:19072
   [junit4]   2> 1001913 T3177 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 1001914 T3177 oasc.ZkController.publish publishing core=collection1 state=active
   [junit4]   2> 1001914 T3177 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1001916 T3177 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1001917 T3118 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0
   [junit4]   2> 1001918 T3118 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 1001919 T3118 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> 1002207 T3118 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 1002210 T3118 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:11485
   [junit4]   2> 1002211 T3118 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 1002211 T3118 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 1002212 T3118 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374729200489
   [junit4]   2> 1002212 T3118 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374729200489/'
   [junit4]   2> 1002253 T3118 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374729200489/solr.xml
   [junit4]   2> 1002343 T3118 oasc.CoreContainer.<init> New CoreContainer 1386303134
   [junit4]   2> 1002344 T3118 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374729200489/]
   [junit4]   2> 1002346 T3118 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 1002347 T3118 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 1002347 T3118 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 1002348 T3118 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 1002348 T3118 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 1002349 T3118 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 1002349 T3118 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 1002350 T3118 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 1002350 T3118 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 1002351 T3118 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
   [junit4]   2> 1002366 T3118 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:33022/solr
   [junit4]   2> 1002367 T3118 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 1002368 T3118 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1002371 T3190 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1cef5918 name:ZooKeeperConnection Watcher:127.0.0.1:33022 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1002372 T3118 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1002386 T3118 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
   [junit4]   2> 1002397 T3118 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1002399 T3192 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@55d72e11 name:ZooKeeperConnection Watcher:127.0.0.1:33022/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1002399 T3118 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1002405 T3118 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1003384 T3141 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1003386 T3141 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:19072_",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:19072"}
   [junit4]   2> 1003403 T3192 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> 1003403 T3140 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> 1003403 T3176 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> 1003403 T3147 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> 1003407 T3160 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> 1003408 T3118 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:11485_
   [junit4]   2> 1003472 T3118 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:11485_
   [junit4]   2> 1003475 T3192 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> 1003475 T3160 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> 1003475 T3176 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> 1003476 T3140 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 1003476 T3147 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 1003476 T3140 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> 1003477 T3147 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> 1003477 T3192 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 1003477 T3160 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 1003541 T3176 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 1003547 T3193 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 1003548 T3193 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1003549 T3193 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 1004974 T3141 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1004976 T3141 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:11485_",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:11485"}
   [junit4]   2> 1004976 T3141 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
   [junit4]   2> 1004976 T3141 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 1004981 T3140 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> 1004981 T3160 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> 1004981 T3147 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> 1004981 T3176 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> 1004981 T3192 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> 1005552 T3193 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 1005552 T3193 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374729200489/collection1
   [junit4]   2> 1005552 T3193 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 1005553 T3193 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 1005554 T3193 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 1005555 T3193 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374729200489/collection1/'
   [junit4]   2> 1005556 T3193 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374729200489/collection1/lib/classes/' to classloader
   [junit4]   2> 1005557 T3193 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374729200489/collection1/lib/README' to classloader
   [junit4]   2> 1005615 T3193 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_45
   [junit4]   2> 1005677 T3193 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 1005779 T3193 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 1005791 T3193 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 1006443 T3193 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 1006444 T3193 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 1006445 T3193 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 1006456 T3193 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 1006460 T3193 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 1006474 T3193 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1006479 T3193 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1006484 T3193 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1006485 T3193 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1006485 T3193 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1006485 T3193 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1006486 T3193 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1006487 T3193 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1006487 T3193 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 1006487 T3193 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374729200489/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZkTest-1374729182840/jetty3/
   [junit4]   2> 1006488 T3193 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@38839ad7
   [junit4]   2> 1006489 T3193 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374729182840/jetty3
   [junit4]   2> 1006489 T3193 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZkTest-1374729182840/jetty3/index/
   [junit4]   2> 1006489 T3193 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZkTest-1374729182840/jetty3/index' doesn't exist. Creating new index...
   [junit4]   2> 1006490 T3193 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374729182840/jetty3/index
   [junit4]   2> 1006493 T3193 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@359e1a19 lockFactory=org.apache.lucene.store.NativeFSLockFactory@5cef6f34),segFN=segments_1,generation=1}
   [junit4]   2> 1006494 T3193 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1006500 T3193 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 1006500 T3193 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1006501 T3193 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1006501 T3193 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 1006502 T3193 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 1006502 T3193 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 1006503 T3193 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 1006503 T3193 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 1006504 T3193 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 1006519 T3193 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 1006526 T3193 oass.SolrIndexSearcher.<init> Opening Searcher@72c52cf1 main
   [junit4]   2> 1006527 T3193 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 1006528 T3193 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 1006532 T3194 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@72c52cf1 main{StandardDirectoryReader(segments_1:1)}
   [junit4]   2> 1006535 T3193 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 1006535 T3193 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:11485 collection:collection1 shard:shard1
   [junit4]   2> 1006535 T3193 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=30000&socketTimeout=30000&retry=false
   [junit4]   2> 1006554 T3193 oasc.ZkController.register We are http://127.0.0.1:11485/collection1/ and leader is http://127.0.0.1:59751/collection1/
   [junit4]   2> 1006554 T3193 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:11485
   [junit4]   2> 1006554 T3193 oasc.ZkController.checkRecovery Core needs to recover:collection1
   [junit4]   2> 1006555 T3193 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
   [junit4]   2> ASYNC  NEW_CORE C1007 name=collection1 org.apache.solr.core.SolrCore@24cd12a url=http://127.0.0.1:11485/collection1 node=127.0.0.1:11485_ C1007_STATE=coll:collection1 core:collection1 props:{state=down, core=collection1, node_name=127.0.0.1:11485_, base_url=http://127.0.0.1:11485}
   [junit4]   2> 1006555 T3195 C1007 P11485 oasc.RecoveryStrategy.run Starting recovery process.  core=collection1 recoveringAfterStartup=true
   [junit4]   2> 1006555 T3195 C1007 P11485 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
   [junit4]   2> 1006555 T3193 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1006556 T3195 C1007 P11485 oasc.ZkController.publish publishing core=collection1 state=recovering
   [junit4]   2> 1006556 T3195 C1007 P11485 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1006557 T3118 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0
   [junit4]   2> 1006557 T3195 C1007 P11485 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> 1006557 T3118 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 1006558 T3118 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> 1006573 T3150 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: core_node3, state: recovering, checkLive: true, onlyIfLeader: true
   [junit4]   2> 1006851 T3118 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 1006854 T3118 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:61489
   [junit4]   2> 1006855 T3118 oass.SolrDispatchFilter.init SolrDispatchFi

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

MockVariableIntBlock(baseBlockSize=112), timestamp=PostingsFormat(name=Asserting), id=PostingsFormat(name=SimpleText), range_facet_sl=PostingsFormat(name=MockSep), range_facet_si=MockVariableIntBlock(baseBlockSize=112), oddField_s=PostingsFormat(name=MockSep), sequence_i=PostingsFormat(name=MockSep), name=PostingsFormat(name=SimpleText), foo_i=MockVariableIntBlock(baseBlockSize=112), regex_dup_B_s=PostingsFormat(name=Asserting), multiDefault=MockVariableIntBlock(baseBlockSize=112), n_tf1=PostingsFormat(name=Asserting), n_dt1=MockVariableIntBlock(baseBlockSize=112), genre_s=PostingsFormat(name=MockSep), author_t=MockVariableIntBlock(baseBlockSize=112), range_facet_l=PostingsFormat(name=Asserting), n_ti1=PostingsFormat(name=SimpleText), text=PostingsFormat(name=MockSep), _version_=PostingsFormat(name=Asserting), val_i=PostingsFormat(name=SimpleText), SubjectTerms_mfacet=PostingsFormat(name=Asserting), series_t=MockVariableIntBlock(baseBlockSize=112), a_t=PostingsFormat(name=Asserting), n_tdt1=PostingsFormat(name=Asserting), regex_dup_A_s=PostingsFormat(name=MockSep), price=PostingsFormat(name=MockSep), other_tl1=PostingsFormat(name=Asserting), n_l1=PostingsFormat(name=Asserting), a_si=MockVariableIntBlock(baseBlockSize=112), inStock=PostingsFormat(name=MockSep)}, docValues:{}, sim=DefaultSimilarity, locale=ko_KR, timezone=America/Winnipeg
   [junit4]   2> NOTE: FreeBSD 9.1-RELEASE-p3 amd64/Oracle Corporation 1.7.0_21 (64-bit)/cpus=16,threads=2,free=382015392,total=524288000
   [junit4]   2> NOTE: All tests run in this JVM: [TestDynamicFieldResource, TestQuerySenderNoQuery, HighlighterTest, TermVectorComponentDistributedTest, TestCopyFieldCollectionResource, TestUpdate, ExternalFileFieldSortTest, TestCSVResponseWriter, TestSchemaVersionResource, TestDistributedSearch, DirectSolrSpellCheckerTest, TestRTGBase, AddSchemaFieldsUpdateProcessorFactoryTest, SpellCheckCollatorTest, DistributedSpellCheckComponentTest, TestElisionMultitermQuery, DistributedTermsComponentTest, CSVRequestHandlerTest, CurrencyFieldXmlFileTest, TestDefaultSimilarityFactory, AssignTest, HdfsDirectoryTest, TestDocSet, QueryEqualityTest, TestBinaryField, SynonymTokenizerTest, TestJmxIntegration, EchoParamsTest, UpdateParamsTest, ChaosMonkeySafeLeaderTest, DocumentAnalysisRequestHandlerTest, SearchHandlerTest, ResponseLogComponentTest, TestFunctionQuery, TestSchemaResource, HdfsUnloadDistributedZkTest, SuggesterTest, PrimUtilsTest, TestShardHandlerFactory, CachingDirectoryFactoryTest, ParsingFieldUpdateProcessorsTest, TestRemoteStreaming, TestDistributedGrouping, TestReloadAndDeleteDocs, BasicDistributedZk2Test, SignatureUpdateProcessorFactoryTest, TestPseudoReturnFields, InfoHandlerTest, HighlighterConfigTest, NumericFieldsTest, TestRandomDVFaceting, HdfsChaosMonkeySafeLeaderTest, UniqFieldsUpdateProcessorFactoryTest, IndexSchemaRuntimeFieldTest, DOMUtilTest, TestFieldResource, TestSolrXMLSerializer, FastVectorHighlighterTest, TestRealTimeGet, TestQueryUtils, TestReversedWildcardFilterFactory, OutputWriterTest, SolrInfoMBeanTest, ScriptEngineTest, SuggesterWFSTTest, TestReplicationHandler, BadIndexSchemaTest, CollectionsAPIDistributedZkTest, DefaultValueUpdateProcessorTest, TestFuzzyAnalyzedSuggestions, TestSolr4Spatial, TestGroupingSearch, SolrTestCaseJ4Test, StressHdfsTest, TestConfig, TestBM25SimilarityFactory, TestFastOutputStream, BasicDistributedZkTest]
   [junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=BasicDistributedZkTest -Dtests.seed=75E5868DDF85DF78 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=ko_KR -Dtests.timezone=America/Winnipeg -Dtests.file.encoding=ISO-8859-1
   [junit4] ERROR   0.00s J0 | BasicDistributedZkTest (suite) <<<
   [junit4]    > Throwable #1: com.carrotsearch.randomizedtesting.ThreadLeakError: 1 thread leaked from SUITE scope at org.apache.solr.cloud.BasicDistributedZkTest: 
   [junit4]    >    1) Thread[id=3603, name=recoveryCmdExecutor-1840-thread-1, state=RUNNABLE, group=TGRP-BasicDistributedZkTest]
   [junit4]    >         at java.net.PlainSocketImpl.socketConnect(Native Method)
   [junit4]    >         at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:339)
   [junit4]    >         at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:200)
   [junit4]    >         at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:182)
   [junit4]    >         at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:391)
   [junit4]    >         at java.net.Socket.connect(Socket.java:579)
   [junit4]    >         at org.apache.http.conn.scheme.PlainSocketFactory.connectSocket(PlainSocketFactory.java:127)
   [junit4]    >         at org.apache.http.impl.conn.DefaultClientConnectionOperator.openConnection(DefaultClientConnectionOperator.java:180)
   [junit4]    >         at org.apache.http.impl.conn.ManagedClientConnectionImpl.open(ManagedClientConnectionImpl.java:294)
   [junit4]    >         at org.apache.http.impl.client.DefaultRequestDirector.tryConnect(DefaultRequestDirector.java:645)
   [junit4]    >         at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:480)
   [junit4]    >         at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:906)
   [junit4]    >         at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:805)
   [junit4]    >         at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:784)
   [junit4]    >         at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:365)
   [junit4]    >         at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:180)
   [junit4]    >         at org.apache.solr.cloud.SyncStrategy$1.run(SyncStrategy.java:291)
   [junit4]    >         at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
   [junit4]    >         at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
   [junit4]    >         at java.lang.Thread.run(Thread.java:722)
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([75E5868DDF85DF78]:0)Throwable #2: com.carrotsearch.randomizedtesting.ThreadLeakError: There are still zombie threads that couldn't be terminated:
   [junit4]    >    1) Thread[id=3603, name=recoveryCmdExecutor-1840-thread-1, state=RUNNABLE, group=TGRP-BasicDistributedZkTest]
   [junit4]    >         at java.net.PlainSocketImpl.socketConnect(Native Method)
   [junit4]    >         at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:339)
   [junit4]    >         at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:200)
   [junit4]    >         at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:182)
   [junit4]    >         at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:391)
   [junit4]    >         at java.net.Socket.connect(Socket.java:579)
   [junit4]    >         at org.apache.http.conn.scheme.PlainSocketFactory.connectSocket(PlainSocketFactory.java:127)
   [junit4]    >         at org.apache.http.impl.conn.DefaultClientConnectionOperator.openConnection(DefaultClientConnectionOperator.java:180)
   [junit4]    >         at org.apache.http.impl.conn.ManagedClientConnectionImpl.open(ManagedClientConnectionImpl.java:294)
   [junit4]    >         at org.apache.http.impl.client.DefaultRequestDirector.tryConnect(DefaultRequestDirector.java:645)
   [junit4]    >         at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:480)
   [junit4]    >         at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:906)
   [junit4]    >         at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:805)
   [junit4]    >         at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:784)
   [junit4]    >         at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:365)
   [junit4]    >         at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:180)
   [junit4]    >         at org.apache.solr.cloud.SyncStrategy$1.run(SyncStrategy.java:291)
   [junit4]    >         at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
   [junit4]    >         at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
   [junit4]    >         at java.lang.Thread.run(Thread.java:722)
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([75E5868DDF85DF78]:0)
   [junit4] Completed on J0 in 418.30s, 1 test, 2 errors <<< FAILURES!

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

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