You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Apache Jenkins Server <je...@builds.apache.org> on 2013/07/26 16:42:43 UTC
[JENKINS] Lucene-Solr-Tests-trunk-Java7 - Build # 4178 - Still
Failing
Build: https://builds.apache.org/job/Lucene-Solr-Tests-trunk-Java7/4178/
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=2237, name=recoveryCmdExecutor-980-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:392) 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:724)
Stack Trace:
com.carrotsearch.randomizedtesting.ThreadLeakError: 1 thread leaked from SUITE scope at org.apache.solr.cloud.BasicDistributedZkTest:
1) Thread[id=2237, name=recoveryCmdExecutor-980-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:392)
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:724)
at __randomizedtesting.SeedInfo.seed([38900BE09D7724C5]: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=2237, name=recoveryCmdExecutor-980-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:392) 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:724)
Stack Trace:
com.carrotsearch.randomizedtesting.ThreadLeakError: There are still zombie threads that couldn't be terminated:
1) Thread[id=2237, name=recoveryCmdExecutor-980-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:392)
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:724)
at __randomizedtesting.SeedInfo.seed([38900BE09D7724C5]:0)
Build Log:
[...truncated 10018 lines...]
[junit4] Suite: org.apache.solr.cloud.BasicDistributedZkTest
[junit4] 2> 1150206 T1752 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
[junit4] 2> 1150212 T1752 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4] 2> Creating dataDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./solrtest-BasicDistributedZkTest-1374849239138
[junit4] 2> 1150214 T1752 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 1150215 T1753 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 1150316 T1752 oasc.ZkTestServer.run start zk server on port:18692
[junit4] 2> 1150317 T1752 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1150321 T1759 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4c6ee3b9 name:ZooKeeperConnection Watcher:127.0.0.1:18692 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1150322 T1752 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1150322 T1752 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 1150338 T1752 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1150340 T1761 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4f64c44c name:ZooKeeperConnection Watcher:127.0.0.1:18692/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1150340 T1752 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1150341 T1752 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4] 2> 1150350 T1752 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4] 2> 1150352 T1752 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4] 2> 1150355 T1752 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4] 2> 1150358 T1752 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4] 2> 1150359 T1752 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4] 2> 1150376 T1752 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
[junit4] 2> 1150377 T1752 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4] 2> 1150480 T1752 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4] 2> 1150481 T1752 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4] 2> 1150484 T1752 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4] 2> 1150485 T1752 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4] 2> 1150488 T1752 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4] 2> 1150489 T1752 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4] 2> 1150500 T1752 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4] 2> 1150500 T1752 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4] 2> 1150503 T1752 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 1150504 T1752 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 1150507 T1752 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4] 2> 1150508 T1752 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4] 2> 1150511 T1752 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4] 2> 1150511 T1752 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4] 2> 1150791 T1752 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 1150795 T1752 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:32597
[junit4] 2> 1150795 T1752 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 1150796 T1752 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1150796 T1752 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374849239440
[junit4] 2> 1150797 T1752 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374849239440/'
[junit4] 2> 1150835 T1752 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374849239440/solr.xml
[junit4] 2> 1150926 T1752 oasc.CoreContainer.<init> New CoreContainer 932912862
[junit4] 2> 1150927 T1752 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374849239440/]
[junit4] 2> 1150929 T1752 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 1150930 T1752 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 1150930 T1752 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 1150931 T1752 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 1150931 T1752 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 1150932 T1752 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 1150932 T1752 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 1150933 T1752 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 1150933 T1752 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 1150934 T1752 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4] 2> 1150951 T1752 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:18692/solr
[junit4] 2> 1150952 T1752 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 1150954 T1752 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1150957 T1772 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1d5c690b name:ZooKeeperConnection Watcher:127.0.0.1:18692 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1150957 T1752 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1150966 T1752 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4] 2> 1150978 T1752 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1150980 T1774 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@a6965a0 name:ZooKeeperConnection Watcher:127.0.0.1:18692/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1150980 T1752 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1150982 T1752 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 1150992 T1752 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 1150996 T1752 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 1151002 T1752 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:32597_
[junit4] 2> 1151004 T1752 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:32597_
[junit4] 2> 1151007 T1752 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 1151024 T1752 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 1151026 T1752 oasc.Overseer.start Overseer (id=90102119736606723-127.0.0.1:32597_-n_0000000000) starting
[junit4] 2> 1151037 T1752 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 1151048 T1776 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 1151049 T1752 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 1151052 T1752 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 1151058 T1752 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1151061 T1775 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 1151067 T1777 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 1151067 T1777 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1151069 T1777 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 1152565 T1775 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1152566 T1775 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:32597_",
[junit4] 2> "base_url":"http://127.0.0.1:32597"}
[junit4] 2> 1152566 T1775 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with numShards 1
[junit4] 2> 1152567 T1775 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 1152613 T1774 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> 1153071 T1777 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 1153071 T1777 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374849239440/collection1
[junit4] 2> 1153071 T1777 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4] 2> 1153072 T1777 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 1153072 T1777 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4] 2> 1153073 T1777 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374849239440/collection1/'
[junit4] 2> 1153075 T1777 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374849239440/collection1/lib/README' to classloader
[junit4] 2> 1153075 T1777 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374849239440/collection1/lib/classes/' to classloader
[junit4] 2> 1153133 T1777 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 1153196 T1777 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 1153298 T1777 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 1153310 T1777 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 1153955 T1777 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 1153968 T1777 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 1153972 T1777 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 1153987 T1777 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1153993 T1777 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1153997 T1777 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 1153998 T1777 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 1153999 T1777 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 1154000 T1777 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 1154001 T1777 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 1154001 T1777 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 1154001 T1777 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 1154002 T1777 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374849239440/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZkTest-1374849239138/control/data/
[junit4] 2> 1154002 T1777 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1f2488c7
[junit4] 2> 1154003 T1777 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374849239138/control/data
[junit4] 2> 1154003 T1777 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZkTest-1374849239138/control/data/index/
[junit4] 2> 1154004 T1777 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZkTest-1374849239138/control/data/index' doesn't exist. Creating new index...
[junit4] 2> 1154004 T1777 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374849239138/control/data/index
[junit4] 2> 1154009 T1777 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@49805ff0 lockFactory=org.apache.lucene.store.NativeFSLockFactory@5a60532e),segFN=segments_1,generation=1}
[junit4] 2> 1154009 T1777 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1154014 T1777 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 1154015 T1777 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 1154016 T1777 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1154016 T1777 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 1154017 T1777 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 1154017 T1777 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 1154018 T1777 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 1154018 T1777 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 1154019 T1777 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 1154035 T1777 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 1154043 T1777 oass.SolrIndexSearcher.<init> Opening Searcher@7584a544 main
[junit4] 2> 1154044 T1777 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 1154044 T1777 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 1154048 T1778 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@7584a544 main{StandardDirectoryReader(segments_1:1)}
[junit4] 2> 1154050 T1777 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 1154051 T1777 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:32597 collection:control_collection shard:shard1
[junit4] 2> 1154051 T1777 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=30000&socketTimeout=30000&retry=false
[junit4] 2> 1154068 T1777 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4] 2> 1154094 T1777 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 1154097 T1777 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 1154097 T1777 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 1154097 T1777 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:32597/collection1/
[junit4] 2> 1154098 T1777 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 1154098 T1777 oasc.SyncStrategy.syncToMe http://127.0.0.1:32597/collection1/ has no replicas
[junit4] 2> 1154098 T1777 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:32597/collection1/ shard1
[junit4] 2> 1154099 T1777 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4] 2> 1154155 T1775 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1154178 T1774 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> 1154207 T1777 oasc.ZkController.register We are http://127.0.0.1:32597/collection1/ and leader is http://127.0.0.1:32597/collection1/
[junit4] 2> 1154207 T1777 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:32597
[junit4] 2> 1154207 T1777 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 1154208 T1777 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 1154208 T1777 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1154210 T1777 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1154211 T1752 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0
[junit4] 2> 1154211 T1752 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 1154212 T1752 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 1154222 T1752 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4] 2> 1154223 T1752 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1154226 T1781 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6f003e60 name:ZooKeeperConnection Watcher:127.0.0.1:18692/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1154226 T1752 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1154227 T1752 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1154230 T1752 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4] 2> 1154506 T1752 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 1154509 T1752 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:20355
[junit4] 2> 1154510 T1752 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 1154511 T1752 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1154511 T1752 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374849243155
[junit4] 2> 1154512 T1752 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374849243155/'
[junit4] 2> 1154551 T1752 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374849243155/solr.xml
[junit4] 2> 1154642 T1752 oasc.CoreContainer.<init> New CoreContainer 1296253266
[junit4] 2> 1154643 T1752 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374849243155/]
[junit4] 2> 1154645 T1752 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 1154645 T1752 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 1154646 T1752 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 1154646 T1752 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 1154647 T1752 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 1154647 T1752 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 1154648 T1752 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 1154648 T1752 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 1154649 T1752 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 1154649 T1752 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4] 2> 1154665 T1752 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:18692/solr
[junit4] 2> 1154666 T1752 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 1154667 T1752 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1154670 T1792 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@59e4c5fc name:ZooKeeperConnection Watcher:127.0.0.1:18692 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1154670 T1752 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1154673 T1752 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4] 2> 1154683 T1752 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1154685 T1794 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4e46cf03 name:ZooKeeperConnection Watcher:127.0.0.1:18692/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1154686 T1752 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1154696 T1752 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1155683 T1775 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1155685 T1775 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:32597_",
[junit4] 2> "base_url":"http://127.0.0.1:32597"}
[junit4] 2> 1155700 T1781 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> 1155700 T1752 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:20355_
[junit4] 2> 1155700 T1774 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> 1155700 T1794 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> 1155703 T1752 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:20355_
[junit4] 2> 1155705 T1781 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> 1155705 T1794 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> 1155706 T1774 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1155706 T1774 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> 1155707 T1781 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1155714 T1794 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1155721 T1795 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 1155721 T1795 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1155723 T1795 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 1157206 T1775 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1157207 T1775 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:20355_",
[junit4] 2> "base_url":"http://127.0.0.1:20355"}
[junit4] 2> 1157207 T1775 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with numShards 2
[junit4] 2> 1157208 T1775 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 1157266 T1781 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> 1157266 T1774 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> 1157266 T1794 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> 1157725 T1795 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 1157725 T1795 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374849243155/collection1
[junit4] 2> 1157725 T1795 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 1157726 T1795 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 1157726 T1795 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 1157728 T1795 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374849243155/collection1/'
[junit4] 2> 1157729 T1795 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374849243155/collection1/lib/classes/' to classloader
[junit4] 2> 1157730 T1795 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374849243155/collection1/lib/README' to classloader
[junit4] 2> 1157788 T1795 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 1157851 T1795 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 1157952 T1795 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 1157964 T1795 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 1158607 T1795 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 1158620 T1795 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 1158624 T1795 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 1158640 T1795 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1158645 T1795 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1158649 T1795 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 1158650 T1795 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 1158651 T1795 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 1158651 T1795 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 1158652 T1795 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 1158652 T1795 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 1158653 T1795 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 1158653 T1795 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374849243155/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZkTest-1374849239138/jetty1/
[junit4] 2> 1158654 T1795 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1f2488c7
[junit4] 2> 1158655 T1795 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374849239138/jetty1
[junit4] 2> 1158655 T1795 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZkTest-1374849239138/jetty1/index/
[junit4] 2> 1158655 T1795 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZkTest-1374849239138/jetty1/index' doesn't exist. Creating new index...
[junit4] 2> 1158656 T1795 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374849239138/jetty1/index
[junit4] 2> 1158660 T1795 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@491f47a3 lockFactory=org.apache.lucene.store.NativeFSLockFactory@c6aa05c),segFN=segments_1,generation=1}
[junit4] 2> 1158660 T1795 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1158666 T1795 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 1158666 T1795 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 1158667 T1795 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1158668 T1795 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 1158669 T1795 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 1158669 T1795 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 1158669 T1795 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 1158670 T1795 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 1158671 T1795 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 1158687 T1795 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 1158695 T1795 oass.SolrIndexSearcher.<init> Opening Searcher@42fe398d main
[junit4] 2> 1158696 T1795 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 1158696 T1795 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 1158701 T1796 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@42fe398d main{StandardDirectoryReader(segments_1:1)}
[junit4] 2> 1158704 T1795 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 1158704 T1795 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:20355 collection:collection1 shard:shard1
[junit4] 2> 1158705 T1795 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=30000&socketTimeout=30000&retry=false
[junit4] 2> 1158722 T1795 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1158759 T1795 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 1158773 T1795 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 1158774 T1795 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 1158774 T1795 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:20355/collection1/
[junit4] 2> 1158774 T1795 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 1158774 T1795 oasc.SyncStrategy.syncToMe http://127.0.0.1:20355/collection1/ has no replicas
[junit4] 2> 1158775 T1795 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:20355/collection1/ shard1
[junit4] 2> 1158775 T1795 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1158815 T1775 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1158830 T1781 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> 1158830 T1774 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> 1158830 T1794 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> 1158840 T1795 oasc.ZkController.register We are http://127.0.0.1:20355/collection1/ and leader is http://127.0.0.1:20355/collection1/
[junit4] 2> 1158840 T1795 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:20355
[junit4] 2> 1158840 T1795 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 1158840 T1795 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 1158841 T1795 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1158843 T1795 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1158844 T1752 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0
[junit4] 2> 1158845 T1752 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 1158846 T1752 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 1159137 T1752 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 1159141 T1752 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:47940
[junit4] 2> 1159141 T1752 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 1159142 T1752 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1159142 T1752 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374849247782
[junit4] 2> 1159143 T1752 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374849247782/'
[junit4] 2> 1159182 T1752 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374849247782/solr.xml
[junit4] 2> 1159274 T1752 oasc.CoreContainer.<init> New CoreContainer 826347938
[junit4] 2> 1159275 T1752 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374849247782/]
[junit4] 2> 1159277 T1752 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 1159277 T1752 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 1159277 T1752 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 1159278 T1752 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 1159278 T1752 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 1159279 T1752 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 1159279 T1752 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 1159280 T1752 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 1159280 T1752 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 1159281 T1752 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4] 2> 1159298 T1752 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:18692/solr
[junit4] 2> 1159299 T1752 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 1159300 T1752 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1159303 T1808 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@78064515 name:ZooKeeperConnection Watcher:127.0.0.1:18692 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1159303 T1752 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1159318 T1752 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4] 2> 1159330 T1752 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1159332 T1810 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@42a6b8a4 name:ZooKeeperConnection Watcher:127.0.0.1:18692/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1159332 T1752 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1159344 T1752 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1160336 T1775 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1160338 T1775 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:20355_",
[junit4] 2> "base_url":"http://127.0.0.1:20355"}
[junit4] 2> 1160356 T1781 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> 1160357 T1752 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:47940_
[junit4] 2> 1160357 T1810 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> 1160357 T1794 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> 1160357 T1774 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> 1160365 T1752 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:47940_
[junit4] 2> 1160368 T1781 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> 1160368 T1794 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> 1160368 T1774 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 1160368 T1810 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 1160368 T1774 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> 1160369 T1810 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> 1160369 T1781 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 1160370 T1794 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 1160378 T1811 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 1160378 T1811 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1160380 T1811 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 1161867 T1775 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1161869 T1775 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:47940_",
[junit4] 2> "base_url":"http://127.0.0.1:47940"}
[junit4] 2> 1161869 T1775 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4] 2> 1161869 T1775 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 1161883 T1781 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> 1161883 T1774 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> 1161883 T1794 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> 1161883 T1810 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> 1162382 T1811 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 1162382 T1811 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374849247782/collection1
[junit4] 2> 1162382 T1811 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 1162383 T1811 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 1162384 T1811 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 1162385 T1811 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374849247782/collection1/'
[junit4] 2> 1162386 T1811 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374849247782/collection1/lib/classes/' to classloader
[junit4] 2> 1162387 T1811 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374849247782/collection1/lib/README' to classloader
[junit4] 2> 1162445 T1811 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 1162508 T1811 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 1162609 T1811 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 1162621 T1811 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 1163264 T1811 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 1163277 T1811 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 1163281 T1811 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 1163296 T1811 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1163301 T1811 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1163306 T1811 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 1163307 T1811 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 1163307 T1811 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 1163307 T1811 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 1163308 T1811 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 1163309 T1811 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 1163309 T1811 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 1163309 T1811 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374849247782/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZkTest-1374849239138/jetty2/
[junit4] 2> 1163310 T1811 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1f2488c7
[junit4] 2> 1163311 T1811 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374849239138/jetty2
[junit4] 2> 1163311 T1811 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZkTest-1374849239138/jetty2/index/
[junit4] 2> 1163312 T1811 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZkTest-1374849239138/jetty2/index' doesn't exist. Creating new index...
[junit4] 2> 1163312 T1811 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374849239138/jetty2/index
[junit4] 2> 1163316 T1811 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@79e72964 lockFactory=org.apache.lucene.store.NativeFSLockFactory@175991ea),segFN=segments_1,generation=1}
[junit4] 2> 1163316 T1811 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1163322 T1811 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 1163323 T1811 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 1163324 T1811 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1163324 T1811 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 1163325 T1811 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 1163325 T1811 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 1163326 T1811 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 1163327 T1811 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 1163327 T1811 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 1163344 T1811 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 1163351 T1811 oass.SolrIndexSearcher.<init> Opening Searcher@8450dae main
[junit4] 2> 1163353 T1811 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 1163353 T1811 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 1163359 T1812 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@8450dae main{StandardDirectoryReader(segments_1:1)}
[junit4] 2> 1163361 T1811 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 1163361 T1811 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:47940 collection:collection1 shard:shard2
[junit4] 2> 1163362 T1811 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=30000&socketTimeout=30000&retry=false
[junit4] 2> 1163379 T1811 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4] 2> 1163402 T1811 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
[junit4] 2> 1163413 T1811 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 1163414 T1811 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 1163414 T1811 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:47940/collection1/
[junit4] 2> 1163414 T1811 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 1163415 T1811 oasc.SyncStrategy.syncToMe http://127.0.0.1:47940/collection1/ has no replicas
[junit4] 2> 1163415 T1811 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:47940/collection1/ shard2
[junit4] 2> 1163415 T1811 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4] 2> 1164904 T1775 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1164927 T1781 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> 1164927 T1774 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> 1164927 T1794 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> 1164927 T1810 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> 1164963 T1811 oasc.ZkController.register We are http://127.0.0.1:47940/collection1/ and leader is http://127.0.0.1:47940/collection1/
[junit4] 2> 1164963 T1811 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:47940
[junit4] 2> 1164963 T1811 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 1164963 T1811 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 1164964 T1811 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1164966 T1811 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1164967 T1752 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0
[junit4] 2> 1164968 T1752 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 1164968 T1752 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 1165253 T1752 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 1165257 T1752 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:38770
[junit4] 2> 1165258 T1752 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 1165258 T1752 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1165259 T1752 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374849253903
[junit4] 2> 1165259 T1752 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374849253903/'
[junit4] 2> 1165298 T1752 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374849253903/solr.xml
[junit4] 2> 1165389 T1752 oasc.CoreContainer.<init> New CoreContainer 1003438304
[junit4] 2> 1165390 T1752 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374849253903/]
[junit4] 2> 1165392 T1752 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 1165392 T1752 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 1165393 T1752 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 1165393 T1752 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 1165394 T1752 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 1165394 T1752 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 1165395 T1752 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 1165395 T1752 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 1165396 T1752 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 1165396 T1752 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4] 2> 1165412 T1752 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:18692/solr
[junit4] 2> 1165412 T1752 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 1165414 T1752 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1165417 T1824 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7f95c19a name:ZooKeeperConnection Watcher:127.0.0.1:18692 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1165417 T1752 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1165432 T1752 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4] 2> 1165443 T1752 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1165445 T1826 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@50797dd7 name:ZooKeeperConnection Watcher:127.0.0.1:18692/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1165446 T1752 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1165467 T1752 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1166433 T1775 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1166435 T1775 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:47940_",
[junit4] 2> "base_url":"http://127.0.0.1:47940"}
[junit4] 2> 1166451 T1826 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> 1166451 T1794 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> 1166451 T1810 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> 1166451 T1781 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> 1166451 T1774 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> 1166470 T1752 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:38770_
[junit4] 2> 1166472 T1752 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:38770_
[junit4] 2> 1166475 T1781 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> 1166475 T1794 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> 1166475 T1826 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 1166475 T1810 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 1166475 T1774 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 1166476 T1810 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> 1166475 T1826 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> 1166476 T1781 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 1166477 T1794 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 1166476 T1774 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> 1166491 T1827 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 1166491 T1827 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1166493 T1827 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 1167957 T1775 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1167958 T1775 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:38770_",
[junit4] 2> "base_url":"http://127.0.0.1:38770"}
[junit4] 2> 1167958 T1775 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4] 2> 1167959 T1775 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 1167984 T1826 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> 1167984 T1794 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> 1167984 T1810 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> 1167984 T1774 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> 1167984 T1781 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> 1168495 T1827 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 1168495 T1827 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374849253903/collection1
[junit4] 2> 1168495 T1827 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 1168496 T1827 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 1168497 T1827 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 1168498 T1827 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374849253903/collection1/'
[junit4] 2> 1168499 T1827 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374849253903/collection1/lib/README' to classloader
[junit4] 2> 1168500 T1827 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374849253903/collection1/lib/classes/' to classloader
[junit4] 2> 1168558 T1827 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 1168620 T1827 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 1168722 T1827 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 1168734 T1827 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 1169377 T1827 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 1169390 T1827 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 1169394 T1827 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 1169409 T1827 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1169414 T1827 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1169419 T1827 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 1169420 T1827 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 1169420 T1827 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 1169421 T1827 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 1169422 T1827 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 1169422 T1827 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 1169422 T1827 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 1169423 T1827 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374849253903/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZkTest-1374849239138/jetty3/
[junit4] 2> 1169423 T1827 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1f2488c7
[junit4] 2> 1169424 T1827 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374849239138/jetty3
[junit4] 2> 1169425 T1827 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZkTest-1374849239138/jetty3/index/
[junit4] 2> 1169425 T1827 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZkTest-1374849239138/jetty3/index' doesn't exist. Creating new index...
[junit4] 2> 1169425 T1827 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374849239138/jetty3/index
[junit4] 2> 1169429 T1827 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1520e2a1 lockFactory=org.apache.lucene.store.NativeFSLockFactory@723241fd),segFN=segments_1,generation=1}
[junit4] 2> 1169430 T1827 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1169435 T1827 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 1169436 T1827 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 1169437 T1827 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1169437 T1827 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 1169438 T1827 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 1169438 T1827 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 1169439 T1827 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 1169440 T1827 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 1169440 T1827 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 1169457 T1827 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 1169464 T1827 oass.SolrIndexSearcher.<init> Opening Searcher@e21d094 main
[junit4] 2> 1169465 T1827 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 1169466 T1827 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 1169471 T1828 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@e21d094 main{StandardDirectoryReader(segments_1:1)}
[junit4] 2> 1169474 T1827 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 1169474 T1827 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:38770 collection:collection1 shard:shard1
[junit4] 2> 1169475 T1827 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=30000&socketTimeout=30000&retry=false
[junit4] 2> 1169495 T1827 oasc.ZkController.register We are http://127.0.0.1:38770/collection1/ and leader is http://127.0.0.1:20355/collection1/
[junit4] 2> 1169495 T1827 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:38770
[junit4] 2> 1169495 T1827 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4] 2> 1169496 T1827 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4] 2> ASYNC NEW_CORE C390 name=collection1 org.apache.solr.core.SolrCore@3d4306 url=http://127.0.0.1:38770/collection1 node=127.0.0.1:38770_ C390_STATE=coll:collection1 core:collection1 props:{state=down, core=collection1, node_name=127.0.0.1:38770_, base_url=http://127.0.0.1:38770}
[junit4] 2> 1169496 T1829 C390 P38770 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4] 2> 1169496 T1827 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1169497 T1829 C390 P38770 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4] 2> 1169497 T1829 C390 P38770 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4] 2> 1169498 T1829 C390 P38770 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1169498 T1752 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0
[junit4] 2> 1169499 T1752 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 1169499 T1829 C390 P38770 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 1169499 T1752 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 1169513 T1784 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: core_node3, state: recovering, checkLive: true, onlyIfLeader: true
[junit4] 2> 1169791 T1752 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 1169795 T1752 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:36526
[junit4] 2> 1169795 T1752 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 1169796 T1752 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1169796 T1752 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty4-1374849258437
[junit4] 2> 1169797 T1752 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty4-1374849258437/'
[junit4] 2> 1169836 T1752 oasc.ConfigSolr.
[...truncated too long message...]
ing), range_facet_si=PostingsFormat(name=Direct), oddField_s=PostingsFormat(name=NestedPulsing), sequence_i=PostingsFormat(name=NestedPulsing), name=PostingsFormat(name=Asserting), foo_i=PostingsFormat(name=Direct), regex_dup_B_s=Pulsing41(freqCutoff=8 minBlockSize=27 maxBlockSize=105), multiDefault=PostingsFormat(name=Direct), n_tf1=Pulsing41(freqCutoff=8 minBlockSize=27 maxBlockSize=105), n_dt1=PostingsFormat(name=Direct), genre_s=PostingsFormat(name=NestedPulsing), author_t=PostingsFormat(name=Direct), range_facet_l=Pulsing41(freqCutoff=8 minBlockSize=27 maxBlockSize=105), n_ti1=PostingsFormat(name=Asserting), text=PostingsFormat(name=NestedPulsing), _version_=Pulsing41(freqCutoff=8 minBlockSize=27 maxBlockSize=105), val_i=PostingsFormat(name=Asserting), SubjectTerms_mfacet=Pulsing41(freqCutoff=8 minBlockSize=27 maxBlockSize=105), series_t=PostingsFormat(name=Direct), a_t=Pulsing41(freqCutoff=8 minBlockSize=27 maxBlockSize=105), n_tdt1=Pulsing41(freqCutoff=8 minBlockSize=27 maxBlockSize=105), regex_dup_A_s=PostingsFormat(name=NestedPulsing), price=PostingsFormat(name=NestedPulsing), other_tl1=Pulsing41(freqCutoff=8 minBlockSize=27 maxBlockSize=105), n_l1=Pulsing41(freqCutoff=8 minBlockSize=27 maxBlockSize=105), a_si=PostingsFormat(name=Direct), inStock=PostingsFormat(name=NestedPulsing)}, docValues:{timestamp=DocValuesFormat(name=Lucene42)}, sim=DefaultSimilarity, locale=ro, timezone=America/Guyana
[junit4] 2> NOTE: FreeBSD 9.1-RELEASE-p3 amd64/Oracle Corporation 1.7.0_25 (64-bit)/cpus=16,threads=2,free=337674488,total=500170752
[junit4] 2> NOTE: All tests run in this JVM: [SOLR749Test, TestSchemaVersionResource, MinimalSchemaTest, BinaryUpdateRequestHandlerTest, ZkCLITest, ResponseLogComponentTest, TestCopyFieldCollectionResource, TestValueSourceCache, TestSolrDeletionPolicy1, MoreLikeThisHandlerTest, UUIDFieldTest, ShowFileRequestHandlerTest, TestMaxScoreQueryParser, ExternalFileFieldSortTest, StressHdfsTest, TestFastWriter, TestXIncludeConfig, ClusterStateUpdateTest, RecoveryZkTest, OverseerCollectionProcessorTest, TermVectorComponentTest, WordBreakSolrSpellCheckerTest, ShardRoutingTest, StatelessScriptUpdateProcessorFactoryTest, TestFieldResource, TestFuzzyAnalyzedSuggestions, DirectSolrConnectionTest, ZkControllerTest, TestLMDirichletSimilarityFactory, TestQuerySenderListener, TestSolrDeletionPolicy2, AutoCommitTest, SyncSliceTest, SystemInfoHandlerTest, SchemaVersionSpecificBehaviorTest, TestGroupingSearch, FileBasedSpellCheckerTest, TestPerFieldSimilarity, TestTrie, DirectUpdateHandlerOptimizeTest, TestQueryUtils, TestRealTimeGet, TestShardHandlerFactory, TestStressVersions, SoftAutoCommitTest, TestBadConfig, TestSolrXml, SolrTestCaseJ4Test, QueryEqualityTest, TermsComponentTest, SpellingQueryConverterTest, TestSolrIndexConfig, TestConfig, RegexBoostProcessorTest, FastVectorHighlighterTest, BlockDirectoryTest, TestSolrQueryParserDefaultOperatorResource, AnalysisAfterCoreReloadTest, DocumentBuilderTest, CachingDirectoryFactoryTest, LukeRequestHandlerTest, PolyFieldTest, AddSchemaFieldsUpdateProcessorFactoryTest, TestCoreContainer, TestSort, PrimUtilsTest, TestCharFilters, TestDynamicFieldResource, TestDocumentBuilder, LegacyHTMLStripCharFilterTest, PreAnalyzedFieldTest, SynonymTokenizerTest, AliasIntegrationTest, SimpleFacetsTest, ResourceLoaderTest, TestPropInjectDefaults, BasicDistributedZkTest]
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=BasicDistributedZkTest -Dtests.seed=38900BE09D7724C5 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=ro -Dtests.timezone=America/Guyana -Dtests.file.encoding=ISO-8859-1
[junit4] ERROR 0.00s J0 | BasicDistributedZkTest (suite) <<<
[junit4] > Throwable #1: com.carrotsearch.randomizedtesting.ThreadLeakError: 1 thread leaked from SUITE scope at org.apache.solr.cloud.BasicDistributedZkTest:
[junit4] > 1) Thread[id=2237, name=recoveryCmdExecutor-980-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:392)
[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:724)
[junit4] > at __randomizedtesting.SeedInfo.seed([38900BE09D7724C5]:0)Throwable #2: com.carrotsearch.randomizedtesting.ThreadLeakError: There are still zombie threads that couldn't be terminated:
[junit4] > 1) Thread[id=2237, name=recoveryCmdExecutor-980-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:392)
[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:724)
[junit4] > at __randomizedtesting.SeedInfo.seed([38900BE09D7724C5]:0)
[junit4] Completed on J0 in 414.05s, 1 test, 2 errors <<< FAILURES!
[...truncated 479 lines...]
BUILD FAILED
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/build.xml:389: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/build.xml:369: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/build.xml:39: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build.xml:181: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/common-build.xml:449: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/lucene/common-build.xml:1230: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/lucene/common-build.xml:873: There were test failures: 318 suites, 1342 tests, 2 suite-level errors, 670 ignored (4 assumptions)
Total time: 49 minutes 26 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure
[JENKINS] Lucene-Solr-Tests-trunk-Java7 - Build # 4179 - Still
Failing
Posted by Apache Jenkins Server <je...@builds.apache.org>.
Build: https://builds.apache.org/job/Lucene-Solr-Tests-trunk-Java7/4179/
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=2284, name=recoveryCmdExecutor-1099-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:392) 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:724)
Stack Trace:
com.carrotsearch.randomizedtesting.ThreadLeakError: 1 thread leaked from SUITE scope at org.apache.solr.cloud.BasicDistributedZkTest:
1) Thread[id=2284, name=recoveryCmdExecutor-1099-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:392)
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:724)
at __randomizedtesting.SeedInfo.seed([FCEE89A443F8D944]: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=2284, name=recoveryCmdExecutor-1099-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:392) 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:724)
Stack Trace:
com.carrotsearch.randomizedtesting.ThreadLeakError: There are still zombie threads that couldn't be terminated:
1) Thread[id=2284, name=recoveryCmdExecutor-1099-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:392)
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:724)
at __randomizedtesting.SeedInfo.seed([FCEE89A443F8D944]:0)
Build Log:
[...truncated 9749 lines...]
[junit4] Suite: org.apache.solr.cloud.BasicDistributedZkTest
[junit4] 2> 833784 T1781 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
[junit4] 2> 833789 T1781 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4] 2> Creating dataDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./solrtest-BasicDistributedZkTest-1374865464363
[junit4] 2> 833791 T1781 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 833791 T1782 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 833892 T1781 oasc.ZkTestServer.run start zk server on port:44348
[junit4] 2> 833893 T1781 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 833898 T1788 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@69ba276 name:ZooKeeperConnection Watcher:127.0.0.1:44348 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 833898 T1781 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 833899 T1781 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 833917 T1781 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 833919 T1790 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5b62d9ea name:ZooKeeperConnection Watcher:127.0.0.1:44348/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 833919 T1781 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 833920 T1781 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4] 2> 833930 T1781 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4] 2> 833933 T1781 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4] 2> 833935 T1781 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4] 2> 833944 T1781 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4] 2> 833945 T1781 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4] 2> 833957 T1781 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
[junit4] 2> 833958 T1781 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4] 2> 834062 T1781 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4] 2> 834062 T1781 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4] 2> 834065 T1781 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4] 2> 834066 T1781 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4] 2> 834080 T1781 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4] 2> 834081 T1781 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4] 2> 834084 T1781 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4] 2> 834084 T1781 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4] 2> 834087 T1781 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 834088 T1781 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 834090 T1781 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4] 2> 834091 T1781 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4] 2> 834094 T1781 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4] 2> 834094 T1781 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4] 2> 834300 T1781 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 834304 T1781 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:44352
[junit4] 2> 834305 T1781 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 834305 T1781 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 834306 T1781 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374865464676
[junit4] 2> 834306 T1781 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374865464676/'
[junit4] 2> 834338 T1781 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374865464676/solr.xml
[junit4] 2> 834405 T1781 oasc.CoreContainer.<init> New CoreContainer 675968073
[junit4] 2> 834406 T1781 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374865464676/]
[junit4] 2> 834407 T1781 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 834407 T1781 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 834408 T1781 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 834408 T1781 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 834408 T1781 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 834409 T1781 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 834409 T1781 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 834409 T1781 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 834410 T1781 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 834410 T1781 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4] 2> 834422 T1781 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:44348/solr
[junit4] 2> 834422 T1781 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 834423 T1781 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 834425 T1801 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4bde45f2 name:ZooKeeperConnection Watcher:127.0.0.1:44348 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 834426 T1781 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 834437 T1781 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4] 2> 834444 T1781 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 834447 T1803 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5ee4ae27 name:ZooKeeperConnection Watcher:127.0.0.1:44348/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 834447 T1781 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 834454 T1781 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 834459 T1781 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 834468 T1781 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 834471 T1781 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:44352_
[junit4] 2> 834472 T1781 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:44352_
[junit4] 2> 834483 T1781 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 834496 T1781 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 834500 T1781 oasc.Overseer.start Overseer (id=90103183072886787-127.0.0.1:44352_-n_0000000000) starting
[junit4] 2> 834510 T1781 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 834530 T1805 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 834530 T1781 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 834533 T1781 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 834535 T1781 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 834538 T1804 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 834542 T1806 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 834543 T1806 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 834544 T1806 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 836041 T1804 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 836042 T1804 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:44352_",
[junit4] 2> "base_url":"http://127.0.0.1:44352"}
[junit4] 2> 836043 T1804 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with numShards 1
[junit4] 2> 836043 T1804 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 836054 T1803 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> 836546 T1806 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 836546 T1806 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374865464676/collection1
[junit4] 2> 836546 T1806 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4] 2> 836547 T1806 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 836548 T1806 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4] 2> 836549 T1806 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374865464676/collection1/'
[junit4] 2> 836550 T1806 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374865464676/collection1/lib/README' to classloader
[junit4] 2> 836551 T1806 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374865464676/collection1/lib/classes/' to classloader
[junit4] 2> 836606 T1806 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 836666 T1806 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 836768 T1806 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 836780 T1806 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 837513 T1806 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 837528 T1806 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 837532 T1806 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 837549 T1806 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 837555 T1806 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 837562 T1806 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 837564 T1806 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 837564 T1806 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 837565 T1806 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 837566 T1806 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 837566 T1806 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 837566 T1806 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 837567 T1806 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374865464676/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZkTest-1374865464363/control/data/
[junit4] 2> 837567 T1806 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@24aad6d7
[junit4] 2> 837568 T1806 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374865464363/control/data
[junit4] 2> 837568 T1806 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZkTest-1374865464363/control/data/index/
[junit4] 2> 837569 T1806 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZkTest-1374865464363/control/data/index' doesn't exist. Creating new index...
[junit4] 2> 837569 T1806 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374865464363/control/data/index
[junit4] 2> 837575 T1806 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@248712c0 lockFactory=org.apache.lucene.store.NativeFSLockFactory@39f19d40),segFN=segments_1,generation=1}
[junit4] 2> 837575 T1806 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 837580 T1806 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 837580 T1806 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 837581 T1806 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 837582 T1806 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 837583 T1806 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 837583 T1806 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 837583 T1806 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 837584 T1806 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 837584 T1806 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 837604 T1806 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 837615 T1806 oass.SolrIndexSearcher.<init> Opening Searcher@699bf2f1 main
[junit4] 2> 837616 T1806 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 837617 T1806 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 837621 T1807 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@699bf2f1 main{StandardDirectoryReader(segments_1:1)}
[junit4] 2> 837623 T1806 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 837623 T1806 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:44352 collection:control_collection shard:shard1
[junit4] 2> 837623 T1806 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=30000&socketTimeout=30000&retry=false
[junit4] 2> 837644 T1806 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4] 2> 837663 T1806 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 837666 T1806 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 837666 T1806 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 837667 T1806 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:44352/collection1/
[junit4] 2> 837667 T1806 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 837667 T1806 oasc.SyncStrategy.syncToMe http://127.0.0.1:44352/collection1/ has no replicas
[junit4] 2> 837667 T1806 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:44352/collection1/ shard1
[junit4] 2> 837668 T1806 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4] 2> 839060 T1804 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 839092 T1803 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> 839103 T1806 oasc.ZkController.register We are http://127.0.0.1:44352/collection1/ and leader is http://127.0.0.1:44352/collection1/
[junit4] 2> 839103 T1806 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:44352
[junit4] 2> 839103 T1806 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 839104 T1806 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 839104 T1806 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 839106 T1806 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 839107 T1781 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0
[junit4] 2> 839108 T1781 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 839108 T1781 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 839121 T1781 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4] 2> 839122 T1781 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 839125 T1810 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3146d556 name:ZooKeeperConnection Watcher:127.0.0.1:44348/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 839125 T1781 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 839126 T1781 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 839129 T1781 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4] 2> 839414 T1781 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 839418 T1781 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:44359
[junit4] 2> 839419 T1781 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 839419 T1781 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 839420 T1781 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374865469702
[junit4] 2> 839420 T1781 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374865469702/'
[junit4] 2> 839460 T1781 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374865469702/solr.xml
[junit4] 2> 839551 T1781 oasc.CoreContainer.<init> New CoreContainer 1651830574
[junit4] 2> 839552 T1781 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374865469702/]
[junit4] 2> 839554 T1781 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 839555 T1781 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 839555 T1781 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 839556 T1781 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 839556 T1781 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 839557 T1781 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 839557 T1781 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 839558 T1781 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 839558 T1781 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 839559 T1781 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4] 2> 839576 T1781 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:44348/solr
[junit4] 2> 839576 T1781 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 839577 T1781 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 839580 T1821 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@a18a183 name:ZooKeeperConnection Watcher:127.0.0.1:44348 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 839580 T1781 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 839583 T1781 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4] 2> 839594 T1781 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 839596 T1823 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@524a7674 name:ZooKeeperConnection Watcher:127.0.0.1:44348/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 839597 T1781 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 839606 T1781 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 840600 T1804 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 840601 T1804 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:44352_",
[junit4] 2> "base_url":"http://127.0.0.1:44352"}
[junit4] 2> 840613 T1803 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> 840613 T1781 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:44359_
[junit4] 2> 840613 T1823 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> 840613 T1810 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> 840616 T1781 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:44359_
[junit4] 2> 840626 T1810 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> 840627 T1803 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 840627 T1823 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 840627 T1803 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> 840627 T1823 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> 840628 T1810 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 840636 T1824 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 840637 T1824 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 840638 T1824 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 842118 T1804 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 842120 T1804 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:44359_",
[junit4] 2> "base_url":"http://127.0.0.1:44359"}
[junit4] 2> 842120 T1804 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with numShards 2
[junit4] 2> 842120 T1804 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 842132 T1803 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> 842132 T1810 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> 842132 T1823 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> 842640 T1824 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 842640 T1824 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374865469702/collection1
[junit4] 2> 842640 T1824 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 842641 T1824 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 842642 T1824 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 842643 T1824 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374865469702/collection1/'
[junit4] 2> 842644 T1824 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374865469702/collection1/lib/classes/' to classloader
[junit4] 2> 842645 T1824 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374865469702/collection1/lib/README' to classloader
[junit4] 2> 842704 T1824 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 842767 T1824 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 842868 T1824 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 842880 T1824 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 843511 T1824 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 843519 T1824 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 843522 T1824 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 843535 T1824 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 843539 T1824 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 843542 T1824 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 843543 T1824 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 843543 T1824 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 843543 T1824 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 843544 T1824 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 843544 T1824 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 843545 T1824 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 843545 T1824 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374865469702/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZkTest-1374865464363/jetty1/
[junit4] 2> 843545 T1824 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@24aad6d7
[junit4] 2> 843546 T1824 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374865464363/jetty1
[junit4] 2> 843546 T1824 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZkTest-1374865464363/jetty1/index/
[junit4] 2> 843546 T1824 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZkTest-1374865464363/jetty1/index' doesn't exist. Creating new index...
[junit4] 2> 843547 T1824 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374865464363/jetty1/index
[junit4] 2> 843549 T1824 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@2425d5c6 lockFactory=org.apache.lucene.store.NativeFSLockFactory@3b8d7c12),segFN=segments_1,generation=1}
[junit4] 2> 843550 T1824 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 843554 T1824 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 843554 T1824 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 843555 T1824 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 843555 T1824 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 843556 T1824 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 843556 T1824 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 843556 T1824 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 843557 T1824 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 843557 T1824 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 843568 T1824 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 843573 T1824 oass.SolrIndexSearcher.<init> Opening Searcher@6c9e2702 main
[junit4] 2> 843574 T1824 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 843574 T1824 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 843578 T1825 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@6c9e2702 main{StandardDirectoryReader(segments_1:1)}
[junit4] 2> 843580 T1824 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 843580 T1824 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:44359 collection:collection1 shard:shard1
[junit4] 2> 843580 T1824 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=30000&socketTimeout=30000&retry=false
[junit4] 2> 843592 T1824 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 843608 T1824 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 843620 T1824 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 843620 T1824 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 843620 T1824 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:44359/collection1/
[junit4] 2> 843620 T1824 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 843621 T1824 oasc.SyncStrategy.syncToMe http://127.0.0.1:44359/collection1/ has no replicas
[junit4] 2> 843621 T1824 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:44359/collection1/ shard1
[junit4] 2> 843621 T1824 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 843637 T1804 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 843658 T1803 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> 843659 T1810 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> 843658 T1823 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> 843684 T1824 oasc.ZkController.register We are http://127.0.0.1:44359/collection1/ and leader is http://127.0.0.1:44359/collection1/
[junit4] 2> 843684 T1824 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:44359
[junit4] 2> 843684 T1824 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 843684 T1824 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 843685 T1824 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 843686 T1824 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 843687 T1781 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0
[junit4] 2> 843688 T1781 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 843688 T1781 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 843879 T1781 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 843883 T1781 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:44362
[junit4] 2> 843884 T1781 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 843884 T1781 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 843884 T1781 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374865474269
[junit4] 2> 843885 T1781 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374865474269/'
[junit4] 2> 843912 T1781 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374865474269/solr.xml
[junit4] 2> 843972 T1781 oasc.CoreContainer.<init> New CoreContainer 1760207827
[junit4] 2> 843973 T1781 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374865474269/]
[junit4] 2> 843974 T1781 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 843975 T1781 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 843975 T1781 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 843975 T1781 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 843976 T1781 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 843976 T1781 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 843976 T1781 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 843977 T1781 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 843977 T1781 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 843977 T1781 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4] 2> 843989 T1781 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:44348/solr
[junit4] 2> 843990 T1781 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 843990 T1781 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 843993 T1837 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@201229dd name:ZooKeeperConnection Watcher:127.0.0.1:44348 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 843994 T1781 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 844007 T1781 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4] 2> 844020 T1781 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 844022 T1839 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@18ac06be name:ZooKeeperConnection Watcher:127.0.0.1:44348/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 844022 T1781 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 844027 T1781 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 845030 T1781 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:44362_
[junit4] 2> 845032 T1781 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:44362_
[junit4] 2> 845035 T1810 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> 845035 T1823 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 845035 T1839 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 845035 T1803 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 845036 T1823 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> 845036 T1803 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> 845037 T1810 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 845056 T1840 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 845056 T1840 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 845058 T1840 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 845164 T1804 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 845165 T1804 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:44359_",
[junit4] 2> "base_url":"http://127.0.0.1:44359"}
[junit4] 2> 845170 T1804 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:44362_",
[junit4] 2> "base_url":"http://127.0.0.1:44362"}
[junit4] 2> 845170 T1804 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4] 2> 845171 T1804 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 845181 T1803 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> 845181 T1823 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> 845181 T1810 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> 845181 T1839 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> 846059 T1840 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 846059 T1840 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374865474269/collection1
[junit4] 2> 846059 T1840 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 846060 T1840 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 846060 T1840 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 846061 T1840 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374865474269/collection1/'
[junit4] 2> 846063 T1840 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374865474269/collection1/lib/README' to classloader
[junit4] 2> 846064 T1840 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374865474269/collection1/lib/classes/' to classloader
[junit4] 2> 846142 T1840 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 846205 T1840 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 846306 T1840 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 846319 T1840 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 846974 T1840 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 846988 T1840 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 846992 T1840 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 847007 T1840 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 847012 T1840 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 847017 T1840 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 847018 T1840 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 847018 T1840 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 847018 T1840 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 847019 T1840 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 847020 T1840 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 847020 T1840 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 847020 T1840 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374865474269/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZkTest-1374865464363/jetty2/
[junit4] 2> 847021 T1840 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@24aad6d7
[junit4] 2> 847022 T1840 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374865464363/jetty2
[junit4] 2> 847022 T1840 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZkTest-1374865464363/jetty2/index/
[junit4] 2> 847023 T1840 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZkTest-1374865464363/jetty2/index' doesn't exist. Creating new index...
[junit4] 2> 847023 T1840 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374865464363/jetty2/index
[junit4] 2> 847027 T1840 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@5e0f345c lockFactory=org.apache.lucene.store.NativeFSLockFactory@26e79202),segFN=segments_1,generation=1}
[junit4] 2> 847027 T1840 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 847033 T1840 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 847034 T1840 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 847034 T1840 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 847035 T1840 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 847036 T1840 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 847036 T1840 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 847037 T1840 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 847038 T1840 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 847038 T1840 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 847055 T1840 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 847062 T1840 oass.SolrIndexSearcher.<init> Opening Searcher@243cec36 main
[junit4] 2> 847064 T1840 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 847064 T1840 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 847070 T1841 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@243cec36 main{StandardDirectoryReader(segments_1:1)}
[junit4] 2> 847072 T1840 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 847073 T1840 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:44362 collection:collection1 shard:shard2
[junit4] 2> 847073 T1840 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=30000&socketTimeout=30000&retry=false
[junit4] 2> 847089 T1840 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4] 2> 847109 T1840 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
[junit4] 2> 847120 T1840 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 847120 T1840 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 847120 T1840 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:44362/collection1/
[junit4] 2> 847120 T1840 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 847121 T1840 oasc.SyncStrategy.syncToMe http://127.0.0.1:44362/collection1/ has no replicas
[junit4] 2> 847121 T1840 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:44362/collection1/ shard2
[junit4] 2> 847121 T1840 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4] 2> 848197 T1804 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 848215 T1839 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> 848215 T1810 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> 848215 T1823 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> 848215 T1803 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> 848258 T1840 oasc.ZkController.register We are http://127.0.0.1:44362/collection1/ and leader is http://127.0.0.1:44362/collection1/
[junit4] 2> 848258 T1840 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:44362
[junit4] 2> 848258 T1840 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 848258 T1840 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 848259 T1840 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 848260 T1840 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 848262 T1781 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0
[junit4] 2> 848262 T1781 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 848263 T1781 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 848561 T1781 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 848565 T1781 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:42212
[junit4] 2> 848566 T1781 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 848566 T1781 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 848567 T1781 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374865478847
[junit4] 2> 848567 T1781 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374865478847/'
[junit4] 2> 848607 T1781 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374865478847/solr.xml
[junit4] 2> 848700 T1781 oasc.CoreContainer.<init> New CoreContainer 643247418
[junit4] 2> 848701 T1781 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374865478847/]
[junit4] 2> 848703 T1781 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 848703 T1781 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 848704 T1781 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 848704 T1781 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 848705 T1781 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 848705 T1781 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 848706 T1781 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 848706 T1781 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 848707 T1781 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 848707 T1781 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4] 2> 848724 T1781 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:44348/solr
[junit4] 2> 848724 T1781 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 848725 T1781 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 848728 T1853 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@43b6b47e name:ZooKeeperConnection Watcher:127.0.0.1:44348 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 848729 T1781 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 848731 T1781 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4] 2> 848742 T1781 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 848744 T1855 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2ac8e211 name:ZooKeeperConnection Watcher:127.0.0.1:44348/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 848745 T1781 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 848756 T1781 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 849728 T1804 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 849730 T1804 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:44362_",
[junit4] 2> "base_url":"http://127.0.0.1:44362"}
[junit4] 2> 849743 T1839 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> 849743 T1810 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> 849743 T1823 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> 849743 T1803 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> 849743 T1855 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> 849760 T1781 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:42212_
[junit4] 2> 849796 T1781 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:42212_
[junit4] 2> 849836 T1810 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> 849836 T1855 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> 849836 T1803 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 849837 T1823 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 849837 T1839 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 849837 T1803 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> 849837 T1839 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> 849838 T1810 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 849837 T1823 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> 849838 T1855 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 849848 T1856 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 849849 T1856 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 849851 T1856 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 851248 T1804 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 851250 T1804 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:42212_",
[junit4] 2> "base_url":"http://127.0.0.1:42212"}
[junit4] 2> 851250 T1804 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4] 2> 851250 T1804 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 851267 T1839 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> 851267 T1810 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> 851267 T1823 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> 851267 T1855 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> 851267 T1803 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> 851853 T1856 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 851853 T1856 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374865478847/collection1
[junit4] 2> 851853 T1856 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 851854 T1856 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 851854 T1856 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 851855 T1856 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374865478847/collection1/'
[junit4] 2> 851857 T1856 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374865478847/collection1/lib/classes/' to classloader
[junit4] 2> 851858 T1856 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374865478847/collection1/lib/README' to classloader
[junit4] 2> 851917 T1856 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 851981 T1856 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 852082 T1856 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 852094 T1856 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 852754 T1856 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 852768 T1856 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 852772 T1856 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 852786 T1856 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 852792 T1856 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 852796 T1856 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 852797 T1856 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 852798 T1856 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 852798 T1856 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 852799 T1856 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 852799 T1856 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 852800 T1856 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 852800 T1856 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374865478847/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZkTest-1374865464363/jetty3/
[junit4] 2> 852800 T1856 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@24aad6d7
[junit4] 2> 852801 T1856 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374865464363/jetty3
[junit4] 2> 852802 T1856 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZkTest-1374865464363/jetty3/index/
[junit4] 2> 852802 T1856 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZkTest-1374865464363/jetty3/index' doesn't exist. Creating new index...
[junit4] 2> 852802 T1856 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374865464363/jetty3/index
[junit4] 2> 852806 T1856 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@6fd4ab3b lockFactory=org.apache.lucene.store.NativeFSLockFactory@9fdc280),segFN=segments_1,generation=1}
[junit4] 2> 852807 T1856 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 852812 T1856 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 852813 T1856 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 852814 T1856 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 852815 T1856 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 852815 T1856 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 852816 T1856 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 852816 T1856 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 852817 T1856 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 852817 T1856 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 852834 T1856 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 852842 T1856 oass.SolrIndexSearcher.<init> Opening Searcher@30cf9d0e main
[junit4] 2> 852843 T1856 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 852843 T1856 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 852849 T1857 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@30cf9d0e main{StandardDirectoryReader(segments_1:1)}
[junit4] 2> 852852 T1856 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 852852 T1856 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:42212 collection:collection1 shard:shard1
[junit4] 2> 852852 T1856 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=30000&socketTimeout=30000&retry=false
[junit4] 2> 852873 T1856 oasc.ZkController.register We are http://127.0.0.1:42212/collection1/ and leader is http://127.0.0.1:44359/collection1/
[junit4] 2> 852874 T1856 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:42212
[junit4] 2> 852874 T1856 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4] 2> 852874 T1856 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4] 2> ASYNC NEW_CORE C571 name=collection1 org.apache.solr.core.SolrCore@58411b63 url=http://127.0.0.1:42212/collection1 node=127.0.0.1:42212_ C571_STATE=coll:collection1 core:collection1 props:{state=down, core=collection1, node_name=127.0.0.1:42212_, base_url=http://127.0.0.1:42212}
[junit4] 2> 852875 T1858 C571 P42212 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4] 2> 852875 T1856 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 852875 T1858 C571 P42212 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4] 2> 852876 T1858 C571 P42212 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4] 2> 852876 T1858 C571 P42212 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 852876 T1781 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0
[junit4] 2> 852877 T1781 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 852877 T1858 C571 P42212 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 852878 T1781 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 852891 T1813 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: core_node3, state: recovering, checkLive: true, onlyIfLeader: true
[junit4] 2> 853159 T1781 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 853163 T1781 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:49868
[junit4] 2> 853164 T1781 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 853165 T1781 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 853165 T1781 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty4-1374865483462
[junit4] 2> 853166 T1781 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty4-1374865483462/'
[junit4] 2> 853205 T1781 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty4-1374865483462/solr.xml
[junit4] 2> 853296 T1781 oasc.CoreContainer.<init> New CoreContainer 379672539
[junit4] 2> 853297 T1781 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty4-1374865483462/]
[junit4] 2> 853299 T1781 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 853300 T1781 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 853300 T1781 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 853301 T1781 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 853301 T1781 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 853302 T1781 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 853302 T1781 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 853303 T1781 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 853303 T1781 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 853304 T1781 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTime
[...truncated too long message...]
ingsFormat(name=NestedPulsing), timestamp=MockVariableIntBlock(baseBlockSize=33), id=PostingsFormat(name=Lucene41WithOrds), range_facet_sl=PostingsFormat(name=Lucene41WithOrds), range_facet_si=MockVariableIntBlock(baseBlockSize=33), oddField_s=PostingsFormat(name=Lucene41WithOrds), sequence_i=PostingsFormat(name=Lucene41WithOrds), name=PostingsFormat(name=Lucene41WithOrds), foo_i=PostingsFormat(name=NestedPulsing), regex_dup_B_s=MockVariableIntBlock(baseBlockSize=33), multiDefault=MockVariableIntBlock(baseBlockSize=33), n_tf1=MockVariableIntBlock(baseBlockSize=33), n_dt1=PostingsFormat(name=NestedPulsing), genre_s=PostingsFormat(name=Lucene41WithOrds), author_t=PostingsFormat(name=NestedPulsing), range_facet_l=MockVariableIntBlock(baseBlockSize=33), n_ti1=PostingsFormat(name=Lucene41WithOrds), text=PostingsFormat(name=MockSep), _version_=PostingsFormat(name=NestedPulsing), val_i=PostingsFormat(name=Lucene41WithOrds), SubjectTerms_mfacet=PostingsFormat(name=NestedPulsing), series_t=PostingsFormat(name=NestedPulsing), a_t=MockVariableIntBlock(baseBlockSize=33), n_tdt1=PostingsFormat(name=NestedPulsing), regex_dup_A_s=PostingsFormat(name=MockSep), price=PostingsFormat(name=MockSep), other_tl1=PostingsFormat(name=NestedPulsing), n_l1=MockVariableIntBlock(baseBlockSize=33), a_si=PostingsFormat(name=NestedPulsing), inStock=PostingsFormat(name=MockSep)}, docValues:{timestamp=DocValuesFormat(name=Lucene42)}, sim=DefaultSimilarity, locale=lv_LV, timezone=Asia/Kamchatka
[junit4] 2> NOTE: FreeBSD 9.1-RELEASE-p3 amd64/Oracle Corporation 1.7.0_25 (64-bit)/cpus=16,threads=2,free=408200400,total=495976448
[junit4] 2> NOTE: All tests run in this JVM: [TestFuzzyAnalyzedSuggestions, TestFieldTypeResource, IndexSchemaTest, TestQuerySenderListener, ScriptEngineTest, TestIBSimilarityFactory, DirectSolrConnectionTest, ResponseLogComponentTest, ExternalFileFieldSortTest, FastVectorHighlighterTest, SolrInfoMBeanTest, MinimalSchemaTest, AnalysisAfterCoreReloadTest, CoreAdminHandlerTest, TestStressRecovery, BadComponentTest, PreAnalyzedUpdateProcessorTest, BadCopyFieldTest, MBeansHandlerTest, TestFastLRUCache, SuggesterTest, TestFunctionQuery, TermVectorComponentTest, StatelessScriptUpdateProcessorFactoryTest, DocValuesTest, LeaderElectionTest, PolyFieldTest, TestXIncludeConfig, TestSort, TestPluginEnable, TestShardHandlerFactory, SyncSliceTest, ParsingFieldUpdateProcessorsTest, TestSchemaVersionResource, JsonLoaderTest, CircularListTest, SolrIndexSplitterTest, PreAnalyzedFieldTest, FieldMutatingUpdateProcessorTest, SpatialFilterTest, SOLR749Test, SystemInfoHandlerTest, DistributedSpellCheckComponentTest, TestFaceting, AlternateDirectoryTest, TestCharFilters, BasicFunctionalityTest, CachingDirectoryFactoryTest, SchemaVersionSpecificBehaviorTest, ChaosMonkeyNothingIsSafeTest, QueryElevationComponentTest, SolrCoreTest, TestSolrDeletionPolicy2, RegexBoostProcessorTest, TestFastWriter, TestTrie, DateFieldTest, FileBasedSpellCheckerTest, ShardRoutingTest, BlockDirectoryTest, TestGroupingSearch, TestMaxScoreQueryParser, DocumentBuilderTest, ZkControllerTest, TestDocSet, AutoCommitTest, TestRemoteStreaming, TestLRUCache, ClusterStateUpdateTest, OverseerCollectionProcessorTest, SynonymTokenizerTest, ResourceLoaderTest, AliasIntegrationTest, SuggesterFSTTest, MoreLikeThisHandlerTest, TestCoreContainer, AssignTest, BasicDistributedZkTest]
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=BasicDistributedZkTest -Dtests.seed=FCEE89A443F8D944 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=lv_LV -Dtests.timezone=Asia/Kamchatka -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=2284, name=recoveryCmdExecutor-1099-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:392)
[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:724)
[junit4] > at __randomizedtesting.SeedInfo.seed([FCEE89A443F8D944]:0)Throwable #2: com.carrotsearch.randomizedtesting.ThreadLeakError: There are still zombie threads that couldn't be terminated:
[junit4] > 1) Thread[id=2284, name=recoveryCmdExecutor-1099-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:392)
[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:724)
[junit4] > at __randomizedtesting.SeedInfo.seed([FCEE89A443F8D944]:0)
[junit4] Completed on J0 in 424.88s, 1 test, 2 errors <<< FAILURES!
[...truncated 511 lines...]
BUILD FAILED
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/build.xml:389: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/build.xml:369: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/build.xml:39: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build.xml:181: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/common-build.xml:449: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/lucene/common-build.xml:1230: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/lucene/common-build.xml:873: There were test failures: 318 suites, 1342 tests, 2 suite-level errors, 653 ignored (6 assumptions)
Total time: 45 minutes 10 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure