lucene-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Apache Jenkins Server <jenk...@builds.apache.org>
Subject [JENKINS] Lucene-Solr-Tests-trunk-Java7 - Build # 4160 - Still Failing
Date Sat, 20 Jul 2013 16:00:02 GMT
Build: https://builds.apache.org/job/Lucene-Solr-Tests-trunk-Java7/4160/

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

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

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




Build Log:
[...truncated 9371 lines...]
   [junit4] Suite: org.apache.solr.cloud.BasicDistributedZkTest
   [junit4]   2> 170733 T821 oas.SolrTestCaseJ4.startTrackingSearchers WARN startTrackingSearchers: numOpens=1 numCloses=1
   [junit4]   2> 170734 T821 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
   [junit4]   2> 170742 T821 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
   [junit4]   2> Creating dataDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./solrtest-BasicDistributedZkTest-1374335209308
   [junit4]   2> 170743 T821 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   2> 170744 T822 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 170845 T821 oasc.ZkTestServer.run start zk server on port:10121
   [junit4]   2> 170846 T821 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 170876 T828 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2a63c591 name:ZooKeeperConnection Watcher:127.0.0.1:10121 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 170877 T821 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 170878 T821 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 170882 T821 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 170892 T830 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@255aaf8a name:ZooKeeperConnection Watcher:127.0.0.1:10121/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 170893 T821 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 170893 T821 oascc.SolrZkClient.makePath makePath: /collections/collection1
   [junit4]   2> 170903 T821 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
   [junit4]   2> 170906 T821 oascc.SolrZkClient.makePath makePath: /collections/control_collection
   [junit4]   2> 170909 T821 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
   [junit4]   2> 170913 T821 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
   [junit4]   2> 170914 T821 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
   [junit4]   2> 170924 T821 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
   [junit4]   2> 170925 T821 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
   [junit4]   2> 170930 T821 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
   [junit4]   2> 170931 T821 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
   [junit4]   2> 170935 T821 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
   [junit4]   2> 170936 T821 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
   [junit4]   2> 170939 T821 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
   [junit4]   2> 170940 T821 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
   [junit4]   2> 170944 T821 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
   [junit4]   2> 170944 T821 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
   [junit4]   2> 170948 T821 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 170949 T821 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 170952 T821 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
   [junit4]   2> 170953 T821 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
   [junit4]   2> 170956 T821 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
   [junit4]   2> 170957 T821 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
   [junit4]   2> 171235 T821 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 171238 T821 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:10124
   [junit4]   2> 171239 T821 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 171240 T821 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 171240 T821 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374335209526
   [junit4]   2> 171241 T821 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374335209526/'
   [junit4]   2> 171278 T821 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374335209526/solr.xml
   [junit4]   2> 171378 T821 oasc.CoreContainer.<init> New CoreContainer 991945374
   [junit4]   2> 171379 T821 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374335209526/]
   [junit4]   2> 171381 T821 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 171381 T821 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 171382 T821 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 171383 T821 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 171383 T821 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 171384 T821 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 171384 T821 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 171385 T821 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 171386 T821 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 171386 T821 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
   [junit4]   2> 171405 T821 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 171406 T821 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:10121/solr
   [junit4]   2> 171407 T821 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 171408 T821 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 171412 T841 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@75e80151 name:ZooKeeperConnection Watcher:127.0.0.1:10121 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 171413 T821 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 171421 T821 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
   [junit4]   2> 171435 T821 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 171437 T843 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@db68109 name:ZooKeeperConnection Watcher:127.0.0.1:10121/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 171437 T821 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 171440 T821 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 171450 T821 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 171454 T821 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 171456 T821 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:10124_
   [junit4]   2> 171464 T821 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:10124_
   [junit4]   2> 171468 T821 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 171486 T821 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 171489 T821 oasc.Overseer.start Overseer (id=90068432277667843-127.0.0.1:10124_-n_0000000000) starting
   [junit4]   2> 171501 T821 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 171512 T845 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 171513 T821 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 171516 T821 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 171519 T821 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 171522 T844 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 171527 T846 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 171528 T846 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 171529 T846 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 173027 T844 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 173028 T844 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:10124_",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:10124"}
   [junit4]   2> 173029 T844 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with numShards 1
   [junit4]   2> 173029 T844 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 173074 T843 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> 173532 T846 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 173532 T846 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374335209526/collection1
   [junit4]   2> 173532 T846 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
   [junit4]   2> 173533 T846 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 173534 T846 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
   [junit4]   2> 173535 T846 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374335209526/collection1/'
   [junit4]   2> 173536 T846 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374335209526/collection1/lib/classes/' to classloader
   [junit4]   2> 173537 T846 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374335209526/collection1/lib/README' to classloader
   [junit4]   2> 173594 T846 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 173664 T846 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 173666 T846 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 173680 T846 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 174341 T846 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 174355 T846 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 174360 T846 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 174381 T846 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 174386 T846 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 174391 T846 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 174393 T846 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 174393 T846 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 174394 T846 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 174395 T846 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 174395 T846 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 174396 T846 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 174396 T846 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374335209526/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZkTest-1374335209307/control/data/
   [junit4]   2> 174397 T846 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@40fe1db2
   [junit4]   2> 174398 T846 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374335209307/control/data
   [junit4]   2> 174398 T846 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZkTest-1374335209307/control/data/index/
   [junit4]   2> 174399 T846 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZkTest-1374335209307/control/data/index' doesn't exist. Creating new index...
   [junit4]   2> 174421 T846 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374335209307/control/data/index
   [junit4]   2> 174427 T846 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.MMapDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/index3109231094tmp lockFactory=org.apache.lucene.store.NativeFSLockFactory@15881ebc),segFN=segments_1,generation=1}
   [junit4]   2> 174428 T846 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 174434 T846 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 174434 T846 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 174435 T846 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 174436 T846 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 174437 T846 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 174437 T846 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 174438 T846 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 174438 T846 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 174439 T846 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 174456 T846 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 174480 T846 oass.SolrIndexSearcher.<init> Opening Searcher@5408807c main
   [junit4]   2> 174481 T846 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 174482 T846 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 174487 T847 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@5408807c main{StandardDirectoryReader(segments_1:1)}
   [junit4]   2> 174491 T846 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 174492 T846 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:10124 collection:control_collection shard:shard1
   [junit4]   2> 174493 T846 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=30000&socketTimeout=30000&retry=false
   [junit4]   2> 174524 T846 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
   [junit4]   2> 174549 T846 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 174560 T846 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 174561 T846 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> 174561 T846 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:10124/collection1/
   [junit4]   2> 174562 T846 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 174562 T846 oasc.SyncStrategy.syncToMe http://127.0.0.1:10124/collection1/ has no replicas
   [junit4]   2> 174563 T846 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:10124/collection1/ shard1
   [junit4]   2> 174563 T846 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
   [junit4]   2> 174580 T844 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 174590 T843 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> 174631 T846 oasc.ZkController.register We are http://127.0.0.1:10124/collection1/ and leader is http://127.0.0.1:10124/collection1/
   [junit4]   2> 174632 T846 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:10124
   [junit4]   2> 174632 T846 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 174632 T846 oasc.ZkController.publish publishing core=collection1 state=active
   [junit4]   2> 174633 T846 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 174636 T846 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 174637 T821 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0
   [junit4]   2> 174639 T821 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 174640 T821 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> 174657 T821 oascsi.HttpClientUtil.createClient Creating new http client, config:
   [junit4]   2> 174659 T821 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 174662 T850 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@20fa9ea5 name:ZooKeeperConnection Watcher:127.0.0.1:10121/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 174662 T821 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 174664 T821 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 174667 T821 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
   [junit4]   2> 174946 T821 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 174950 T821 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:10128
   [junit4]   2> 174951 T821 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 174951 T821 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 174952 T821 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374335213232
   [junit4]   2> 174953 T821 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374335213232/'
   [junit4]   2> 174991 T821 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374335213232/solr.xml
   [junit4]   2> 175096 T821 oasc.CoreContainer.<init> New CoreContainer 764627270
   [junit4]   2> 175097 T821 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374335213232/]
   [junit4]   2> 175099 T821 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 175099 T821 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 175100 T821 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 175101 T821 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 175101 T821 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 175102 T821 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 175102 T821 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 175103 T821 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 175103 T821 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 175104 T821 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
   [junit4]   2> 175123 T821 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 175124 T821 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:10121/solr
   [junit4]   2> 175124 T821 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 175125 T821 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 175129 T861 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5a8e0168 name:ZooKeeperConnection Watcher:127.0.0.1:10121 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 175129 T821 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 175144 T821 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
   [junit4]   2> 175157 T821 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 175160 T863 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3ed0eea6 name:ZooKeeperConnection Watcher:127.0.0.1:10121/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 175160 T821 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 175166 T821 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 176097 T844 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 176098 T844 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:10124_",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:10124"}
   [junit4]   2> 176111 T863 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> 176111 T843 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> 176111 T850 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> 176170 T821 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:10128_
   [junit4]   2> 176172 T821 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:10128_
   [junit4]   2> 176176 T850 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 1)
   [junit4]   2> 176176 T843 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 1)
   [junit4]   2> 176176 T863 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 176177 T863 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> 176177 T850 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 176179 T843 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 176186 T864 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 176186 T864 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 176188 T864 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 177618 T844 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 177619 T844 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:10128_",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:10128"}
   [junit4]   2> 177620 T844 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with numShards 2
   [junit4]   2> 177620 T844 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 177640 T850 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> 177640 T843 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> 177640 T863 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> 178190 T864 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 178190 T864 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374335213232/collection1
   [junit4]   2> 178191 T864 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 178192 T864 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 178192 T864 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 178193 T864 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374335213232/collection1/'
   [junit4]   2> 178195 T864 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374335213232/collection1/lib/classes/' to classloader
   [junit4]   2> 178196 T864 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374335213232/collection1/lib/README' to classloader
   [junit4]   2> 178255 T864 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 178326 T864 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 178328 T864 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 178342 T864 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 179004 T864 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 179018 T864 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 179023 T864 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 179044 T864 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 179049 T864 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 179055 T864 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 179056 T864 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 179057 T864 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 179057 T864 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 179059 T864 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 179059 T864 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 179059 T864 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 179060 T864 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374335213232/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZkTest-1374335209307/jetty1/
   [junit4]   2> 179060 T864 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@40fe1db2
   [junit4]   2> 179062 T864 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374335209307/jetty1
   [junit4]   2> 179062 T864 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZkTest-1374335209307/jetty1/index/
   [junit4]   2> 179062 T864 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZkTest-1374335209307/jetty1/index' doesn't exist. Creating new index...
   [junit4]   2> 179065 T864 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374335209307/jetty1/index
   [junit4]   2> 179070 T864 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.MMapDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/index3109231095tmp lockFactory=org.apache.lucene.store.NativeFSLockFactory@4c0c5d6c),segFN=segments_1,generation=1}
   [junit4]   2> 179070 T864 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 179077 T864 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 179078 T864 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 179079 T864 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 179080 T864 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 179080 T864 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 179081 T864 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 179081 T864 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 179082 T864 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 179083 T864 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 179100 T864 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 179109 T864 oass.SolrIndexSearcher.<init> Opening Searcher@27707f2c main
   [junit4]   2> 179111 T864 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 179111 T864 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 179117 T865 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@27707f2c main{StandardDirectoryReader(segments_1:1)}
   [junit4]   2> 179120 T864 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 179121 T864 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:10128 collection:collection1 shard:shard1
   [junit4]   2> 179121 T864 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=30000&socketTimeout=30000&retry=false
   [junit4]   2> 179140 T864 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 179164 T864 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 179176 T864 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 179176 T864 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> 179176 T864 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:10128/collection1/
   [junit4]   2> 179177 T864 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 179177 T864 oasc.SyncStrategy.syncToMe http://127.0.0.1:10128/collection1/ has no replicas
   [junit4]   2> 179177 T864 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:10128/collection1/ shard1
   [junit4]   2> 179178 T864 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 180666 T844 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 180685 T863 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> 180685 T843 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> 180685 T850 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> 180715 T864 oasc.ZkController.register We are http://127.0.0.1:10128/collection1/ and leader is http://127.0.0.1:10128/collection1/
   [junit4]   2> 180715 T864 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:10128
   [junit4]   2> 180715 T864 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 180716 T864 oasc.ZkController.publish publishing core=collection1 state=active
   [junit4]   2> 180716 T864 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 180718 T864 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 180720 T821 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0
   [junit4]   2> 180720 T821 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 180721 T821 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> 181006 T821 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 181009 T821 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:10135
   [junit4]   2> 181010 T821 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 181011 T821 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 181011 T821 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374335219297
   [junit4]   2> 181012 T821 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374335219297/'
   [junit4]   2> 181049 T821 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374335219297/solr.xml
   [junit4]   2> 181149 T821 oasc.CoreContainer.<init> New CoreContainer 528956179
   [junit4]   2> 181150 T821 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374335219297/]
   [junit4]   2> 181152 T821 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 181153 T821 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 181153 T821 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 181154 T821 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 181155 T821 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 181155 T821 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 181156 T821 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 181156 T821 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 181157 T821 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 181157 T821 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
   [junit4]   2> 181174 T821 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 181175 T821 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:10121/solr
   [junit4]   2> 181176 T821 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 181177 T821 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 181180 T877 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7b98153 name:ZooKeeperConnection Watcher:127.0.0.1:10121 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 181181 T821 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 181194 T821 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
   [junit4]   2> 181207 T821 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 181209 T879 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3e0671e1 name:ZooKeeperConnection Watcher:127.0.0.1:10121/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 181209 T821 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 181219 T821 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 182192 T844 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 182194 T844 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:10128_",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:10128"}
   [junit4]   2> 182239 T821 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:10135_
   [junit4]   2> 182241 T850 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> 182241 T843 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> 182241 T879 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> 182241 T863 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> 182311 T821 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:10135_
   [junit4]   2> 182326 T850 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> 182326 T879 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> 182327 T863 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 182327 T843 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> 182327 T863 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> 182328 T850 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 182330 T879 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 182330 T843 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 182337 T880 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 182337 T880 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 182379 T880 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 183817 T844 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 183818 T844 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:10135_",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:10135"}
   [junit4]   2> 183819 T844 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
   [junit4]   2> 183819 T844 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
   [junit4]   2> 183825 T863 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> 183825 T843 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> 183825 T879 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> 183825 T850 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> 184381 T880 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 184381 T880 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374335219297/collection1
   [junit4]   2> 184382 T880 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 184383 T880 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 184383 T880 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 184384 T880 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374335219297/collection1/'
   [junit4]   2> 184386 T880 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374335219297/collection1/lib/classes/' to classloader
   [junit4]   2> 184387 T880 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374335219297/collection1/lib/README' to classloader
   [junit4]   2> 184444 T880 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 184515 T880 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 184517 T880 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 184531 T880 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 185196 T880 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 185211 T880 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 185215 T880 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 185236 T880 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 185241 T880 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 185247 T880 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 185248 T880 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 185249 T880 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 185249 T880 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 185250 T880 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 185251 T880 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 185251 T880 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 185252 T880 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374335219297/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZkTest-1374335209307/jetty2/
   [junit4]   2> 185252 T880 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@40fe1db2
   [junit4]   2> 185254 T880 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374335209307/jetty2
   [junit4]   2> 185254 T880 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZkTest-1374335209307/jetty2/index/
   [junit4]   2> 185254 T880 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZkTest-1374335209307/jetty2/index' doesn't exist. Creating new index...
   [junit4]   2> 185256 T880 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374335209307/jetty2/index
   [junit4]   2> 185262 T880 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.MMapDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/index3109231096tmp lockFactory=org.apache.lucene.store.NativeFSLockFactory@564307ac),segFN=segments_1,generation=1}
   [junit4]   2> 185262 T880 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 185269 T880 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 185269 T880 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 185270 T880 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 185271 T880 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 185272 T880 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 185272 T880 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 185273 T880 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 185274 T880 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 185274 T880 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 185291 T880 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 185300 T880 oass.SolrIndexSearcher.<init> Opening Searcher@4d602e3c main
   [junit4]   2> 185302 T880 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 185302 T880 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 185308 T881 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@4d602e3c main{StandardDirectoryReader(segments_1:1)}
   [junit4]   2> 185311 T880 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 185312 T880 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:10135 collection:collection1 shard:shard2
   [junit4]   2> 185312 T880 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=30000&socketTimeout=30000&retry=false
   [junit4]   2> 185331 T880 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
   [junit4]   2> 185349 T880 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
   [junit4]   2> 185353 T880 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 185354 T880 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> 185354 T880 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:10135/collection1/
   [junit4]   2> 185354 T880 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 185355 T880 oasc.SyncStrategy.syncToMe http://127.0.0.1:10135/collection1/ has no replicas
   [junit4]   2> 185355 T880 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:10135/collection1/ shard2
   [junit4]   2> 185355 T880 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
   [junit4]   2> 186832 T844 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 186854 T850 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> 186854 T843 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> 186854 T879 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> 186854 T863 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> 186892 T880 oasc.ZkController.register We are http://127.0.0.1:10135/collection1/ and leader is http://127.0.0.1:10135/collection1/
   [junit4]   2> 186892 T880 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:10135
   [junit4]   2> 186892 T880 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 186893 T880 oasc.ZkController.publish publishing core=collection1 state=active
   [junit4]   2> 186893 T880 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 186895 T880 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 186897 T821 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0
   [junit4]   2> 186897 T821 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 186898 T821 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> 187193 T821 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 187197 T821 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:10138
   [junit4]   2> 187197 T821 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 187198 T821 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 187199 T821 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374335225474
   [junit4]   2> 187199 T821 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374335225474/'
   [junit4]   2> 187237 T821 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374335225474/solr.xml
   [junit4]   2> 187337 T821 oasc.CoreContainer.<init> New CoreContainer 250041437
   [junit4]   2> 187338 T821 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374335225474/]
   [junit4]   2> 187340 T821 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 187341 T821 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 187341 T821 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 187342 T821 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 187342 T821 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 187343 T821 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 187344 T821 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 187344 T821 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 187345 T821 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 187345 T821 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
   [junit4]   2> 187362 T821 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 187363 T821 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:10121/solr
   [junit4]   2> 187364 T821 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 187365 T821 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 187435 T893 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4882e0f5 name:ZooKeeperConnection Watcher:127.0.0.1:10121 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 187436 T821 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 187439 T821 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
   [junit4]   2> 187451 T821 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 187453 T895 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1923f086 name:ZooKeeperConnection Watcher:127.0.0.1:10121/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 187454 T821 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 187497 T821 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 188369 T844 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 188371 T844 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:10135_",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:10135"}
   [junit4]   2> 188391 T895 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> 188392 T843 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> 188392 T879 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> 188392 T863 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> 188391 T850 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> 188501 T821 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:10138_
   [junit4]   2> 188503 T821 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:10138_
   [junit4]   2> 188506 T895 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> 188506 T843 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> 188506 T850 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> 188506 T879 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> 188506 T863 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 188508 T863 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> 188508 T895 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 188508 T843 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 188515 T850 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 188515 T879 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 188522 T896 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 188523 T896 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 188525 T896 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 189898 T844 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 189899 T844 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:10138_",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:10138"}
   [junit4]   2> 189900 T844 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
   [junit4]   2> 189900 T844 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 189914 T895 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> 189914 T843 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> 189914 T879 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> 189914 T863 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> 189914 T850 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> 190527 T896 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 190527 T896 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374335225474/collection1
   [junit4]   2> 190528 T896 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 190529 T896 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 190529 T896 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 190530 T896 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374335225474/collection1/'
   [junit4]   2> 190532 T896 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374335225474/collection1/lib/README' to classloader
   [junit4]   2> 190533 T896 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374335225474/collection1/lib/classes/' to classloader
   [junit4]   2> 190590 T896 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 190662 T896 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 190664 T896 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 190678 T896 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 191354 T896 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 191376 T896 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 191381 T896 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 191402 T896 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 191407 T896 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 191412 T896 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 191414 T896 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 191414 T896 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 191415 T896 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 191416 T896 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 191416 T896 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 191417 T896 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 191417 T896 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374335225474/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZkTest-1374335209307/jetty3/
   [junit4]   2> 191418 T896 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@40fe1db2
   [junit4]   2> 191420 T896 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374335209307/jetty3
   [junit4]   2> 191421 T896 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZkTest-1374335209307/jetty3/index/
   [junit4]   2> 191421 T896 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZkTest-1374335209307/jetty3/index' doesn't exist. Creating new index...
   [junit4]   2> 191423 T896 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374335209307/jetty3/index
   [junit4]   2> 191428 T896 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.MMapDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/index3109231097tmp lockFactory=org.apache.lucene.store.NativeFSLockFactory@162d44d5),segFN=segments_1,generation=1}
   [junit4]   2> 191429 T896 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 191436 T896 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 191436 T896 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 191437 T896 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 191438 T896 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 191439 T896 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 191439 T896 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 191440 T896 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 191441 T896 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 191441 T896 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 191459 T896 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 191468 T896 oass.SolrIndexSearcher.<init> Opening Searcher@39535b8a main
   [junit4]   2> 191470 T896 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 191470 T896 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 191476 T897 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@39535b8a main{StandardDirectoryReader(segments_1:1)}
   [junit4]   2> 191479 T896 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 191479 T896 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:10138 collection:collection1 shard:shard1
   [junit4]   2> 191480 T896 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=30000&socketTimeout=30000&retry=false
   [junit4]   2> 191538 T896 oasc.ZkController.register We are http://127.0.0.1:10138/collection1/ and leader is http://127.0.0.1:10128/collection1/
   [junit4]   2> 191538 T896 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:10138
   [junit4]   2> 191538 T896 oasc.ZkController.checkRecovery Core needs to recover:collection1
   [junit4]   2> 191539 T896 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
   [junit4]   2> ASYNC  NEW_CORE C76 name=collection1 org.apache.solr.core.SolrCore@2346a766 url=http://127.0.0.1:10138/collection1 node=127.0.0.1:10138_ C76_STATE=coll:collection1 core:collection1 props:{state=down, core=collection1, node_name=127.0.0.1:10138_, base_url=http://127.0.0.1:10138}
   [junit4]   2> 191539 T898 C76 P10138 oasc.RecoveryStrategy.run Starting recovery process.  core=collection1 recoveringAfterStartup=true
   [junit4]   2> 191540 T898 C76 P10138 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
   [junit4]   2> 191540 T896 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 191540 T898 C76 P10138 oasc.ZkController.publish publishing core=collection1 state=recovering
   [junit4]   2> 191541 T898 C76 P10138 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 191542 T821 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0
   [junit4]   2> 191542 T821 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 191542 T898 C76 P10138 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> 191543 T821 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> 191556 T853 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: core_node3, state: recovering, checkLive: true, onlyIfLeader: true
   [junit4]   2> 191836 T821 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 191840 T821 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:10142
   [junit4]   2> 191841 T821 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 191841 T821 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 191842 T821 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty4-1374335230125
   [junit4]   2> 191842 T821 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty4-1374335230125/'
   [junit4]   

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

e.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:180)
   [junit4]   2> 	        at org.apache.solr.cloud.SyncStrategy$1.run(SyncStrategy.java:291)
   [junit4]   2> 	        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
   [junit4]   2> 	        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
   [junit4]   2> 	        at java.lang.Thread.run(Thread.java:722)
   [junit4]   2> NOTE: test params are: codec=Lucene42: {foo_b=PostingsFormat(name=Lucene41WithOrds), n_f1=PostingsFormat(name=Asserting), cat=PostingsFormat(name=TestBloomFilteredLucene41Postings), foo_d=Pulsing41(freqCutoff=17 minBlockSize=72 maxBlockSize=198), n_tl1=PostingsFormat(name=Asserting), foo_f=PostingsFormat(name=Lucene41WithOrds), n_d1=PostingsFormat(name=TestBloomFilteredLucene41Postings), rnd_b=Pulsing41(freqCutoff=17 minBlockSize=72 maxBlockSize=198), intDefault=PostingsFormat(name=TestBloomFilteredLucene41Postings), n_td1=PostingsFormat(name=Asserting), timestamp=PostingsFormat(name=TestBloomFilteredLucene41Postings), id=Pulsing41(freqCutoff=17 minBlockSize=72 maxBlockSize=198), range_facet_sl=PostingsFormat(name=Lucene41WithOrds), range_facet_si=PostingsFormat(name=Asserting), oddField_s=PostingsFormat(name=Lucene41WithOrds), sequence_i=PostingsFormat(name=Lucene41WithOrds), name=Pulsing41(freqCutoff=17 minBlockSize=72 maxBlockSize=198), foo_i=PostingsFormat(name=Asserting), regex_dup_B_s=PostingsFormat(name=TestBloomFilteredLucene41Postings), multiDefault=PostingsFormat(name=Asserting), n_tf1=PostingsFormat(name=TestBloomFilteredLucene41Postings), n_dt1=PostingsFormat(name=Asserting), genre_s=PostingsFormat(name=Lucene41WithOrds), author_t=PostingsFormat(name=Asserting), range_facet_l=PostingsFormat(name=TestBloomFilteredLucene41Postings), n_ti1=Pulsing41(freqCutoff=17 minBlockSize=72 maxBlockSize=198), text=PostingsFormat(name=Lucene41WithOrds), _version_=PostingsFormat(name=TestBloomFilteredLucene41Postings), val_i=Pulsing41(freqCutoff=17 minBlockSize=72 maxBlockSize=198), SubjectTerms_mfacet=PostingsFormat(name=TestBloomFilteredLucene41Postings), series_t=PostingsFormat(name=Asserting), a_t=PostingsFormat(name=TestBloomFilteredLucene41Postings), n_tdt1=PostingsFormat(name=TestBloomFilteredLucene41Postings), regex_dup_A_s=PostingsFormat(name=Lucene41WithOrds), price=PostingsFormat(name=Lucene41WithOrds), other_tl1=PostingsFormat(name=TestBloomFilteredLucene41Postings), n_l1=PostingsFormat(name=TestBloomFilteredLucene41Postings), a_si=PostingsFormat(name=Asserting), inStock=PostingsFormat(name=Lucene41WithOrds)}, docValues:{timestamp=DocValuesFormat(name=Lucene42)}, sim=RandomSimilarityProvider(queryNorm=false,coord=no): {}, locale=ja_JP, timezone=US/Indiana-Starke
   [junit4]   2> NOTE: FreeBSD 9.1-RELEASE-p3 amd64/Oracle Corporation 1.7.0_21 (64-bit)/cpus=16,threads=2,free=269363512,total=426770432
   [junit4]   2> NOTE: All tests run in this JVM: [PreAnalyzedFieldTest, TestSchemaNameResource, LeaderElectionTest, TestSolrDeletionPolicy1, TestDynamicFieldCollectionResource, TestXIncludeConfig, ZkControllerTest, BadCopyFieldTest, SOLR749Test, DistributedTermsComponentTest, SolrInfoMBeanTest, DistributedQueryElevationComponentTest, ShardRoutingTest, SliceStateTest, TestDynamicFieldResource, CacheHeaderTest, TestSolrCoreProperties, BasicDistributedZkTest]
   [junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=BasicDistributedZkTest -Dtests.seed=C18A2261C446C504 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=ja_JP -Dtests.timezone=US/Indiana-Starke -Dtests.file.encoding=UTF-8
   [junit4] ERROR   0.00s J0 | BasicDistributedZkTest (suite) <<<
   [junit4]    > Throwable #1: com.carrotsearch.randomizedtesting.ThreadLeakError: 1 thread leaked from SUITE scope at org.apache.solr.cloud.BasicDistributedZkTest: 
   [junit4]    >    1) Thread[id=1319, name=recoveryCmdExecutor-309-thread-1, state=RUNNABLE, group=TGRP-BasicDistributedZkTest]
   [junit4]    >         at java.net.PlainSocketImpl.socketConnect(Native Method)
   [junit4]    >         at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:339)
   [junit4]    >         at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:200)
   [junit4]    >         at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:182)
   [junit4]    >         at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:391)
   [junit4]    >         at java.net.Socket.connect(Socket.java:579)
   [junit4]    >         at org.apache.http.conn.scheme.PlainSocketFactory.connectSocket(PlainSocketFactory.java:127)
   [junit4]    >         at org.apache.http.impl.conn.DefaultClientConnectionOperator.openConnection(DefaultClientConnectionOperator.java:180)
   [junit4]    >         at org.apache.http.impl.conn.ManagedClientConnectionImpl.open(ManagedClientConnectionImpl.java:294)
   [junit4]    >         at org.apache.http.impl.client.DefaultRequestDirector.tryConnect(DefaultRequestDirector.java:645)
   [junit4]    >         at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:480)
   [junit4]    >         at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:906)
   [junit4]    >         at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:805)
   [junit4]    >         at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:784)
   [junit4]    >         at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:365)
   [junit4]    >         at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:180)
   [junit4]    >         at org.apache.solr.cloud.SyncStrategy$1.run(SyncStrategy.java:291)
   [junit4]    >         at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
   [junit4]    >         at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
   [junit4]    >         at java.lang.Thread.run(Thread.java:722)
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([C18A2261C446C504]:0)Throwable #2: com.carrotsearch.randomizedtesting.ThreadLeakError: There are still zombie threads that couldn't be terminated:
   [junit4]    >    1) Thread[id=1319, name=recoveryCmdExecutor-309-thread-1, state=RUNNABLE, group=TGRP-BasicDistributedZkTest]
   [junit4]    >         at java.net.PlainSocketImpl.socketConnect(Native Method)
   [junit4]    >         at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:339)
   [junit4]    >         at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:200)
   [junit4]    >         at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:182)
   [junit4]    >         at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:391)
   [junit4]    >         at java.net.Socket.connect(Socket.java:579)
   [junit4]    >         at org.apache.http.conn.scheme.PlainSocketFactory.connectSocket(PlainSocketFactory.java:127)
   [junit4]    >         at org.apache.http.impl.conn.DefaultClientConnectionOperator.openConnection(DefaultClientConnectionOperator.java:180)
   [junit4]    >         at org.apache.http.impl.conn.ManagedClientConnectionImpl.open(ManagedClientConnectionImpl.java:294)
   [junit4]    >         at org.apache.http.impl.client.DefaultRequestDirector.tryConnect(DefaultRequestDirector.java:645)
   [junit4]    >         at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:480)
   [junit4]    >         at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:906)
   [junit4]    >         at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:805)
   [junit4]    >         at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:784)
   [junit4]    >         at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:365)
   [junit4]    >         at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:180)
   [junit4]    >         at org.apache.solr.cloud.SyncStrategy$1.run(SyncStrategy.java:291)
   [junit4]    >         at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
   [junit4]    >         at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
   [junit4]    >         at java.lang.Thread.run(Thread.java:722)
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([C18A2261C446C504]:0)
   [junit4] Completed on J0 in 483.19s, 1 test, 2 errors <<< FAILURES!

[...truncated 779 lines...]
BUILD FAILED
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/build.xml:389: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/build.xml:369: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/build.xml:39: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build.xml:181: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/common-build.xml:449: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/lucene/common-build.xml:1247: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/lucene/common-build.xml:890: There were test failures: 318 suites, 1342 tests, 2 suite-level errors, 955 ignored (1 assumption)

Total time: 36 minutes 15 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