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-4.x-Java7 - Build # 1427 - Still Failing
Date Sat, 20 Jul 2013 03:50:36 GMT
Build: https://builds.apache.org/job/Lucene-Solr-Tests-4.x-Java7/1427/

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=2112, name=recoveryCmdExecutor-894-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=2112, name=recoveryCmdExecutor-894-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([61518CB492DA6B01]: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=2112, name=recoveryCmdExecutor-894-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=2112, name=recoveryCmdExecutor-894-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([61518CB492DA6B01]:0)




Build Log:
[...truncated 9423 lines...]
   [junit4] Suite: org.apache.solr.cloud.BasicDistributedZkTest
   [junit4]   2> 395438 T1635 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
   [junit4]   2> 395445 T1635 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
   [junit4]   2> Creating dataDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./solrtest-BasicDistributedZkTest-1374291363665
   [junit4]   2> 395447 T1635 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   2> 395448 T1636 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 395548 T1635 oasc.ZkTestServer.run start zk server on port:11942
   [junit4]   2> 395549 T1635 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 395555 T1642 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2831b9e2 name:ZooKeeperConnection Watcher:127.0.0.1:11942 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 395555 T1635 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 395556 T1635 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 395561 T1635 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 395576 T1644 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7aa62c53 name:ZooKeeperConnection Watcher:127.0.0.1:11942/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 395576 T1635 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 395577 T1635 oascc.SolrZkClient.makePath makePath: /collections/collection1
   [junit4]   2> 395581 T1635 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
   [junit4]   2> 395593 T1635 oascc.SolrZkClient.makePath makePath: /collections/control_collection
   [junit4]   2> 395596 T1635 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
   [junit4]   2> 395611 T1635 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
   [junit4]   2> 395612 T1635 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
   [junit4]   2> 395634 T1635 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
   [junit4]   2> 395635 T1635 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
   [junit4]   2> 395739 T1635 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
   [junit4]   2> 395740 T1635 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
   [junit4]   2> 395743 T1635 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
   [junit4]   2> 395743 T1635 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
   [junit4]   2> 395746 T1635 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
   [junit4]   2> 395747 T1635 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
   [junit4]   2> 395760 T1635 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
   [junit4]   2> 395760 T1635 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
   [junit4]   2> 395770 T1635 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 395771 T1635 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 395774 T1635 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
   [junit4]   2> 395775 T1635 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
   [junit4]   2> 395787 T1635 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
   [junit4]   2> 395787 T1635 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
   [junit4]   2> 396013 T1635 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 396018 T1635 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:11945
   [junit4]   2> 396019 T1635 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 396020 T1635 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 396020 T1635 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374291364010
   [junit4]   2> 396021 T1635 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374291364010/'
   [junit4]   2> 396069 T1635 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374291364010/solr.xml
   [junit4]   2> 396189 T1635 oasc.CoreContainer.<init> New CoreContainer 1178875998
   [junit4]   2> 396190 T1635 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374291364010/]
   [junit4]   2> 396192 T1635 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 396193 T1635 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 396193 T1635 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 396194 T1635 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 396194 T1635 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 396195 T1635 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 396195 T1635 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 396196 T1635 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 396196 T1635 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 396197 T1635 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
   [junit4]   2> 396219 T1635 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 396220 T1635 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:11942/solr
   [junit4]   2> 396241 T1635 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 396243 T1635 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 396247 T1655 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7a322f4 name:ZooKeeperConnection Watcher:127.0.0.1:11942 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 396248 T1635 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 396273 T1635 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
   [junit4]   2> 396295 T1635 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 396297 T1657 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@38b0a839 name:ZooKeeperConnection Watcher:127.0.0.1:11942/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 396298 T1635 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 396300 T1635 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 396315 T1635 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 396319 T1635 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 396326 T1635 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:11945_
   [junit4]   2> 396327 T1635 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:11945_
   [junit4]   2> 396330 T1635 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 396366 T1635 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 396384 T1635 oasc.Overseer.start Overseer (id=90065558809542659-127.0.0.1:11945_-n_0000000000) starting
   [junit4]   2> 396394 T1635 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 396405 T1659 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 396406 T1635 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 396408 T1635 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 396417 T1635 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 396419 T1658 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 396424 T1660 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 396425 T1660 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 396427 T1660 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 397922 T1658 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 397923 T1658 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:11945_",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:11945"}
   [junit4]   2> 397923 T1658 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with numShards 1
   [junit4]   2> 397923 T1658 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 397949 T1657 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> 398429 T1660 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 398429 T1660 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374291364010/collection1
   [junit4]   2> 398430 T1660 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
   [junit4]   2> 398430 T1660 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 398431 T1660 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
   [junit4]   2> 398432 T1660 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374291364010/collection1/'
   [junit4]   2> 398434 T1660 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374291364010/collection1/lib/classes/' to classloader
   [junit4]   2> 398434 T1660 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374291364010/collection1/lib/README' to classloader
   [junit4]   2> 398497 T1660 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_45
   [junit4]   2> 398566 T1660 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 398668 T1660 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 398677 T1660 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 399185 T1660 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 399186 T1660 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 399187 T1660 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 399197 T1660 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 399200 T1660 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 399213 T1660 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 399217 T1660 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 399220 T1660 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 399221 T1660 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 399221 T1660 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 399222 T1660 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 399222 T1660 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 399222 T1660 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 399223 T1660 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 399223 T1660 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374291364010/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZkTest-1374291363664/control/data/
   [junit4]   2> 399223 T1660 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@70ad1339
   [junit4]   2> 399224 T1660 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374291363664/control/data
   [junit4]   2> 399224 T1660 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZkTest-1374291363664/control/data/index/
   [junit4]   2> 399224 T1660 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZkTest-1374291363664/control/data/index' doesn't exist. Creating new index...
   [junit4]   2> 399225 T1660 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374291363664/control/data/index
   [junit4]   2> 399228 T1660 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@5d1a5f6 lockFactory=org.apache.lucene.store.NativeFSLockFactory@31768b95),segFN=segments_1,generation=1}
   [junit4]   2> 399229 T1660 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 399232 T1660 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 399233 T1660 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 399233 T1660 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 399234 T1660 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 399234 T1660 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 399234 T1660 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 399235 T1660 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 399235 T1660 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 399235 T1660 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 399248 T1660 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 399254 T1660 oass.SolrIndexSearcher.<init> Opening Searcher@6ff52d00 main
   [junit4]   2> 399256 T1660 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 399256 T1660 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 399258 T1661 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@6ff52d00 main{StandardDirectoryReader(segments_1:1)}
   [junit4]   2> 399260 T1660 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 399260 T1660 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:11945 collection:control_collection shard:shard1
   [junit4]   2> 399270 T1660 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=30000&socketTimeout=30000&retry=false
   [junit4]   2> 399283 T1660 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
   [junit4]   2> 399303 T1660 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 399305 T1660 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 399305 T1660 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> 399306 T1660 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:11945/collection1/
   [junit4]   2> 399306 T1660 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 399306 T1660 oasc.SyncStrategy.syncToMe http://127.0.0.1:11945/collection1/ has no replicas
   [junit4]   2> 399307 T1660 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:11945/collection1/ shard1
   [junit4]   2> 399307 T1660 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
   [junit4]   2> 399453 T1658 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 399473 T1657 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> 399515 T1660 oasc.ZkController.register We are http://127.0.0.1:11945/collection1/ and leader is http://127.0.0.1:11945/collection1/
   [junit4]   2> 399515 T1660 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:11945
   [junit4]   2> 399515 T1660 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 399516 T1660 oasc.ZkController.publish publishing core=collection1 state=active
   [junit4]   2> 399516 T1660 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 399518 T1660 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 399519 T1635 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0
   [junit4]   2> 399520 T1635 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 399520 T1635 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> 399535 T1635 oascsi.HttpClientUtil.createClient Creating new http client, config:
   [junit4]   2> 399546 T1635 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 399550 T1664 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@45e7a93d name:ZooKeeperConnection Watcher:127.0.0.1:11942/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 399550 T1635 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 399551 T1635 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 399556 T1635 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
   [junit4]   2> 399865 T1635 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 399869 T1635 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:11949
   [junit4]   2> 399869 T1635 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 399870 T1635 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 399871 T1635 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374291367775
   [junit4]   2> 399871 T1635 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374291367775/'
   [junit4]   2> 399912 T1635 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374291367775/solr.xml
   [junit4]   2> 400007 T1635 oasc.CoreContainer.<init> New CoreContainer 1174901388
   [junit4]   2> 400008 T1635 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374291367775/]
   [junit4]   2> 400010 T1635 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 400011 T1635 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 400011 T1635 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 400012 T1635 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 400012 T1635 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 400013 T1635 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 400013 T1635 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 400014 T1635 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 400014 T1635 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 400015 T1635 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
   [junit4]   2> 400033 T1635 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 400034 T1635 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:11942/solr
   [junit4]   2> 400034 T1635 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 400035 T1635 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 400043 T1675 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@69df73f9 name:ZooKeeperConnection Watcher:127.0.0.1:11942 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 400043 T1635 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 400128 T1635 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
   [junit4]   2> 400141 T1635 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 400150 T1677 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5288eedc name:ZooKeeperConnection Watcher:127.0.0.1:11942/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 400150 T1635 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 400175 T1635 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 400978 T1658 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 400980 T1658 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:11945_",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:11945"}
   [junit4]   2> 400995 T1677 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> 400995 T1664 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> 400995 T1657 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> 401179 T1635 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:11949_
   [junit4]   2> 401184 T1635 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:11949_
   [junit4]   2> 401240 T1677 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> 401240 T1664 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> 401241 T1657 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 401241 T1657 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> 401242 T1677 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 401243 T1664 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 401251 T1678 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 401251 T1678 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 401253 T1678 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 402500 T1658 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 402501 T1658 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:11949_",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:11949"}
   [junit4]   2> 402502 T1658 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with numShards 2
   [junit4]   2> 402502 T1658 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 402518 T1657 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> 402518 T1677 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> 402518 T1664 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> 403255 T1678 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 403255 T1678 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374291367775/collection1
   [junit4]   2> 403255 T1678 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 403256 T1678 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 403257 T1678 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 403258 T1678 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374291367775/collection1/'
   [junit4]   2> 403259 T1678 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374291367775/collection1/lib/README' to classloader
   [junit4]   2> 403260 T1678 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374291367775/collection1/lib/classes/' to classloader
   [junit4]   2> 403320 T1678 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_45
   [junit4]   2> 403387 T1678 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 403489 T1678 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 403502 T1678 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 404208 T1678 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 404209 T1678 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 404210 T1678 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 404228 T1678 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 404233 T1678 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 404248 T1678 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 404254 T1678 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 404259 T1678 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 404260 T1678 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 404260 T1678 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 404260 T1678 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 404261 T1678 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 404262 T1678 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 404262 T1678 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 404262 T1678 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374291367775/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZkTest-1374291363664/jetty1/
   [junit4]   2> 404263 T1678 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@70ad1339
   [junit4]   2> 404264 T1678 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374291363664/jetty1
   [junit4]   2> 404264 T1678 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZkTest-1374291363664/jetty1/index/
   [junit4]   2> 404265 T1678 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZkTest-1374291363664/jetty1/index' doesn't exist. Creating new index...
   [junit4]   2> 404265 T1678 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374291363664/jetty1/index
   [junit4]   2> 404269 T1678 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@2790733e lockFactory=org.apache.lucene.store.NativeFSLockFactory@561673ee),segFN=segments_1,generation=1}
   [junit4]   2> 404270 T1678 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 404276 T1678 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 404277 T1678 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 404278 T1678 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 404279 T1678 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 404279 T1678 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 404280 T1678 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 404280 T1678 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 404281 T1678 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 404281 T1678 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 404301 T1678 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 404311 T1678 oass.SolrIndexSearcher.<init> Opening Searcher@b4b8076 main
   [junit4]   2> 404312 T1678 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 404312 T1678 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 404318 T1679 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@b4b8076 main{StandardDirectoryReader(segments_1:1)}
   [junit4]   2> 404321 T1678 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 404321 T1678 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:11949 collection:collection1 shard:shard1
   [junit4]   2> 404321 T1678 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=30000&socketTimeout=30000&retry=false
   [junit4]   2> 404341 T1678 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 404362 T1678 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 404375 T1678 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 404375 T1678 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> 404375 T1678 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:11949/collection1/
   [junit4]   2> 404376 T1678 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 404376 T1678 oasc.SyncStrategy.syncToMe http://127.0.0.1:11949/collection1/ has no replicas
   [junit4]   2> 404376 T1678 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:11949/collection1/ shard1
   [junit4]   2> 404377 T1678 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 405524 T1658 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 405552 T1664 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> 405552 T1657 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> 405552 T1677 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> 405578 T1678 oasc.ZkController.register We are http://127.0.0.1:11949/collection1/ and leader is http://127.0.0.1:11949/collection1/
   [junit4]   2> 405578 T1678 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:11949
   [junit4]   2> 405578 T1678 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 405579 T1678 oasc.ZkController.publish publishing core=collection1 state=active
   [junit4]   2> 405579 T1678 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 405581 T1678 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 405582 T1635 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0
   [junit4]   2> 405582 T1635 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 405583 T1635 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> 405808 T1635 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 405811 T1635 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:11952
   [junit4]   2> 405812 T1635 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 405812 T1635 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 405812 T1635 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374291373810
   [junit4]   2> 405813 T1635 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374291373810/'
   [junit4]   2> 405843 T1635 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374291373810/solr.xml
   [junit4]   2> 405909 T1635 oasc.CoreContainer.<init> New CoreContainer 1629369043
   [junit4]   2> 405910 T1635 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374291373810/]
   [junit4]   2> 405911 T1635 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 405912 T1635 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 405912 T1635 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 405912 T1635 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 405913 T1635 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 405913 T1635 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 405913 T1635 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 405914 T1635 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 405914 T1635 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 405915 T1635 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
   [junit4]   2> 405929 T1635 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 405930 T1635 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:11942/solr
   [junit4]   2> 405930 T1635 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 405931 T1635 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 405934 T1691 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5af5db4b name:ZooKeeperConnection Watcher:127.0.0.1:11942 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 405935 T1635 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 405947 T1635 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
   [junit4]   2> 405957 T1635 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 405960 T1693 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5282e92c name:ZooKeeperConnection Watcher:127.0.0.1:11942/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 405960 T1635 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 405969 T1635 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 406972 T1635 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:11952_
   [junit4]   2> 406977 T1635 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:11952_
   [junit4]   2> 407044 T1664 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> 407044 T1677 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> 407045 T1693 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 407045 T1657 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 407046 T1657 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> 407046 T1664 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 407047 T1677 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 407055 T1694 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 407055 T1694 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 407057 T1694 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 407058 T1658 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 407059 T1658 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:11949_",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:11949"}
   [junit4]   2> 407068 T1658 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:11952_",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:11952"}
   [junit4]   2> 407068 T1658 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
   [junit4]   2> 407068 T1658 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
   [junit4]   2> 407081 T1693 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 407081 T1664 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> 407081 T1657 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> 407081 T1677 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> 408058 T1694 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 408058 T1694 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374291373810/collection1
   [junit4]   2> 408058 T1694 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 408059 T1694 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 408060 T1694 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 408061 T1694 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374291373810/collection1/'
   [junit4]   2> 408062 T1694 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374291373810/collection1/lib/README' to classloader
   [junit4]   2> 408063 T1694 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374291373810/collection1/lib/classes/' to classloader
   [junit4]   2> 408129 T1694 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_45
   [junit4]   2> 408199 T1694 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 408300 T1694 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 408313 T1694 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 409001 T1694 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 409002 T1694 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 409003 T1694 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 409017 T1694 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 409022 T1694 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 409036 T1694 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 409041 T1694 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 409046 T1694 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 409052 T1694 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 409052 T1694 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 409053 T1694 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 409054 T1694 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 409054 T1694 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 409055 T1694 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 409055 T1694 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374291373810/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZkTest-1374291363664/jetty2/
   [junit4]   2> 409056 T1694 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@70ad1339
   [junit4]   2> 409057 T1694 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374291363664/jetty2
   [junit4]   2> 409057 T1694 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZkTest-1374291363664/jetty2/index/
   [junit4]   2> 409058 T1694 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZkTest-1374291363664/jetty2/index' doesn't exist. Creating new index...
   [junit4]   2> 409058 T1694 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374291363664/jetty2/index
   [junit4]   2> 409062 T1694 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@73eb69c7 lockFactory=org.apache.lucene.store.NativeFSLockFactory@276441f),segFN=segments_1,generation=1}
   [junit4]   2> 409063 T1694 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 409069 T1694 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 409069 T1694 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 409070 T1694 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 409071 T1694 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 409072 T1694 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 409072 T1694 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 409072 T1694 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 409073 T1694 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 409073 T1694 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 409092 T1694 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 409101 T1694 oass.SolrIndexSearcher.<init> Opening Searcher@168a067a main
   [junit4]   2> 409102 T1694 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 409102 T1694 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 409107 T1695 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@168a067a main{StandardDirectoryReader(segments_1:1)}
   [junit4]   2> 409110 T1694 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 409110 T1694 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:11952 collection:collection1 shard:shard2
   [junit4]   2> 409110 T1694 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=30000&socketTimeout=30000&retry=false
   [junit4]   2> 409128 T1694 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
   [junit4]   2> 409146 T1694 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
   [junit4]   2> 409154 T1694 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 409155 T1694 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> 409155 T1694 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:11952/collection1/
   [junit4]   2> 409155 T1694 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 409156 T1694 oasc.SyncStrategy.syncToMe http://127.0.0.1:11952/collection1/ has no replicas
   [junit4]   2> 409156 T1694 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:11952/collection1/ shard2
   [junit4]   2> 409156 T1694 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
   [junit4]   2> 410089 T1658 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 410111 T1677 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> 410111 T1664 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> 410111 T1657 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> 410111 T1693 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 410138 T1694 oasc.ZkController.register We are http://127.0.0.1:11952/collection1/ and leader is http://127.0.0.1:11952/collection1/
   [junit4]   2> 410138 T1694 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:11952
   [junit4]   2> 410138 T1694 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 410138 T1694 oasc.ZkController.publish publishing core=collection1 state=active
   [junit4]   2> 410138 T1694 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 410140 T1694 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 410141 T1635 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0
   [junit4]   2> 410142 T1635 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 410142 T1635 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> 410457 T1635 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 410461 T1635 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:37501
   [junit4]   2> 410462 T1635 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 410462 T1635 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 410463 T1635 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374291378374
   [junit4]   2> 410463 T1635 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374291378374/'
   [junit4]   2> 410506 T1635 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374291378374/solr.xml
   [junit4]   2> 410608 T1635 oasc.CoreContainer.<init> New CoreContainer 1819586576
   [junit4]   2> 410609 T1635 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374291378374/]
   [junit4]   2> 410611 T1635 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 410612 T1635 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 410612 T1635 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 410613 T1635 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 410613 T1635 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 410614 T1635 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 410614 T1635 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 410615 T1635 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 410615 T1635 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 410616 T1635 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
   [junit4]   2> 410635 T1635 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 410635 T1635 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:11942/solr
   [junit4]   2> 410636 T1635 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 410637 T1635 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 410640 T1707 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@29722e5 name:ZooKeeperConnection Watcher:127.0.0.1:11942 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 410640 T1635 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 410652 T1635 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
   [junit4]   2> 410664 T1635 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 410667 T1709 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1c210064 name:ZooKeeperConnection Watcher:127.0.0.1:11942/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 410667 T1635 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 410675 T1635 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 411624 T1658 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 411625 T1658 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:11952_",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:11952"}
   [junit4]   2> 411641 T1664 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> 411641 T1693 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 411641 T1709 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> 411641 T1657 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> 411641 T1677 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> 411678 T1635 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:37501_
   [junit4]   2> 411680 T1635 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:37501_
   [junit4]   2> 411683 T1677 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> 411683 T1664 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> 411684 T1693 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 411684 T1709 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 411684 T1657 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 411684 T1709 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> 411684 T1693 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
   [junit4]   2> 411685 T1657 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> 411685 T1677 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 411685 T1664 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 411692 T1710 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 411692 T1710 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 411693 T1710 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 413149 T1658 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 413151 T1658 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:37501_",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:37501"}
   [junit4]   2> 413151 T1658 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
   [junit4]   2> 413151 T1658 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 413164 T1677 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> 413164 T1709 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> 413164 T1664 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> 413164 T1693 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
   [junit4]   2> 413164 T1657 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> 413696 T1710 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 413696 T1710 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374291378374/collection1
   [junit4]   2> 413696 T1710 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 413697 T1710 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 413698 T1710 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 413699 T1710 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374291378374/collection1/'
   [junit4]   2> 413700 T1710 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374291378374/collection1/lib/README' to classloader
   [junit4]   2> 413701 T1710 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374291378374/collection1/lib/classes/' to classloader
   [junit4]   2> 413773 T1710 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_45
   [junit4]   2> 413839 T1710 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 413941 T1710 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 413954 T1710 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 414657 T1710 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 414658 T1710 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 414659 T1710 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 414673 T1710 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 414677 T1710 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 414691 T1710 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 414696 T1710 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 414702 T1710 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 414704 T1710 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 414704 T1710 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 414705 T1710 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 414706 T1710 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 414706 T1710 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 414706 T1710 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 414707 T1710 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374291378374/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZkTest-1374291363664/jetty3/
   [junit4]   2> 414707 T1710 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@70ad1339
   [junit4]   2> 414708 T1710 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374291363664/jetty3
   [junit4]   2> 414709 T1710 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZkTest-1374291363664/jetty3/index/
   [junit4]   2> 414709 T1710 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZkTest-1374291363664/jetty3/index' doesn't exist. Creating new index...
   [junit4]   2> 414709 T1710 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374291363664/jetty3/index
   [junit4]   2> 414713 T1710 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@50e7ac8f lockFactory=org.apache.lucene.store.NativeFSLockFactory@73ac331b),segFN=segments_1,generation=1}
   [junit4]   2> 414714 T1710 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 414720 T1710 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 414720 T1710 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 414721 T1710 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 414722 T1710 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 414722 T1710 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 414723 T1710 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 414723 T1710 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 414724 T1710 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 414724 T1710 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 414741 T1710 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 414748 T1710 oass.SolrIndexSearcher.<init> Opening Searcher@36e1359c main
   [junit4]   2> 414750 T1710 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 414750 T1710 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 414755 T1711 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@36e1359c main{StandardDirectoryReader(segments_1:1)}
   [junit4]   2> 414758 T1710 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 414758 T1710 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:37501 collection:collection1 shard:shard1
   [junit4]   2> 414758 T1710 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=30000&socketTimeout=30000&retry=false
   [junit4]   2> 414778 T1710 oasc.ZkController.register We are http://127.0.0.1:37501/collection1/ and leader is http://127.0.0.1:11949/collection1/
   [junit4]   2> 414778 T1710 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:37501
   [junit4]   2> 414778 T1710 oasc.ZkController.checkRecovery Core needs to recover:collection1
   [junit4]   2> 414779 T1710 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
   [junit4]   2> ASYNC  NEW_CORE C1177 name=collection1 org.apache.solr.core.SolrCore@291a8bfe url=http://127.0.0.1:37501/collection1 node=127.0.0.1:37501_ C1177_STATE=coll:collection1 core:collection1 props:{state=down, core=collection1, node_name=127.0.0.1:37501_, base_url=http://127.0.0.1:37501}
   [junit4]   2> 414787 T1712 C1177 P37501 oasc.RecoveryStrategy.run Starting recovery process.  core=collection1 recoveringAfterStartup=true
   [junit4]   2> 414788 T1710 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 414788 T1712 C1177 P37501 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
   [junit4]   2> 414789 T1712 C1177 P37501 oasc.ZkController.publish publishing core=collection1 state=recovering
   [junit4]   2> 414789 T1712 C1177 P37501 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 414790 T1635 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0
   [junit4]   2> 414790 T1635 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 414791 T1635 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> 414791 T1712 C1177 P37501 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> 414820 T1667 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: core_node3, state: recovering, checkLive: true, onlyIfLeader: true
   [junit4]   2> 415099 T1635 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 415102 T1635 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:42978
   [junit4]   2> 415102 T1635 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 415103 T1635 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 415104 T1635 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty4-1374291383025
   [junit4]   2> 415104 T1635 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty4-1374291383025/'
   [junit4]   2> 415147 T1635 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/works

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

112, name=recoveryCmdExecutor-894-thread-1, state=RUNNABLE, group=TGRP-BasicDistributedZkTest]
   [junit4]   2> 	        at java.net.PlainSocketImpl.socketConnect(Native Method)
   [junit4]   2> 	        at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:339)
   [junit4]   2> 	        at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:200)
   [junit4]   2> 	        at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:182)
   [junit4]   2> 	        at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:391)
   [junit4]   2> 	        at java.net.Socket.connect(Socket.java:579)
   [junit4]   2> 	        at org.apache.http.conn.scheme.PlainSocketFactory.connectSocket(PlainSocketFactory.java:127)
   [junit4]   2> 	        at org.apache.http.impl.conn.DefaultClientConnectionOperator.openConnection(DefaultClientConnectionOperator.java:180)
   [junit4]   2> 	        at org.apache.http.impl.conn.ManagedClientConnectionImpl.open(ManagedClientConnectionImpl.java:294)
   [junit4]   2> 	        at org.apache.http.impl.client.DefaultRequestDirector.tryConnect(DefaultRequestDirector.java:645)
   [junit4]   2> 	        at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:480)
   [junit4]   2> 	        at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:906)
   [junit4]   2> 	        at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:805)
   [junit4]   2> 	        at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:784)
   [junit4]   2> 	        at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:365)
   [junit4]   2> 	        at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:180)
   [junit4]   2> 	        at org.apache.solr.cloud.SyncStrategy$1.run(SyncStrategy.java:291)
   [junit4]   2> 	        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
   [junit4]   2> 	        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
   [junit4]   2> 	        at java.lang.Thread.run(Thread.java:722)
   [junit4]   2> NOTE: test params are: codec=Lucene3x, sim=DefaultSimilarity, locale=es_US, timezone=Libya
   [junit4]   2> NOTE: FreeBSD 9.1-RELEASE-p3 amd64/Oracle Corporation 1.7.0_21 (64-bit)/cpus=16,threads=2,free=158805584,total=373293056
   [junit4]   2> NOTE: All tests run in this JVM: [TestBadConfig, TestSolr4Spatial, TestValueSourceCache, TestPluginEnable, TestReplicationHandler, TestPHPSerializedResponseWriter, TestRemoteStreaming, URLClassifyProcessorTest, TestCopyFieldCollectionResource, TestSchemaVersionResource, TestIBSimilarityFactory, OverseerTest, ScriptEngineTest, DocumentBuilderTest, SolrInfoMBeanTest, TestPartialUpdateDeduplication, TermsComponentTest, TestBM25SimilarityFactory, EchoParamsTest, TestFuzzyAnalyzedSuggestions, TestSuggestSpellingConverter, UniqFieldsUpdateProcessorFactoryTest, PrimitiveFieldTypeTest, PeerSyncTest, ReturnFieldsTest, MBeansHandlerTest, QueryEqualityTest, TestJmxIntegration, FileBasedSpellCheckerTest, TestSolrQueryParserResource, MinimalSchemaTest, TestUtils, QueryElevationComponentTest, ConvertedLegacyTest, StandardRequestHandlerTest, CacheHeaderTest, OpenCloseCoreStressTest, BasicDistributedZkTest]
   [junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=BasicDistributedZkTest -Dtests.seed=61518CB492DA6B01 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=es_US -Dtests.timezone=Libya -Dtests.file.encoding=US-ASCII
   [junit4] ERROR   0.00s J0 | BasicDistributedZkTest (suite) <<<
   [junit4]    > Throwable #1: com.carrotsearch.randomizedtesting.ThreadLeakError: 1 thread leaked from SUITE scope at org.apache.solr.cloud.BasicDistributedZkTest: 
   [junit4]    >    1) Thread[id=2112, name=recoveryCmdExecutor-894-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([61518CB492DA6B01]:0)Throwable #2: com.carrotsearch.randomizedtesting.ThreadLeakError: There are still zombie threads that couldn't be terminated:
   [junit4]    >    1) Thread[id=2112, name=recoveryCmdExecutor-894-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([61518CB492DA6B01]:0)
   [junit4] Completed on J0 in 418.53s, 1 test, 2 errors <<< FAILURES!

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

Total time: 47 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