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/29 07:20:06 UTC
[JENKINS] Lucene-Solr-Tests-trunk-Java7 - Build # 4186 - Still
Failing
Build: https://builds.apache.org/job/Lucene-Solr-Tests-trunk-Java7/4186/
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=2506, name=recoveryCmdExecutor-1103-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=2506, name=recoveryCmdExecutor-1103-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([2EC31A61BB8D159F]: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=2506, name=recoveryCmdExecutor-1103-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=2506, name=recoveryCmdExecutor-1103-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([2EC31A61BB8D159F]:0)
Build Log:
[...truncated 9807 lines...]
[junit4] Suite: org.apache.solr.cloud.BasicDistributedZkTest
[junit4] 2> 996419 T2017 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /_y/d
[junit4] 2> 996423 T2017 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-1375074700568
[junit4] 2> 996425 T2017 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 996425 T2018 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 996526 T2017 oasc.ZkTestServer.run start zk server on port:56243
[junit4] 2> 996526 T2017 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 996560 T2024 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6f64eac2 name:ZooKeeperConnection Watcher:127.0.0.1:56243 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 996560 T2017 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 996561 T2017 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 996578 T2017 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 996580 T2026 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@419d191b name:ZooKeeperConnection Watcher:127.0.0.1:56243/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 996580 T2017 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 996581 T2017 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4] 2> 996584 T2017 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4] 2> 996596 T2017 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4] 2> 996597 T2017 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4] 2> 996599 T2017 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> 996600 T2017 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4] 2> 996611 T2017 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> 996611 T2017 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4] 2> 996719 T2017 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> 996720 T2017 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4] 2> 996751 T2017 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> 996751 T2017 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4] 2> 996769 T2017 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> 996769 T2017 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4] 2> 996777 T2017 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> 996777 T2017 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4] 2> 996781 T2017 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> 996781 T2017 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 996788 T2017 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> 996789 T2017 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4] 2> 996796 T2017 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> 996797 T2017 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4] 2> 997087 T2017 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 997092 T2017 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:56703
[junit4] 2> 997093 T2017 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 997093 T2017 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 997094 T2017 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-1375074700945
[junit4] 2> 997094 T2017 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-1375074700945/'
[junit4] 2> 997131 T2017 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-1375074700945/solr.xml
[junit4] 2> 997222 T2017 oasc.CoreContainer.<init> New CoreContainer 1326039547
[junit4] 2> 997223 T2017 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-1375074700945/]
[junit4] 2> 997225 T2017 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 997225 T2017 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 997226 T2017 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 997226 T2017 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 997227 T2017 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 997227 T2017 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 997227 T2017 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 997228 T2017 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 997228 T2017 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 997229 T2017 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4] 2> 997247 T2017 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:56243/solr
[junit4] 2> 997247 T2017 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 997248 T2017 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 997251 T2037 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@13bfcdee name:ZooKeeperConnection Watcher:127.0.0.1:56243 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 997251 T2017 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 997253 T2017 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4] 2> 997266 T2017 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 997268 T2039 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@10d64873 name:ZooKeeperConnection Watcher:127.0.0.1:56243/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 997269 T2017 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 997271 T2017 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 997281 T2017 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 997284 T2017 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 997292 T2017 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:56703__y%2Fd
[junit4] 2> 997293 T2017 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:56703__y%2Fd
[junit4] 2> 997297 T2017 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 997324 T2017 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 997337 T2017 oasc.Overseer.start Overseer (id=90116895576817667-127.0.0.1:56703__y%2Fd-n_0000000000) starting
[junit4] 2> 997349 T2017 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 997359 T2041 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 997359 T2017 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 997362 T2017 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 997363 T2017 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 997366 T2040 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 997372 T2042 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 997372 T2042 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 997373 T2042 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 998870 T2040 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 998871 T2040 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:56703__y%2Fd",
[junit4] 2> "base_url":"http://127.0.0.1:56703/_y/d"}
[junit4] 2> 998872 T2040 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with numShards 1
[junit4] 2> 998872 T2040 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 998886 T2039 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> 999375 T2042 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 999375 T2042 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-1375074700945/collection1
[junit4] 2> 999375 T2042 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4] 2> 999376 T2042 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 999376 T2042 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4] 2> 999377 T2042 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-1375074700945/collection1/'
[junit4] 2> 999379 T2042 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-1375074700945/collection1/lib/classes/' to classloader
[junit4] 2> 999379 T2042 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-1375074700945/collection1/lib/README' to classloader
[junit4] 2> 999436 T2042 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 999498 T2042 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 999600 T2042 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 999612 T2042 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 1000294 T2042 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 1000304 T2042 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 1000307 T2042 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 1000319 T2042 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1000323 T2042 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1000326 T2042 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 1000327 T2042 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 1000327 T2042 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 1000327 T2042 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 1000328 T2042 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 1000328 T2042 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 1000329 T2042 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 1000329 T2042 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-1375074700945/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZkTest-1375074700568/control/data/
[junit4] 2> 1000329 T2042 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@3d605cf6
[junit4] 2> 1000330 T2042 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1375074700568/control/data
[junit4] 2> 1000330 T2042 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZkTest-1375074700568/control/data/index/
[junit4] 2> 1000330 T2042 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZkTest-1375074700568/control/data/index' doesn't exist. Creating new index...
[junit4] 2> 1000330 T2042 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1375074700568/control/data/index
[junit4] 2> 1000334 T2042 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@3b97a3a2 lockFactory=org.apache.lucene.store.NativeFSLockFactory@4b4fca50),segFN=segments_1,generation=1}
[junit4] 2> 1000334 T2042 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1000338 T2042 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 1000338 T2042 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 1000338 T2042 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1000339 T2042 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 1000339 T2042 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 1000339 T2042 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 1000340 T2042 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 1000340 T2042 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 1000340 T2042 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 1000352 T2042 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 1000359 T2042 oass.SolrIndexSearcher.<init> Opening Searcher@23429bbf main
[junit4] 2> 1000360 T2042 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 1000360 T2042 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 1000364 T2043 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@23429bbf main{StandardDirectoryReader(segments_1:1)}
[junit4] 2> 1000364 T2042 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 1000364 T2042 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:56703/_y/d collection:control_collection shard:shard1
[junit4] 2> 1000365 T2042 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=30000&socketTimeout=30000&retry=false
[junit4] 2> 1000378 T2042 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4] 2> 1000400 T2042 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 1000410 T2042 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 1000411 T2042 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 1000411 T2042 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:56703/_y/d/collection1/
[junit4] 2> 1000411 T2042 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 1000411 T2042 oasc.SyncStrategy.syncToMe http://127.0.0.1:56703/_y/d/collection1/ has no replicas
[junit4] 2> 1000411 T2042 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:56703/_y/d/collection1/ shard1
[junit4] 2> 1000411 T2042 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4] 2> 1001900 T2040 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1001925 T2039 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> 1001958 T2042 oasc.ZkController.register We are http://127.0.0.1:56703/_y/d/collection1/ and leader is http://127.0.0.1:56703/_y/d/collection1/
[junit4] 2> 1001958 T2042 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:56703/_y/d
[junit4] 2> 1001958 T2042 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 1001958 T2042 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 1001959 T2042 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1001961 T2042 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1001962 T2017 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0
[junit4] 2> 1001962 T2017 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 1001963 T2017 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 1001975 T2017 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4] 2> 1001977 T2017 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1001980 T2046 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@19d8a653 name:ZooKeeperConnection Watcher:127.0.0.1:56243/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1001980 T2017 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1001981 T2017 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1001983 T2017 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4] 2> 1002281 T2017 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 1002284 T2017 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:28014
[junit4] 2> 1002285 T2017 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 1002286 T2017 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1002286 T2017 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-1375074706128
[junit4] 2> 1002286 T2017 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-1375074706128/'
[junit4] 2> 1002323 T2017 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-1375074706128/solr.xml
[junit4] 2> 1002415 T2017 oasc.CoreContainer.<init> New CoreContainer 1995232339
[junit4] 2> 1002415 T2017 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-1375074706128/]
[junit4] 2> 1002417 T2017 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 1002418 T2017 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 1002418 T2017 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 1002419 T2017 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 1002419 T2017 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 1002419 T2017 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 1002420 T2017 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 1002420 T2017 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 1002421 T2017 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 1002421 T2017 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4] 2> 1002437 T2017 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:56243/solr
[junit4] 2> 1002438 T2017 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 1002439 T2017 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1002441 T2057 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2e9904c9 name:ZooKeeperConnection Watcher:127.0.0.1:56243 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1002441 T2017 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1002443 T2017 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4] 2> 1002454 T2017 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1002456 T2059 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@136b8c87 name:ZooKeeperConnection Watcher:127.0.0.1:56243/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1002457 T2017 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1002468 T2017 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1003438 T2040 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1003439 T2040 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:56703__y%2Fd",
[junit4] 2> "base_url":"http://127.0.0.1:56703/_y/d"}
[junit4] 2> 1003454 T2046 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> 1003454 T2059 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> 1003454 T2039 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> 1003471 T2017 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:28014__y%2Fd
[junit4] 2> 1003473 T2017 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:28014__y%2Fd
[junit4] 2> 1003475 T2046 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> 1003475 T2039 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> 1003475 T2059 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1003476 T2059 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> 1003476 T2046 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1003476 T2039 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1003492 T2060 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 1003492 T2060 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1003493 T2060 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 1004958 T2040 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1004959 T2040 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:28014__y%2Fd",
[junit4] 2> "base_url":"http://127.0.0.1:28014/_y/d"}
[junit4] 2> 1004960 T2040 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with numShards 2
[junit4] 2> 1004960 T2040 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 1004964 T2039 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> 1004964 T2059 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> 1004964 T2046 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> 1005496 T2060 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 1005496 T2060 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-1375074706128/collection1
[junit4] 2> 1005496 T2060 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 1005497 T2060 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 1005497 T2060 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 1005498 T2060 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-1375074706128/collection1/'
[junit4] 2> 1005500 T2060 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-1375074706128/collection1/lib/README' to classloader
[junit4] 2> 1005500 T2060 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-1375074706128/collection1/lib/classes/' to classloader
[junit4] 2> 1005557 T2060 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 1005637 T2060 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 1005739 T2060 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 1005751 T2060 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 1006386 T2060 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 1006398 T2060 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 1006401 T2060 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 1006413 T2060 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1006417 T2060 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1006420 T2060 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 1006421 T2060 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 1006421 T2060 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 1006421 T2060 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 1006422 T2060 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 1006422 T2060 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 1006423 T2060 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 1006423 T2060 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-1375074706128/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZkTest-1375074700568/jetty1/
[junit4] 2> 1006423 T2060 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@3d605cf6
[junit4] 2> 1006424 T2060 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1375074700568/jetty1
[junit4] 2> 1006424 T2060 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZkTest-1375074700568/jetty1/index/
[junit4] 2> 1006424 T2060 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZkTest-1375074700568/jetty1/index' doesn't exist. Creating new index...
[junit4] 2> 1006425 T2060 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1375074700568/jetty1/index
[junit4] 2> 1006427 T2060 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1c0067fe lockFactory=org.apache.lucene.store.NativeFSLockFactory@2df14ab1),segFN=segments_1,generation=1}
[junit4] 2> 1006427 T2060 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1006431 T2060 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 1006431 T2060 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 1006432 T2060 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1006433 T2060 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 1006433 T2060 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 1006434 T2060 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 1006434 T2060 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 1006434 T2060 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 1006435 T2060 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 1006445 T2060 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 1006450 T2060 oass.SolrIndexSearcher.<init> Opening Searcher@57937126 main
[junit4] 2> 1006451 T2060 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 1006451 T2060 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 1006456 T2061 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@57937126 main{StandardDirectoryReader(segments_1:1)}
[junit4] 2> 1006458 T2060 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 1006458 T2060 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:28014/_y/d collection:collection1 shard:shard1
[junit4] 2> 1006458 T2060 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=30000&socketTimeout=30000&retry=false
[junit4] 2> 1006470 T2060 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1006681 T2060 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 1006738 T2060 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 1006739 T2060 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 1006739 T2060 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:28014/_y/d/collection1/
[junit4] 2> 1006740 T2060 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 1006740 T2060 oasc.SyncStrategy.syncToMe http://127.0.0.1:28014/_y/d/collection1/ has no replicas
[junit4] 2> 1006740 T2060 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:28014/_y/d/collection1/ shard1
[junit4] 2> 1006740 T2060 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1008108 T2040 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1008124 T2039 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> 1008124 T2046 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> 1008124 T2059 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> 1008178 T2060 oasc.ZkController.register We are http://127.0.0.1:28014/_y/d/collection1/ and leader is http://127.0.0.1:28014/_y/d/collection1/
[junit4] 2> 1008178 T2060 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:28014/_y/d
[junit4] 2> 1008178 T2060 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 1008178 T2060 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 1008179 T2060 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1008180 T2060 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1008181 T2017 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0
[junit4] 2> 1008181 T2017 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 1008182 T2017 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 1008433 T2017 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 1008436 T2017 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:37995
[junit4] 2> 1008437 T2017 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 1008438 T2017 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1008438 T2017 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-1375074712334
[junit4] 2> 1008439 T2017 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-1375074712334/'
[junit4] 2> 1008476 T2017 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-1375074712334/solr.xml
[junit4] 2> 1008569 T2017 oasc.CoreContainer.<init> New CoreContainer 2056780197
[junit4] 2> 1008570 T2017 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-1375074712334/]
[junit4] 2> 1008571 T2017 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 1008572 T2017 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 1008572 T2017 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 1008573 T2017 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 1008573 T2017 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 1008574 T2017 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 1008574 T2017 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 1008574 T2017 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 1008575 T2017 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 1008575 T2017 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4] 2> 1008592 T2017 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:56243/solr
[junit4] 2> 1008592 T2017 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 1008593 T2017 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1008595 T2073 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@38225eec name:ZooKeeperConnection Watcher:127.0.0.1:56243 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1008595 T2017 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1008597 T2017 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4] 2> 1008609 T2017 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1008611 T2075 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@237a1f28 name:ZooKeeperConnection Watcher:127.0.0.1:56243/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1008611 T2017 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1008615 T2017 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1009618 T2017 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:37995__y%2Fd
[junit4] 2> 1009645 T2017 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:37995__y%2Fd
[junit4] 2> 1009646 T2040 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1009647 T2039 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> 1009647 T2046 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> 1009648 T2059 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 1009648 T2040 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:28014__y%2Fd",
[junit4] 2> "base_url":"http://127.0.0.1:28014/_y/d"}
[junit4] 2> 1009648 T2075 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 1009648 T2059 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> 1009655 T2046 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 1009662 T2076 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 1009663 T2076 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1009667 T2046 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> 1009667 T2075 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> 1009667 T2059 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> 1009667 T2076 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 1009670 T2039 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 1009670 T2039 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> 1011172 T2040 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1011174 T2040 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:37995__y%2Fd",
[junit4] 2> "base_url":"http://127.0.0.1:37995/_y/d"}
[junit4] 2> 1011174 T2040 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4] 2> 1011174 T2040 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 1011194 T2046 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> 1011194 T2059 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> 1011194 T2039 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> 1011194 T2075 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> 1011670 T2076 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 1011670 T2076 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-1375074712334/collection1
[junit4] 2> 1011671 T2076 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 1011672 T2076 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 1011672 T2076 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 1011674 T2076 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-1375074712334/collection1/'
[junit4] 2> 1011677 T2076 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-1375074712334/collection1/lib/README' to classloader
[junit4] 2> 1011679 T2076 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-1375074712334/collection1/lib/classes/' to classloader
[junit4] 2> 1011782 T2076 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 1011881 T2076 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 1011983 T2076 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 1012008 T2076 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 1013022 T2076 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 1013036 T2076 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 1013042 T2076 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 1013066 T2076 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1013071 T2076 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1013076 T2076 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 1013077 T2076 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 1013077 T2076 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 1013077 T2076 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 1013078 T2076 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 1013079 T2076 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 1013079 T2076 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 1013080 T2076 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-1375074712334/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZkTest-1375074700568/jetty2/
[junit4] 2> 1013080 T2076 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@3d605cf6
[junit4] 2> 1013081 T2076 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1375074700568/jetty2
[junit4] 2> 1013082 T2076 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZkTest-1375074700568/jetty2/index/
[junit4] 2> 1013082 T2076 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZkTest-1375074700568/jetty2/index' doesn't exist. Creating new index...
[junit4] 2> 1013082 T2076 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1375074700568/jetty2/index
[junit4] 2> 1013086 T2076 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@19095503 lockFactory=org.apache.lucene.store.NativeFSLockFactory@76170073),segFN=segments_1,generation=1}
[junit4] 2> 1013086 T2076 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1013092 T2076 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 1013092 T2076 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 1013093 T2076 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1013094 T2076 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 1013095 T2076 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 1013095 T2076 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 1013095 T2076 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 1013096 T2076 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 1013097 T2076 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 1013113 T2076 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 1013121 T2076 oass.SolrIndexSearcher.<init> Opening Searcher@21a429fe main
[junit4] 2> 1013122 T2076 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 1013122 T2076 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 1013128 T2077 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@21a429fe main{StandardDirectoryReader(segments_1:1)}
[junit4] 2> 1013131 T2076 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 1013131 T2076 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:37995/_y/d collection:collection1 shard:shard2
[junit4] 2> 1013131 T2076 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=30000&socketTimeout=30000&retry=false
[junit4] 2> 1013152 T2076 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4] 2> 1013168 T2076 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
[junit4] 2> 1013171 T2076 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 1013171 T2076 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 1013171 T2076 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:37995/_y/d/collection1/
[junit4] 2> 1013172 T2076 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 1013172 T2076 oasc.SyncStrategy.syncToMe http://127.0.0.1:37995/_y/d/collection1/ has no replicas
[junit4] 2> 1013172 T2076 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:37995/_y/d/collection1/ shard2
[junit4] 2> 1013172 T2076 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4] 2> 1014202 T2040 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1014209 T2039 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> 1014209 T2059 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> 1014209 T2046 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> 1014209 T2075 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> 1014251 T2076 oasc.ZkController.register We are http://127.0.0.1:37995/_y/d/collection1/ and leader is http://127.0.0.1:37995/_y/d/collection1/
[junit4] 2> 1014251 T2076 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:37995/_y/d
[junit4] 2> 1014251 T2076 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 1014251 T2076 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 1014252 T2076 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1014253 T2076 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1014254 T2017 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0
[junit4] 2> 1014255 T2017 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 1014255 T2017 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 1014537 T2017 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 1014541 T2017 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:36396
[junit4] 2> 1014541 T2017 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 1014542 T2017 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1014542 T2017 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-1375074718406
[junit4] 2> 1014543 T2017 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-1375074718406/'
[junit4] 2> 1014580 T2017 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-1375074718406/solr.xml
[junit4] 2> 1014670 T2017 oasc.CoreContainer.<init> New CoreContainer 970023321
[junit4] 2> 1014671 T2017 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-1375074718406/]
[junit4] 2> 1014673 T2017 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 1014673 T2017 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 1014674 T2017 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 1014674 T2017 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 1014675 T2017 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 1014675 T2017 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 1014675 T2017 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 1014676 T2017 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 1014676 T2017 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 1014677 T2017 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4] 2> 1014693 T2017 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:56243/solr
[junit4] 2> 1014693 T2017 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 1014694 T2017 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1014697 T2089 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1d8751 name:ZooKeeperConnection Watcher:127.0.0.1:56243 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1014697 T2017 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1014712 T2017 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4] 2> 1014723 T2017 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1014732 T2091 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@55fe9100 name:ZooKeeperConnection Watcher:127.0.0.1:56243/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1014732 T2017 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1014743 T2017 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1015716 T2040 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1015718 T2040 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:37995__y%2Fd",
[junit4] 2> "base_url":"http://127.0.0.1:37995/_y/d"}
[junit4] 2> 1015732 T2075 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> 1015732 T2039 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> 1015732 T2046 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> 1015732 T2091 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> 1015732 T2059 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> 1015746 T2017 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:36396__y%2Fd
[junit4] 2> 1015749 T2017 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:36396__y%2Fd
[junit4] 2> 1015751 T2075 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> 1015752 T2039 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> 1015752 T2046 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> 1015753 T2091 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 1015753 T2091 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> 1015753 T2059 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 1015754 T2059 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> 1015755 T2075 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 1015755 T2039 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 1015757 T2046 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 1015771 T2092 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 1015771 T2092 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1015774 T2092 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 1017245 T2040 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1017247 T2040 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:36396__y%2Fd",
[junit4] 2> "base_url":"http://127.0.0.1:36396/_y/d"}
[junit4] 2> 1017247 T2040 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4] 2> 1017248 T2040 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 1017280 T2075 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> 1017280 T2091 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> 1017280 T2046 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> 1017280 T2039 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> 1017280 T2059 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> 1017776 T2092 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 1017776 T2092 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-1375074718406/collection1
[junit4] 2> 1017777 T2092 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 1017778 T2092 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 1017778 T2092 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 1017779 T2092 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-1375074718406/collection1/'
[junit4] 2> 1017785 T2092 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-1375074718406/collection1/lib/README' to classloader
[junit4] 2> 1017786 T2092 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-1375074718406/collection1/lib/classes/' to classloader
[junit4] 2> 1017855 T2092 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 1017921 T2092 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 1018023 T2092 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 1018036 T2092 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 1018688 T2092 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 1018701 T2092 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 1018705 T2092 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 1018719 T2092 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1018724 T2092 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1018728 T2092 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 1018729 T2092 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 1018730 T2092 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 1018730 T2092 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 1018731 T2092 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 1018731 T2092 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 1018731 T2092 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 1018732 T2092 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-1375074718406/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZkTest-1375074700568/jetty3/
[junit4] 2> 1018732 T2092 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@3d605cf6
[junit4] 2> 1018733 T2092 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1375074700568/jetty3
[junit4] 2> 1018733 T2092 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZkTest-1375074700568/jetty3/index/
[junit4] 2> 1018734 T2092 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZkTest-1375074700568/jetty3/index' doesn't exist. Creating new index...
[junit4] 2> 1018734 T2092 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1375074700568/jetty3/index
[junit4] 2> 1018738 T2092 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@51802b03 lockFactory=org.apache.lucene.store.NativeFSLockFactory@4f448d19),segFN=segments_1,generation=1}
[junit4] 2> 1018738 T2092 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1018744 T2092 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 1018744 T2092 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 1018745 T2092 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1018746 T2092 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 1018746 T2092 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 1018747 T2092 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 1018747 T2092 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 1018748 T2092 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 1018748 T2092 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 1018765 T2092 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 1018773 T2092 oass.SolrIndexSearcher.<init> Opening Searcher@436e938c main
[junit4] 2> 1018774 T2092 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 1018774 T2092 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 1018780 T2093 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@436e938c main{StandardDirectoryReader(segments_1:1)}
[junit4] 2> 1018782 T2092 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 1018782 T2092 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:36396/_y/d collection:collection1 shard:shard1
[junit4] 2> 1018783 T2092 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=30000&socketTimeout=30000&retry=false
[junit4] 2> 1018800 T2092 oasc.ZkController.register We are http://127.0.0.1:36396/_y/d/collection1/ and leader is http://127.0.0.1:28014/_y/d/collection1/
[junit4] 2> 1018801 T2092 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:36396/_y/d
[junit4] 2> 1018801 T2092 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4] 2> 1018801 T2092 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4] 2> ASYNC NEW_CORE C922 name=collection1 org.apache.solr.core.SolrCore@4fa4037e url=http://127.0.0.1:36396/_y/d/collection1 node=127.0.0.1:36396__y%2Fd C922_STATE=coll:collection1 core:collection1 props:{state=down, core=collection1, node_name=127.0.0.1:36396__y%2Fd, base_url=http://127.0.0.1:36396/_y/d}
[junit4] 2> 1018801 T2094 C922 P36396 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4] 2> 1018802 T2092 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1018802 T2094 C922 P36396 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4] 2> 1018803 T2094 C922 P36396 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4] 2> 1018803 T2094 C922 P36396 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1018803 T2017 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0
[junit4] 2> 1018804 T2017 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 1018804 T2094 C922 P36396 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 1018804 T2017 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 1018817 T2049 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: core_node3, state: recovering, checkLive: true, onlyIfLeader: true
[junit4] 2> 1019098 T2017 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 1019102 T2017 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:36420
[junit4] 2> 1019102 T2017 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 1019103 T2017 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1019103 T2017 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-1375074722960
[junit4] 2> 1019104 T2017 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-1375074722960/'
[junit4] 2> 1019140 T2017 oasc.ConfigSolr.fromFile Load
[...truncated too long message...]
aultClientConnectionOperator.java:180)
[junit4] 2> at org.apache.http.impl.conn.ManagedClientConnectionImpl.open(ManagedClientConnectionImpl.java:294)
[junit4] 2> at org.apache.http.impl.client.DefaultRequestDirector.tryConnect(DefaultRequestDirector.java:645)
[junit4] 2> at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:480)
[junit4] 2> at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:906)
[junit4] 2> at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:805)
[junit4] 2> at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:784)
[junit4] 2> at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:365)
[junit4] 2> at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:180)
[junit4] 2> at org.apache.solr.cloud.SyncStrategy$1.run(SyncStrategy.java:291)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
[junit4] 2> at java.lang.Thread.run(Thread.java:724)
[junit4] 2> NOTE: test params are: codec=Lucene40, sim=RandomSimilarityProvider(queryNorm=true,coord=yes): {}, locale=en_NZ, timezone=HST
[junit4] 2> NOTE: FreeBSD 9.1-RELEASE-p3 amd64/Oracle Corporation 1.7.0_25 (64-bit)/cpus=16,threads=2,free=297205608,total=477102080
[junit4] 2> NOTE: All tests run in this JVM: [TestRandomDVFaceting, LukeRequestHandlerTest, TestCharFilters, TermsComponentTest, DocumentBuilderTest, SoftAutoCommitTest, LoggingHandlerTest, SolrInfoMBeanTest, RecoveryZkTest, ZkControllerTest, PrimitiveFieldTypeTest, OverseerTest, QueryEqualityTest, TestIBSimilarityFactory, TestSolrDeletionPolicy2, PreAnalyzedUpdateProcessorTest, AutoCommitTest, TestFieldResource, SyncSliceTest, TestAddFieldRealTimeGet, TestCopyFieldCollectionResource, ReturnFieldsTest, BlockDirectoryTest, SliceStateTest, TestSerializedLuceneMatchVersion, ShardRoutingTest, ShowFileRequestHandlerTest, TestLRUCache, TestSolrDeletionPolicy1, TestPseudoReturnFields, WordBreakSolrSpellCheckerTest, TestSolrXmlPersistence, StatelessScriptUpdateProcessorFactoryTest, TestExtendedDismaxParser, RegexBoostProcessorTest, TestFieldTypeResource, TestQuerySenderListener, MBeansHandlerTest, TestFunctionQuery, IndexSchemaTest, TestJoin, UpdateRequestProcessorFactoryTest, TestSearchPerf, BinaryUpdateRequestHandlerTest, TestDocumentBuilder, LegacyHTMLStripCharFilterTest, AddSchemaFieldsUpdateProcessorFactoryTest, TestSchemaVersionResource, TestSolrXml, TestDefaultSearchFieldResource, TestCoreContainer, TestFastWriter, TestQueryUtils, TestValueSourceCache, BadComponentTest, CacheHeaderTest, TestReversedWildcardFilterFactory, ScriptEngineTest, TestPropInjectDefaults, DocValuesTest, SuggesterFSTTest, TestFaceting, SOLR749Test, TestDocSet, TestSurroundQueryParser, TestGroupingSearch, TestWriterPerf, SolrIndexSplitterTest, TestStressRecovery, FileBasedSpellCheckerTest, QueryElevationComponentTest, TestSolrIndexConfig, RAMDirectoryFactoryTest, PrimUtilsTest, SimpleFacetsTest, AssignTest, TestRemoteStreaming, BasicDistributedZkTest]
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=BasicDistributedZkTest -Dtests.seed=2EC31A61BB8D159F -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=en_NZ -Dtests.timezone=HST -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=2506, name=recoveryCmdExecutor-1103-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([2EC31A61BB8D159F]:0)Throwable #2: com.carrotsearch.randomizedtesting.ThreadLeakError: There are still zombie threads that couldn't be terminated:
[junit4] > 1) Thread[id=2506, name=recoveryCmdExecutor-1103-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([2EC31A61BB8D159F]:0)
[junit4] Completed on J0 in 421.50s, 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, 633 ignored (1 assumption)
Total time: 46 minutes 51 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure