lucene-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Apache Jenkins Server <jenk...@builds.apache.org>
Subject [JENKINS] Lucene-Solr-NightlyTests-4.4 - Build # 9 - Still Failing
Date Fri, 19 Jul 2013 01:15:42 GMT
Build: https://builds.apache.org/job/Lucene-Solr-NightlyTests-4.4/9/

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

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

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




Build Log:
[...truncated 9269 lines...]
   [junit4] Suite: org.apache.solr.cloud.BasicDistributedZkTest
   [junit4]   2> 1888091 T3185 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
   [junit4]   2> 1888095 T3185 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
   [junit4]   2> Creating dataDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZkTest-1374196175686
   [junit4]   2> 1888097 T3185 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   2> 1888097 T3186 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 1888199 T3185 oasc.ZkTestServer.run start zk server on port:48257
   [junit4]   2> 1888200 T3185 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1888204 T3192 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@531f148c name:ZooKeeperConnection Watcher:127.0.0.1:48257 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1888204 T3185 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1888205 T3185 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 1888215 T3185 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1888216 T3194 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@360775a1 name:ZooKeeperConnection Watcher:127.0.0.1:48257/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1888217 T3185 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1888217 T3185 oascc.SolrZkClient.makePath makePath: /collections/collection1
   [junit4]   2> 1888228 T3185 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
   [junit4]   2> 1888230 T3185 oascc.SolrZkClient.makePath makePath: /collections/control_collection
   [junit4]   2> 1888233 T3185 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
   [junit4]   2> 1888242 T3185 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
   [junit4]   2> 1888243 T3185 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
   [junit4]   2> 1888254 T3185 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
   [junit4]   2> 1888255 T3185 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
   [junit4]   2> 1888364 T3185 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
   [junit4]   2> 1888364 T3185 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
   [junit4]   2> 1888368 T3185 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
   [junit4]   2> 1888368 T3185 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
   [junit4]   2> 1888383 T3185 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
   [junit4]   2> 1888383 T3185 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
   [junit4]   2> 1888386 T3185 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
   [junit4]   2> 1888387 T3185 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
   [junit4]   2> 1888390 T3185 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 1888391 T3185 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 1888394 T3185 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
   [junit4]   2> 1888395 T3185 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
   [junit4]   2> 1888398 T3185 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
   [junit4]   2> 1888399 T3185 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
   [junit4]   2> 1888678 T3185 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 1888683 T3185 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:48260
   [junit4]   2> 1888684 T3185 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 1888684 T3185 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 1888685 T3185 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374196176000
   [junit4]   2> 1888685 T3185 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374196176000/'
   [junit4]   2> 1888722 T3185 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374196176000/solr.xml
   [junit4]   2> 1888793 T3185 oasc.CoreContainer.<init> New CoreContainer 892709629
   [junit4]   2> 1888794 T3185 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374196176000/]
   [junit4]   2> 1888796 T3185 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 1888796 T3185 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 1888797 T3185 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 1888797 T3185 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 1888798 T3185 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 1888798 T3185 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 1888799 T3185 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 1888799 T3185 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 1888800 T3185 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 1888800 T3185 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
   [junit4]   2> 1888817 T3185 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 1888818 T3185 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:48257/solr
   [junit4]   2> 1888818 T3185 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 1888819 T3185 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1888822 T3205 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@566ce355 name:ZooKeeperConnection Watcher:127.0.0.1:48257 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1888822 T3185 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1888834 T3185 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
   [junit4]   2> 1888846 T3185 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1888847 T3207 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6b7f6ea9 name:ZooKeeperConnection Watcher:127.0.0.1:48257/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1888848 T3185 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1888850 T3185 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 1888862 T3185 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 1888865 T3185 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 1888868 T3185 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:48260_
   [junit4]   2> 1888875 T3185 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:48260_
   [junit4]   2> 1888878 T3185 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 1888897 T3185 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 1888899 T3185 oasc.Overseer.start Overseer (id=90059320570216451-127.0.0.1:48260_-n_0000000000) starting
   [junit4]   2> 1888912 T3185 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 1888924 T3209 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 1888925 T3185 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 1888928 T3185 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 1888930 T3185 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1888933 T3208 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 1888937 T3210 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 1888937 T3210 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1888939 T3210 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 1890437 T3208 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1890437 T3208 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:48260_",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:48260"}
   [junit4]   2> 1890438 T3208 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with numShards 1
   [junit4]   2> 1890438 T3208 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 1890451 T3207 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> 1890942 T3210 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 1890942 T3210 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374196176000/collection1
   [junit4]   2> 1890942 T3210 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
   [junit4]   2> 1890943 T3210 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 1890943 T3210 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
   [junit4]   2> 1890945 T3210 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374196176000/collection1/'
   [junit4]   2> 1890946 T3210 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374196176000/collection1/lib/README' to classloader
   [junit4]   2> 1890947 T3210 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374196176000/collection1/lib/classes/' to classloader
   [junit4]   2> 1891001 T3210 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
   [junit4]   2> 1891060 T3210 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 1891161 T3210 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 1891172 T3210 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 1891805 T3210 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 1891806 T3210 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 1891807 T3210 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 1891818 T3210 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 1891822 T3210 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 1891836 T3210 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1891841 T3210 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1891845 T3210 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1891846 T3210 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1891846 T3210 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1891847 T3210 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1891848 T3210 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1891848 T3210 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1891848 T3210 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 1891849 T3210 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374196176000/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZkTest-1374196175686/control/data/
   [junit4]   2> 1891849 T3210 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@62513bb5
   [junit4]   2> 1891850 T3210 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374196175686/control/data
   [junit4]   2> 1891850 T3210 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZkTest-1374196175686/control/data/index/
   [junit4]   2> 1891850 T3210 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZkTest-1374196175686/control/data/index' doesn't exist. Creating new index...
   [junit4]   2> 1891851 T3210 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374196175686/control/data/index
   [junit4]   2> 1891855 T3210 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirWrapper(RateLimitedDirectoryWrapper(org.apache.lucene.store.RAMDirectory@11a49a26 lockFactory=org.apache.lucene.store.NativeFSLockFactory@a96f6fa)),segFN=segments_1,generation=1}
   [junit4]   2> 1891855 T3210 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1891859 T3210 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 1891859 T3210 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1891860 T3210 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1891860 T3210 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 1891861 T3210 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 1891861 T3210 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 1891861 T3210 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 1891862 T3210 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 1891862 T3210 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 1891871 T3210 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 1891878 T3210 oass.SolrIndexSearcher.<init> Opening Searcher@349ca78d main
   [junit4]   2> 1891880 T3210 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 1891880 T3210 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 1891883 T3211 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@349ca78d main{StandardDirectoryReader(segments_1:1)}
   [junit4]   2> 1891885 T3210 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 1891885 T3210 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:48260 collection:control_collection shard:shard1
   [junit4]   2> 1891885 T3210 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=30000&socketTimeout=30000&retry=false
   [junit4]   2> 1891901 T3210 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
   [junit4]   2> 1891939 T3210 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 1891974 T3210 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 1891975 T3210 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> 1891975 T3210 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:48260/collection1/
   [junit4]   2> 1891975 T3210 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 1891975 T3210 oasc.SyncStrategy.syncToMe http://127.0.0.1:48260/collection1/ has no replicas
   [junit4]   2> 1891976 T3210 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:48260/collection1/ shard1
   [junit4]   2> 1891976 T3210 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
   [junit4]   2> 1893478 T3208 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1893498 T3207 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> 1893521 T3210 oasc.ZkController.register We are http://127.0.0.1:48260/collection1/ and leader is http://127.0.0.1:48260/collection1/
   [junit4]   2> 1893521 T3210 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:48260
   [junit4]   2> 1893521 T3210 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 1893521 T3210 oasc.ZkController.publish publishing core=collection1 state=active
   [junit4]   2> 1893522 T3210 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1893523 T3210 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1893524 T3185 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/solr/build/solr-core/test/J1
   [junit4]   2> 1893525 T3185 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 1893526 T3185 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> 1893536 T3185 oascsi.HttpClientUtil.createClient Creating new http client, config:
   [junit4]   2> 1893538 T3185 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1893540 T3214 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1456f24d name:ZooKeeperConnection Watcher:127.0.0.1:48257/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1893540 T3185 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1893542 T3185 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1893544 T3185 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
   [junit4]   2> 1893809 T3185 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 1893813 T3185 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:48266
   [junit4]   2> 1893813 T3185 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 1893814 T3185 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 1893814 T3185 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374196181135
   [junit4]   2> 1893815 T3185 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374196181135/'
   [junit4]   2> 1893852 T3185 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374196181135/solr.xml
   [junit4]   2> 1893923 T3185 oasc.CoreContainer.<init> New CoreContainer 1396414981
   [junit4]   2> 1893923 T3185 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374196181135/]
   [junit4]   2> 1893925 T3185 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 1893926 T3185 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 1893926 T3185 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 1893927 T3185 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 1893927 T3185 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 1893928 T3185 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 1893928 T3185 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 1893928 T3185 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 1893929 T3185 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 1893929 T3185 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
   [junit4]   2> 1893946 T3185 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 1893947 T3185 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:48257/solr
   [junit4]   2> 1893947 T3185 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 1893948 T3185 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1893951 T3225 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6dfce8f3 name:ZooKeeperConnection Watcher:127.0.0.1:48257 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1893951 T3185 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1893964 T3185 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
   [junit4]   2> 1893976 T3185 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1893977 T3227 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@85ce57f name:ZooKeeperConnection Watcher:127.0.0.1:48257/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1893978 T3185 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1893989 T3185 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1894993 T3185 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:48266_
   [junit4]   2> 1894995 T3185 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:48266_
   [junit4]   2> 1894999 T3214 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 1894999 T3227 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 1894999 T3207 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 1894999 T3207 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> 1895009 T3208 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1895010 T3208 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:48260_",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:48260"}
   [junit4]   2> 1895013 T3228 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 1895014 T3228 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1895020 T3227 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> 1895020 T3214 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> 1895020 T3207 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> 1895021 T3228 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 1896531 T3208 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1896532 T3208 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:48266_",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:48266"}
   [junit4]   2> 1896533 T3208 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with numShards 2
   [junit4]   2> 1896533 T3208 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 1896547 T3214 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> 1896547 T3227 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> 1896547 T3207 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> 1897024 T3228 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 1897024 T3228 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374196181135/collection1
   [junit4]   2> 1897024 T3228 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 1897025 T3228 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 1897026 T3228 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 1897027 T3228 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374196181135/collection1/'
   [junit4]   2> 1897028 T3228 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374196181135/collection1/lib/classes/' to classloader
   [junit4]   2> 1897029 T3228 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374196181135/collection1/lib/README' to classloader
   [junit4]   2> 1897083 T3228 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
   [junit4]   2> 1897142 T3228 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 1897244 T3228 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 1897255 T3228 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 1897909 T3228 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 1897910 T3228 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 1897911 T3228 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 1897925 T3228 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 1897930 T3228 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 1897949 T3228 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1897954 T3228 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1897959 T3228 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1897960 T3228 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1897960 T3228 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1897960 T3228 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1897961 T3228 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1897962 T3228 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1897962 T3228 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 1897962 T3228 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374196181135/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZkTest-1374196175686/jetty1/
   [junit4]   2> 1897963 T3228 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@62513bb5
   [junit4]   2> 1897964 T3228 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374196175686/jetty1
   [junit4]   2> 1897964 T3228 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZkTest-1374196175686/jetty1/index/
   [junit4]   2> 1897964 T3228 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZkTest-1374196175686/jetty1/index' doesn't exist. Creating new index...
   [junit4]   2> 1897964 T3228 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374196175686/jetty1/index
   [junit4]   2> 1897968 T3228 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirWrapper(RateLimitedDirectoryWrapper(org.apache.lucene.store.RAMDirectory@d61dca7 lockFactory=org.apache.lucene.store.NativeFSLockFactory@7db1d707)),segFN=segments_1,generation=1}
   [junit4]   2> 1897969 T3228 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1897974 T3228 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 1897974 T3228 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1897975 T3228 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1897975 T3228 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 1897976 T3228 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 1897976 T3228 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 1897976 T3228 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 1897977 T3228 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 1897978 T3228 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 1897989 T3228 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 1897997 T3228 oass.SolrIndexSearcher.<init> Opening Searcher@71046d8e main
   [junit4]   2> 1897998 T3228 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 1897999 T3228 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 1898003 T3229 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@71046d8e main{StandardDirectoryReader(segments_1:1)}
   [junit4]   2> 1898005 T3228 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 1898005 T3228 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:48266 collection:collection1 shard:shard1
   [junit4]   2> 1898006 T3228 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=30000&socketTimeout=30000&retry=false
   [junit4]   2> 1898022 T3228 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 1898047 T3228 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 1898050 T3228 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 1898050 T3228 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> 1898050 T3228 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:48266/collection1/
   [junit4]   2> 1898051 T3228 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 1898051 T3228 oasc.SyncStrategy.syncToMe http://127.0.0.1:48266/collection1/ has no replicas
   [junit4]   2> 1898051 T3228 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:48266/collection1/ shard1
   [junit4]   2> 1898051 T3228 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 1898052 T3208 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1898057 T3227 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> 1898057 T3214 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> 1898057 T3207 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> 1899563 T3208 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1899581 T3214 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> 1899581 T3207 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> 1899581 T3227 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> 1899597 T3228 oasc.ZkController.register We are http://127.0.0.1:48266/collection1/ and leader is http://127.0.0.1:48266/collection1/
   [junit4]   2> 1899597 T3228 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:48266
   [junit4]   2> 1899597 T3228 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 1899597 T3228 oasc.ZkController.publish publishing core=collection1 state=active
   [junit4]   2> 1899598 T3228 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1899599 T3228 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1899600 T3185 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/solr/build/solr-core/test/J1
   [junit4]   2> 1899601 T3185 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 1899601 T3185 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> 1899815 T3185 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 1899817 T3185 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:48269
   [junit4]   2> 1899818 T3185 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 1899818 T3185 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 1899819 T3185 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374196187198
   [junit4]   2> 1899819 T3185 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374196187198/'
   [junit4]   2> 1899854 T3185 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374196187198/solr.xml
   [junit4]   2> 1899909 T3185 oasc.CoreContainer.<init> New CoreContainer 859289455
   [junit4]   2> 1899910 T3185 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374196187198/]
   [junit4]   2> 1899911 T3185 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 1899911 T3185 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 1899912 T3185 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 1899912 T3185 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 1899912 T3185 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 1899912 T3185 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 1899913 T3185 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 1899913 T3185 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 1899913 T3185 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 1899914 T3185 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
   [junit4]   2> 1899924 T3185 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 1899925 T3185 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:48257/solr
   [junit4]   2> 1899925 T3185 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 1899926 T3185 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1899929 T3241 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@eebf2ae name:ZooKeeperConnection Watcher:127.0.0.1:48257 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1899929 T3185 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1899947 T3185 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
   [junit4]   2> 1899957 T3185 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1899959 T3243 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@31408083 name:ZooKeeperConnection Watcher:127.0.0.1:48257/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1899959 T3185 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1899970 T3185 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1900973 T3185 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:48269_
   [junit4]   2> 1900976 T3185 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:48269_
   [junit4]   2> 1900979 T3227 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> 1900980 T3214 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 1900980 T3243 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 1900980 T3214 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> 1900980 T3207 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 1900980 T3207 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> 1900981 T3227 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 1900995 T3244 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 1900995 T3244 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1900997 T3244 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 1901086 T3208 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1901087 T3208 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:48266_",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:48266"}
   [junit4]   2> 1901091 T3208 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:48269_",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:48269"}
   [junit4]   2> 1901092 T3208 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
   [junit4]   2> 1901092 T3208 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
   [junit4]   2> 1901108 T3243 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> 1901108 T3207 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> 1901108 T3227 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> 1901108 T3214 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> 1901999 T3244 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 1901999 T3244 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374196187198/collection1
   [junit4]   2> 1901999 T3244 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 1902000 T3244 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 1902000 T3244 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 1902002 T3244 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374196187198/collection1/'
   [junit4]   2> 1902003 T3244 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374196187198/collection1/lib/README' to classloader
   [junit4]   2> 1902003 T3244 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374196187198/collection1/lib/classes/' to classloader
   [junit4]   2> 1902044 T3244 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
   [junit4]   2> 1902089 T3244 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 1902192 T3244 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 1902203 T3244 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 1902881 T3244 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 1902882 T3244 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 1902883 T3244 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 1902897 T3244 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 1902902 T3244 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 1902916 T3244 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1902921 T3244 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1902926 T3244 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1902927 T3244 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1902927 T3244 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1902928 T3244 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1902929 T3244 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1902929 T3244 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1902929 T3244 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 1902930 T3244 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374196187198/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZkTest-1374196175686/jetty2/
   [junit4]   2> 1902930 T3244 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@62513bb5
   [junit4]   2> 1902931 T3244 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374196175686/jetty2
   [junit4]   2> 1902931 T3244 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZkTest-1374196175686/jetty2/index/
   [junit4]   2> 1902932 T3244 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZkTest-1374196175686/jetty2/index' doesn't exist. Creating new index...
   [junit4]   2> 1902932 T3244 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374196175686/jetty2/index
   [junit4]   2> 1902936 T3244 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirWrapper(RateLimitedDirectoryWrapper(org.apache.lucene.store.RAMDirectory@1ff704a1 lockFactory=org.apache.lucene.store.NativeFSLockFactory@56bd3a44)),segFN=segments_1,generation=1}
   [junit4]   2> 1902936 T3244 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1902941 T3244 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 1902941 T3244 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1902942 T3244 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1902943 T3244 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 1902943 T3244 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 1902944 T3244 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 1902944 T3244 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 1902945 T3244 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 1902945 T3244 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 1902956 T3244 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 1902964 T3244 oass.SolrIndexSearcher.<init> Opening Searcher@664f2e41 main
   [junit4]   2> 1902966 T3244 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 1902966 T3244 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 1902970 T3245 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@664f2e41 main{StandardDirectoryReader(segments_1:1)}
   [junit4]   2> 1902972 T3244 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 1902972 T3244 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:48269 collection:collection1 shard:shard2
   [junit4]   2> 1902973 T3244 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=30000&socketTimeout=30000&retry=false
   [junit4]   2> 1902991 T3244 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
   [junit4]   2> 1903035 T3244 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
   [junit4]   2> 1903044 T3244 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 1903045 T3244 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> 1903045 T3244 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:48269/collection1/
   [junit4]   2> 1903045 T3244 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 1903045 T3244 oasc.SyncStrategy.syncToMe http://127.0.0.1:48269/collection1/ has no replicas
   [junit4]   2> 1903046 T3244 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:48269/collection1/ shard2
   [junit4]   2> 1903046 T3244 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
   [junit4]   2> 1904117 T3208 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1904153 T3243 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> 1904153 T3214 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> 1904153 T3207 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> 1904153 T3227 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> 1904182 T3244 oasc.ZkController.register We are http://127.0.0.1:48269/collection1/ and leader is http://127.0.0.1:48269/collection1/
   [junit4]   2> 1904182 T3244 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:48269
   [junit4]   2> 1904182 T3244 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 1904182 T3244 oasc.ZkController.publish publishing core=collection1 state=active
   [junit4]   2> 1904183 T3244 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1904185 T3244 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1904186 T3185 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/solr/build/solr-core/test/J1
   [junit4]   2> 1904187 T3185 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 1904188 T3185 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> 1904512 T3185 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 1904514 T3185 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:48277
   [junit4]   2> 1904515 T3185 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 1904515 T3185 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 1904516 T3185 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374196191788
   [junit4]   2> 1904516 T3185 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374196191788/'
   [junit4]   2> 1904567 T3185 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374196191788/solr.xml
   [junit4]   2> 1904641 T3185 oasc.CoreContainer.<init> New CoreContainer 1209011515
   [junit4]   2> 1904642 T3185 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374196191788/]
   [junit4]   2> 1904643 T3185 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 1904644 T3185 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 1904644 T3185 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 1904645 T3185 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 1904645 T3185 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 1904646 T3185 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 1904646 T3185 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 1904647 T3185 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 1904647 T3185 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 1904648 T3185 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
   [junit4]   2> 1904664 T3185 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 1904665 T3185 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:48257/solr
   [junit4]   2> 1904665 T3185 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 1904666 T3185 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1904670 T3257 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@15d4c173 name:ZooKeeperConnection Watcher:127.0.0.1:48257 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1904670 T3185 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1904673 T3185 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
   [junit4]   2> 1904685 T3185 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1904687 T3259 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2061354 name:ZooKeeperConnection Watcher:127.0.0.1:48257/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1904687 T3185 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1904699 T3185 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1905659 T3208 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1905660 T3208 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:48269_",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:48269"}
   [junit4]   2> 1905701 T3259 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> 1905701 T3243 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> 1905701 T3227 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> 1905701 T3207 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> 1905701 T3214 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> 1905703 T3185 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:48277_
   [junit4]   2> 1905712 T3185 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:48277_
   [junit4]   2> 1905713 T3243 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> 1905714 T3227 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> 1905714 T3214 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 1905714 T3214 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> 1905714 T3259 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 1905714 T3207 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 1905715 T3259 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> 1905715 T3207 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> 1905715 T3243 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 1905716 T3227 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 1905721 T3260 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 1905721 T3260 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1905723 T3260 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 1907214 T3208 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1907215 T3208 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:48277_",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:48277"}
   [junit4]   2> 1907215 T3208 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
   [junit4]   2> 1907215 T3208 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 1907226 T3259 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> 1907226 T3243 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> 1907226 T3207 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> 1907226 T3227 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> 1907226 T3214 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> 1907726 T3260 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 1907726 T3260 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374196191788/collection1
   [junit4]   2> 1907726 T3260 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 1907727 T3260 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 1907727 T3260 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 1907728 T3260 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374196191788/collection1/'
   [junit4]   2> 1907730 T3260 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374196191788/collection1/lib/README' to classloader
   [junit4]   2> 1907730 T3260 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374196191788/collection1/lib/classes/' to classloader
   [junit4]   2> 1907772 T3260 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
   [junit4]   2> 1907824 T3260 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 1907926 T3260 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 1907933 T3260 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 1909004 T3260 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 1909004 T3260 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 1909005 T3260 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 1909014 T3260 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 1909018 T3260 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 1909029 T3260 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1909033 T3260 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1909037 T3260 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1909038 T3260 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1909038 T3260 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1909038 T3260 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1909039 T3260 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1909039 T3260 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1909040 T3260 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 1909040 T3260 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374196191788/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZkTest-1374196175686/jetty3/
   [junit4]   2> 1909040 T3260 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@62513bb5
   [junit4]   2> 1909041 T3260 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374196175686/jetty3
   [junit4]   2> 1909041 T3260 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZkTest-1374196175686/jetty3/index/
   [junit4]   2> 1909041 T3260 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZkTest-1374196175686/jetty3/index' doesn't exist. Creating new index...
   [junit4]   2> 1909042 T3260 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374196175686/jetty3/index
   [junit4]   2> 1909047 T3260 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirWrapper(RateLimitedDirectoryWrapper(org.apache.lucene.store.RAMDirectory@5327b646 lockFactory=org.apache.lucene.store.NativeFSLockFactory@75ffa51b)),segFN=segments_1,generation=1}
   [junit4]   2> 1909047 T3260 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1909051 T3260 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 1909051 T3260 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1909051 T3260 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1909052 T3260 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 1909052 T3260 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 1909053 T3260 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 1909053 T3260 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 1909053 T3260 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 1909054 T3260 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 1909062 T3260 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 1909068 T3260 oass.SolrIndexSearcher.<init> Opening Searcher@876c11a main
   [junit4]   2> 1909069 T3260 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 1909069 T3260 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 1909073 T3261 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@876c11a main{StandardDirectoryReader(segments_1:1)}
   [junit4]   2> 1909074 T3260 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 1909074 T3260 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:48277 collection:collection1 shard:shard1
   [junit4]   2> 1909075 T3260 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=30000&socketTimeout=30000&retry=false
   [junit4]   2> 1909091 T3260 oasc.ZkController.register We are http://127.0.0.1:48277/collection1/ and leader is http://127.0.0.1:48266/collection1/
   [junit4]   2> 1909091 T3260 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:48277
   [junit4]   2> 1909092 T3260 oasc.ZkController.checkRecovery Core needs to recover:collection1
   [junit4]   2> 1909092 T3260 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
   [junit4]   2> ASYNC  NEW_CORE C22638 name=collection1 org.apache.solr.core.SolrCore@4225f844 url=http://127.0.0.1:48277/collection1 node=127.0.0.1:48277_ C22638_STATE=coll:collection1 core:collection1 props:{state=down, core=collection1, node_name=127.0.0.1:48277_, base_url=http://127.0.0.1:48277}
   [junit4]   2> 1909092 T3262 C22638 P48277 oasc.RecoveryStrategy.run Starting recovery process.  core=collection1 recoveringAfterStartup=true
   [junit4]   2> 1909093 T3262 C22638 P48277 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
   [junit4]   2> 1909093 T3260 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1909093 T3262 C22638 P48277 oasc.ZkController.publish publishing core=collection1 state=recovering
   [junit4]   2> 1909093 T3262 C22638 P48277 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1909094 T3185 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/solr/build/solr-core/test/J1
   [junit4]   2> 1909095 T3185 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 1909095 T3185 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> 1909100 T3262 C22638 P48277 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> 1909109 T3217 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: core_node3, state: recovering, checkLive: true, onlyIfLeader: true
   [j

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

stingsFormat(name=MockSep), range_facet_sl=MockFixedIntBlock(blockSize=185), range_facet_si=PostingsFormat(name=NestedPulsing), oddField_s=MockFixedIntBlock(blockSize=185), sequence_i=MockFixedIntBlock(blockSize=185), name=PostingsFormat(name=MockSep), foo_i=PostingsFormat(name=NestedPulsing), regex_dup_B_s=Lucene41(blocksize=128), multiDefault=PostingsFormat(name=NestedPulsing), n_tf1=Lucene41(blocksize=128), n_dt1=PostingsFormat(name=NestedPulsing), genre_s=MockFixedIntBlock(blockSize=185), author_t=PostingsFormat(name=NestedPulsing), range_facet_l=Lucene41(blocksize=128), n_ti1=PostingsFormat(name=MockSep), text=MockFixedIntBlock(blockSize=185), _version_=Lucene41(blocksize=128), val_i=PostingsFormat(name=MockSep), SubjectTerms_mfacet=Lucene41(blocksize=128), series_t=PostingsFormat(name=NestedPulsing), a_t=Lucene41(blocksize=128), n_tdt1=Lucene41(blocksize=128), regex_dup_A_s=MockFixedIntBlock(blockSize=185), price=MockFixedIntBlock(blockSize=185), other_tl1=Lucene41(blocksize=128), n_l1=Lucene41(blocksize=128), a_si=PostingsFormat(name=NestedPulsing), inStock=MockFixedIntBlock(blockSize=185)}, docValues:{}, sim=RandomSimilarityProvider(queryNorm=false,coord=no): {}, locale=mk_MK, timezone=Africa/Lusaka
   [junit4]   2> NOTE: FreeBSD 9.1-RELEASE-p3 amd64/Sun Microsystems Inc. 1.6.0_32 (64-bit)/cpus=16,threads=2,free=278688800,total=531365888
   [junit4]   2> NOTE: All tests run in this JVM: [TestStressReorder, QueryResultKeyTest, BasicDistributedZk2Test, TestIndexingPerformance, CoreAdminCreateDiscoverTest, PreAnalyzedUpdateProcessorTest, TestRecovery, TestAddFieldRealTimeGet, TestUtils, DateMathParserTest, TestArbitraryIndexDir, FullSolrCloudDistribCmdsTest, TestQuerySenderNoQuery, OpenCloseCoreStressTest, BadIndexSchemaTest, DebugComponentTest, ShardRoutingCustomTest, TestCollationKeyRangeQueries, PingRequestHandlerTest, TestSolrXml, TestSystemIdResolver, TestSerializedLuceneMatchVersion, DocValuesMultiTest, TestOmitPositions, TestSchemaVersionResource, NoCacheHeaderTest, TestDFRSimilarityFactory, TestBM25SimilarityFactory, SolrPluginUtilsTest, SpellCheckComponentTest, UniqFieldsUpdateProcessorFactoryTest, URLClassifyProcessorTest, TestUpdate, TestZkChroot, TestPartialUpdateDeduplication, TestSolr4Spatial, SolrCmdDistributorTest, XmlUpdateRequestHandlerTest, DirectUpdateHandlerTest, TestPostingsSolrHighlighter, TestAtomicUpdateErrorCases, UpdateParamsTest, BasicHdfsTest, TestRandomFaceting, TestMultiCoreConfBootstrap, TestFiltering, ZkSolrClientTest, NumericFieldsTest, SortByFunctionTest, TestComponentsName, TestFoldingMultitermQuery, TestRangeQuery, OutputWriterTest, TestDefaultSimilarityFactory, TestStressLucene, DocumentAnalysisRequestHandlerTest, TestCoreDiscovery, ClusterStateTest, TestRTGBase, TestLuceneMatchVersion, TestSchemaSimilarityResource, TestDynamicFieldResource, SignatureUpdateProcessorFactoryTest, HighlighterTest, TestSuggestSpellingConverter, CachingDirectoryFactoryTest, CoreContainerCoreInitFailuresTest, TestWordDelimiterFilterFactory, SampleTest, TestDefaultSearchFieldResource, ChaosMonkeySafeLeaderTest, TestSolrXMLSerializer, TestBinaryField, BasicZkTest, BasicDistributedZkTest]
   [junit4]   2> NOTE: download the large Jenkins line-docs file by running 'ant get-jenkins-line-docs' in the lucene directory.
   [junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=BasicDistributedZkTest -Dtests.seed=CE7EA7067E9B92AC -Dtests.multiplier=2 -Dtests.nightly=true -Dtests.slow=true -Dtests.linedocsfile=/home/hudson/lucene-data/enwiki.random.lines.txt -Dtests.locale=mk_MK -Dtests.timezone=Africa/Lusaka -Dtests.file.encoding=US-ASCII
   [junit4] ERROR   0.00s J1 | BasicDistributedZkTest (suite) <<<
   [junit4]    > Throwable #1: com.carrotsearch.randomizedtesting.ThreadLeakError: 1 thread leaked from SUITE scope at org.apache.solr.cloud.BasicDistributedZkTest: 
   [junit4]    >    1) Thread[id=3685, name=recoveryCmdExecutor-1226-thread-1, state=RUNNABLE, group=TGRP-BasicDistributedZkTest]
   [junit4]    >         at java.net.PlainSocketImpl.socketConnect(Native Method)
   [junit4]    >         at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:327)
   [junit4]    >         at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:193)
   [junit4]    >         at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:180)
   [junit4]    >         at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:384)
   [junit4]    >         at java.net.Socket.connect(Socket.java:546)
   [junit4]    >         at org.apache.http.conn.scheme.PlainSocketFactory.connectSocket(PlainSocketFactory.java:127)
   [junit4]    >         at org.apache.http.impl.conn.DefaultClientConnectionOperator.openConnection(DefaultClientConnectionOperator.java:180)
   [junit4]    >         at org.apache.http.impl.conn.ManagedClientConnectionImpl.open(ManagedClientConnectionImpl.java:294)
   [junit4]    >         at org.apache.http.impl.client.DefaultRequestDirector.tryConnect(DefaultRequestDirector.java:645)
   [junit4]    >         at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:480)
   [junit4]    >         at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:906)
   [junit4]    >         at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:805)
   [junit4]    >         at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:784)
   [junit4]    >         at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:365)
   [junit4]    >         at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:180)
   [junit4]    >         at org.apache.solr.cloud.SyncStrategy$1.run(SyncStrategy.java:291)
   [junit4]    >         at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1146)
   [junit4]    >         at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
   [junit4]    >         at java.lang.Thread.run(Thread.java:679)
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([CE7EA7067E9B92AC]:0)Throwable #2: com.carrotsearch.randomizedtesting.ThreadLeakError: There are still zombie threads that couldn't be terminated:
   [junit4]    >    1) Thread[id=3685, name=recoveryCmdExecutor-1226-thread-1, state=RUNNABLE, group=TGRP-BasicDistributedZkTest]
   [junit4]    >         at java.net.PlainSocketImpl.socketConnect(Native Method)
   [junit4]    >         at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:327)
   [junit4]    >         at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:193)
   [junit4]    >         at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:180)
   [junit4]    >         at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:384)
   [junit4]    >         at java.net.Socket.connect(Socket.java:546)
   [junit4]    >         at org.apache.http.conn.scheme.PlainSocketFactory.connectSocket(PlainSocketFactory.java:127)
   [junit4]    >         at org.apache.http.impl.conn.DefaultClientConnectionOperator.openConnection(DefaultClientConnectionOperator.java:180)
   [junit4]    >         at org.apache.http.impl.conn.ManagedClientConnectionImpl.open(ManagedClientConnectionImpl.java:294)
   [junit4]    >         at org.apache.http.impl.client.DefaultRequestDirector.tryConnect(DefaultRequestDirector.java:645)
   [junit4]    >         at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:480)
   [junit4]    >         at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:906)
   [junit4]    >         at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:805)
   [junit4]    >         at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:784)
   [junit4]    >         at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:365)
   [junit4]    >         at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:180)
   [junit4]    >         at org.apache.solr.cloud.SyncStrategy$1.run(SyncStrategy.java:291)
   [junit4]    >         at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1146)
   [junit4]    >         at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
   [junit4]    >         at java.lang.Thread.run(Thread.java:679)
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([CE7EA7067E9B92AC]:0)
   [junit4] Completed on J1 in 240.90s, 1 test, 2 errors <<< FAILURES!

[...truncated 482 lines...]
BUILD FAILED
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/build.xml:402: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/build.xml:375: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/build.xml:39: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/solr/build.xml:181: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/solr/common-build.xml:449: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/lucene/common-build.xml:1250: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/lucene/common-build.xml:893: There were test failures: 317 suites, 1337 tests, 2 suite-level errors, 639 ignored (4 assumptions)

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



Mime
View raw message