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/25 11:19:55 UTC
[JENKINS] Lucene-Solr-Tests-4.4-Java6 - Build # 51 - Still Failing
Build: https://builds.apache.org/job/Lucene-Solr-Tests-4.4-Java6/51/
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=2934, name=recoveryCmdExecutor-1117-thread-1, state=RUNNABLE, group=TGRP-BasicDistributedZkTest] at java.net.PlainSocketImpl.socketConnect(Native Method) at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:327) at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:193) at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:180) at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:384) at java.net.Socket.connect(Socket.java:546) at org.apache.http.conn.scheme.PlainSocketFactory.connectSocket(PlainSocketFactory.java:127) at org.apache.http.impl.conn.DefaultClientConnectionOperator.openConnection(DefaultClientConnectionOperator.java:180) at org.apache.http.impl.conn.ManagedClientConnectionImpl.open(ManagedClientConnectionImpl.java:294) at org.apache.http.impl.client.DefaultRequestDirector.tryConnect(DefaultRequestDirector.java:645) at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:480) at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:906) at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:805) at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:784) at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:365) at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:180) at org.apache.solr.cloud.SyncStrategy$1.run(SyncStrategy.java:291) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1146) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) at java.lang.Thread.run(Thread.java:679)
Stack Trace:
com.carrotsearch.randomizedtesting.ThreadLeakError: 1 thread leaked from SUITE scope at org.apache.solr.cloud.BasicDistributedZkTest:
1) Thread[id=2934, name=recoveryCmdExecutor-1117-thread-1, state=RUNNABLE, group=TGRP-BasicDistributedZkTest]
at java.net.PlainSocketImpl.socketConnect(Native Method)
at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:327)
at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:193)
at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:180)
at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:384)
at java.net.Socket.connect(Socket.java:546)
at org.apache.http.conn.scheme.PlainSocketFactory.connectSocket(PlainSocketFactory.java:127)
at org.apache.http.impl.conn.DefaultClientConnectionOperator.openConnection(DefaultClientConnectionOperator.java:180)
at org.apache.http.impl.conn.ManagedClientConnectionImpl.open(ManagedClientConnectionImpl.java:294)
at org.apache.http.impl.client.DefaultRequestDirector.tryConnect(DefaultRequestDirector.java:645)
at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:480)
at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:906)
at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:805)
at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:784)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:365)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:180)
at org.apache.solr.cloud.SyncStrategy$1.run(SyncStrategy.java:291)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1146)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:679)
at __randomizedtesting.SeedInfo.seed([C420AC0720679321]: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=2934, name=recoveryCmdExecutor-1117-thread-1, state=RUNNABLE, group=TGRP-BasicDistributedZkTest] at java.net.PlainSocketImpl.socketConnect(Native Method) at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:327) at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:193) at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:180) at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:384) at java.net.Socket.connect(Socket.java:546) at org.apache.http.conn.scheme.PlainSocketFactory.connectSocket(PlainSocketFactory.java:127) at org.apache.http.impl.conn.DefaultClientConnectionOperator.openConnection(DefaultClientConnectionOperator.java:180) at org.apache.http.impl.conn.ManagedClientConnectionImpl.open(ManagedClientConnectionImpl.java:294) at org.apache.http.impl.client.DefaultRequestDirector.tryConnect(DefaultRequestDirector.java:645) at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:480) at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:906) at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:805) at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:784) at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:365) at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:180) at org.apache.solr.cloud.SyncStrategy$1.run(SyncStrategy.java:291) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1146) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) at java.lang.Thread.run(Thread.java:679)
Stack Trace:
com.carrotsearch.randomizedtesting.ThreadLeakError: There are still zombie threads that couldn't be terminated:
1) Thread[id=2934, name=recoveryCmdExecutor-1117-thread-1, state=RUNNABLE, group=TGRP-BasicDistributedZkTest]
at java.net.PlainSocketImpl.socketConnect(Native Method)
at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:327)
at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:193)
at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:180)
at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:384)
at java.net.Socket.connect(Socket.java:546)
at org.apache.http.conn.scheme.PlainSocketFactory.connectSocket(PlainSocketFactory.java:127)
at org.apache.http.impl.conn.DefaultClientConnectionOperator.openConnection(DefaultClientConnectionOperator.java:180)
at org.apache.http.impl.conn.ManagedClientConnectionImpl.open(ManagedClientConnectionImpl.java:294)
at org.apache.http.impl.client.DefaultRequestDirector.tryConnect(DefaultRequestDirector.java:645)
at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:480)
at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:906)
at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:805)
at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:784)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:365)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:180)
at org.apache.solr.cloud.SyncStrategy$1.run(SyncStrategy.java:291)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1146)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:679)
at __randomizedtesting.SeedInfo.seed([C420AC0720679321]:0)
Build Log:
[...truncated 9022 lines...]
[junit4] Suite: org.apache.solr.cloud.BasicDistributedZkTest
[junit4] 2> 804932 T2475 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
[junit4] 2> 804938 T2475 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4] 2> Creating dataDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J0/./solrtest-BasicDistributedZkTest-1374743410424
[junit4] 2> 804940 T2475 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 804940 T2476 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 805041 T2475 oasc.ZkTestServer.run start zk server on port:48606
[junit4] 2> 805042 T2475 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 805045 T2482 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@14bcc1d name:ZooKeeperConnection Watcher:127.0.0.1:48606 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 805046 T2475 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 805046 T2475 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 805050 T2475 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 805058 T2484 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@336a6026 name:ZooKeeperConnection Watcher:127.0.0.1:48606/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 805059 T2475 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 805059 T2475 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4] 2> 805066 T2475 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4] 2> 805069 T2475 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4] 2> 805071 T2475 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4] 2> 805079 T2475 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4] 2> 805079 T2475 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4] 2> 805088 T2475 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
[junit4] 2> 805089 T2475 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4] 2> 805192 T2475 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4] 2> 805193 T2475 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4] 2> 805196 T2475 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4] 2> 805196 T2475 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4] 2> 805207 T2475 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4] 2> 805208 T2475 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4] 2> 805210 T2475 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4] 2> 805211 T2475 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4] 2> 805214 T2475 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 805214 T2475 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 805217 T2475 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4] 2> 805217 T2475 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4] 2> 805220 T2475 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4] 2> 805221 T2475 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4] 2> 805495 T2475 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 805499 T2475 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:48609
[junit4] 2> 805500 T2475 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 805500 T2475 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 805501 T2475 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374743410716
[junit4] 2> 805501 T2475 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374743410716/'
[junit4] 2> 805540 T2475 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374743410716/solr.xml
[junit4] 2> 805613 T2475 oasc.CoreContainer.<init> New CoreContainer 1609713758
[junit4] 2> 805614 T2475 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374743410716/]
[junit4] 2> 805616 T2475 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 805616 T2475 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 805617 T2475 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 805617 T2475 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 805618 T2475 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 805618 T2475 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 805619 T2475 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 805619 T2475 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 805620 T2475 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 805620 T2475 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4] 2> 805636 T2475 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 805637 T2475 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:48606/solr
[junit4] 2> 805637 T2475 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 805638 T2475 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 805641 T2495 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1b6d4488 name:ZooKeeperConnection Watcher:127.0.0.1:48606 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 805642 T2475 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 805657 T2475 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4] 2> 805667 T2475 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 805668 T2497 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@ce76d34 name:ZooKeeperConnection Watcher:127.0.0.1:48606/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 805669 T2475 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 805675 T2475 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 805679 T2475 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 805689 T2475 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 805691 T2475 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:48609_
[junit4] 2> 805697 T2475 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:48609_
[junit4] 2> 805700 T2475 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 805717 T2475 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 805719 T2475 oasc.Overseer.start Overseer (id=90095184146006019-127.0.0.1:48609_-n_0000000000) starting
[junit4] 2> 805731 T2475 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 805743 T2499 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 805743 T2475 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 805745 T2475 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 805747 T2475 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 805749 T2498 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 805753 T2500 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 805753 T2500 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 805754 T2500 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 807251 T2498 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 807252 T2498 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:48609_",
[junit4] 2> "base_url":"http://127.0.0.1:48609"}
[junit4] 2> 807252 T2498 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with numShards 1
[junit4] 2> 807252 T2498 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 807265 T2497 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> 807756 T2500 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 807756 T2500 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374743410716/collection1
[junit4] 2> 807756 T2500 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4] 2> 807757 T2500 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 807757 T2500 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4] 2> 807759 T2500 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374743410716/collection1/'
[junit4] 2> 807760 T2500 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374743410716/collection1/lib/classes/' to classloader
[junit4] 2> 807761 T2500 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374743410716/collection1/lib/README' to classloader
[junit4] 2> 807816 T2500 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4] 2> 807876 T2500 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 807978 T2500 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 807990 T2500 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 808605 T2500 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 808607 T2500 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 808607 T2500 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 808615 T2500 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 808618 T2500 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 808627 T2500 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 808631 T2500 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 808633 T2500 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 808634 T2500 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 808634 T2500 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 808634 T2500 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 808635 T2500 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 808635 T2500 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 808636 T2500 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 808636 T2500 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374743410716/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZkTest-1374743410424/control/data/
[junit4] 2> 808636 T2500 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@4d88a387
[junit4] 2> 808637 T2500 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374743410424/control/data
[junit4] 2> 808637 T2500 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZkTest-1374743410424/control/data/index/
[junit4] 2> 808637 T2500 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZkTest-1374743410424/control/data/index' doesn't exist. Creating new index...
[junit4] 2> 808637 T2500 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374743410424/control/data/index
[junit4] 2> 808641 T2500 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@18c450e1 lockFactory=org.apache.lucene.store.NativeFSLockFactory@284d817f),segFN=segments_1,generation=1}
[junit4] 2> 808641 T2500 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 808644 T2500 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 808644 T2500 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 808645 T2500 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 808645 T2500 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 808645 T2500 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 808646 T2500 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 808646 T2500 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 808646 T2500 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 808646 T2500 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 808653 T2500 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 808658 T2500 oass.SolrIndexSearcher.<init> Opening Searcher@1b3f4f07 main
[junit4] 2> 808659 T2500 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 808660 T2500 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 808662 T2501 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1b3f4f07 main{StandardDirectoryReader(segments_1:1)}
[junit4] 2> 808664 T2500 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 808664 T2500 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:48609 collection:control_collection shard:shard1
[junit4] 2> 808664 T2500 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=30000&socketTimeout=30000&retry=false
[junit4] 2> 808675 T2500 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4] 2> 808697 T2500 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 808700 T2500 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 808700 T2500 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 808700 T2500 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:48609/collection1/
[junit4] 2> 808700 T2500 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 808700 T2500 oasc.SyncStrategy.syncToMe http://127.0.0.1:48609/collection1/ has no replicas
[junit4] 2> 808701 T2500 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:48609/collection1/ shard1
[junit4] 2> 808701 T2500 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4] 2> 808768 T2498 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 808787 T2497 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> 808819 T2500 oasc.ZkController.register We are http://127.0.0.1:48609/collection1/ and leader is http://127.0.0.1:48609/collection1/
[junit4] 2> 808819 T2500 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:48609
[junit4] 2> 808819 T2500 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 808819 T2500 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 808819 T2500 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 808821 T2500 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 808822 T2475 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J0
[junit4] 2> 808823 T2475 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 808823 T2475 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 808830 T2475 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4] 2> 808831 T2475 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 808833 T2504 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@313b452d name:ZooKeeperConnection Watcher:127.0.0.1:48606/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 808833 T2475 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 808834 T2475 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 808835 T2475 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4] 2> 809011 T2475 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 809013 T2475 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:48616
[junit4] 2> 809014 T2475 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 809014 T2475 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 809014 T2475 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374743414320
[junit4] 2> 809015 T2475 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374743414320/'
[junit4] 2> 809041 T2475 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374743414320/solr.xml
[junit4] 2> 809089 T2475 oasc.CoreContainer.<init> New CoreContainer 1782851753
[junit4] 2> 809090 T2475 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374743414320/]
[junit4] 2> 809091 T2475 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 809091 T2475 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 809092 T2475 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 809092 T2475 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 809092 T2475 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 809093 T2475 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 809093 T2475 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 809093 T2475 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 809094 T2475 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 809094 T2475 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4] 2> 809105 T2475 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 809105 T2475 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:48606/solr
[junit4] 2> 809106 T2475 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 809107 T2475 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 809110 T2515 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@20c9a5c0 name:ZooKeeperConnection Watcher:127.0.0.1:48606 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 809111 T2475 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 809125 T2475 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4] 2> 809132 T2475 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 809134 T2517 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5ba6789 name:ZooKeeperConnection Watcher:127.0.0.1:48606/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 809134 T2475 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 809143 T2475 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 810145 T2475 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:48616_
[junit4] 2> 810147 T2475 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:48616_
[junit4] 2> 810150 T2504 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 810150 T2517 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 810150 T2497 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 810151 T2497 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> 810158 T2518 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 810158 T2518 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 810159 T2518 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 810291 T2498 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 810291 T2498 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:48609_",
[junit4] 2> "base_url":"http://127.0.0.1:48609"}
[junit4] 2> 810295 T2498 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:48616_",
[junit4] 2> "base_url":"http://127.0.0.1:48616"}
[junit4] 2> 810295 T2498 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with numShards 2
[junit4] 2> 810295 T2498 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 810307 T2504 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> 810307 T2497 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> 810307 T2517 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> 811161 T2518 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 811161 T2518 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374743414320/collection1
[junit4] 2> 811161 T2518 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 811162 T2518 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 811162 T2518 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 811164 T2518 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374743414320/collection1/'
[junit4] 2> 811165 T2518 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374743414320/collection1/lib/README' to classloader
[junit4] 2> 811166 T2518 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374743414320/collection1/lib/classes/' to classloader
[junit4] 2> 811230 T2518 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4] 2> 811290 T2518 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 811391 T2518 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 811403 T2518 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 812067 T2518 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 812068 T2518 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 812069 T2518 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 812083 T2518 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 812088 T2518 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 812101 T2518 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 812106 T2518 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 812111 T2518 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 812112 T2518 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 812112 T2518 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 812113 T2518 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 812113 T2518 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 812114 T2518 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 812114 T2518 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 812114 T2518 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374743414320/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZkTest-1374743410424/jetty1/
[junit4] 2> 812115 T2518 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@4d88a387
[junit4] 2> 812116 T2518 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374743410424/jetty1
[junit4] 2> 812116 T2518 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZkTest-1374743410424/jetty1/index/
[junit4] 2> 812116 T2518 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZkTest-1374743410424/jetty1/index' doesn't exist. Creating new index...
[junit4] 2> 812117 T2518 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374743410424/jetty1/index
[junit4] 2> 812121 T2518 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@3c921604 lockFactory=org.apache.lucene.store.NativeFSLockFactory@693fd48d),segFN=segments_1,generation=1}
[junit4] 2> 812121 T2518 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 812127 T2518 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 812127 T2518 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 812128 T2518 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 812128 T2518 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 812129 T2518 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 812129 T2518 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 812130 T2518 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 812131 T2518 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 812131 T2518 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 812142 T2518 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 812151 T2518 oass.SolrIndexSearcher.<init> Opening Searcher@49b1d8a9 main
[junit4] 2> 812152 T2518 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 812152 T2518 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 812157 T2519 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@49b1d8a9 main{StandardDirectoryReader(segments_1:1)}
[junit4] 2> 812159 T2518 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 812160 T2518 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:48616 collection:collection1 shard:shard1
[junit4] 2> 812160 T2518 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=30000&socketTimeout=30000&retry=false
[junit4] 2> 812176 T2518 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 812221 T2518 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 812231 T2518 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 812232 T2518 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 812232 T2518 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:48616/collection1/
[junit4] 2> 812232 T2518 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 812233 T2518 oasc.SyncStrategy.syncToMe http://127.0.0.1:48616/collection1/ has no replicas
[junit4] 2> 812233 T2518 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:48616/collection1/ shard1
[junit4] 2> 812233 T2518 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 813319 T2498 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 813491 T2517 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> 813491 T2504 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> 813491 T2497 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> 813520 T2518 oasc.ZkController.register We are http://127.0.0.1:48616/collection1/ and leader is http://127.0.0.1:48616/collection1/
[junit4] 2> 813520 T2518 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:48616
[junit4] 2> 813520 T2518 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 813520 T2518 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 813521 T2518 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 813523 T2518 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 813524 T2475 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J0
[junit4] 2> 813524 T2475 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 813525 T2475 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 813789 T2475 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 813793 T2475 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:48623
[junit4] 2> 813794 T2475 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 813794 T2475 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 813795 T2475 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374743419016
[junit4] 2> 813795 T2475 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374743419016/'
[junit4] 2> 813833 T2475 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374743419016/solr.xml
[junit4] 2> 813904 T2475 oasc.CoreContainer.<init> New CoreContainer 2012619686
[junit4] 2> 813905 T2475 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374743419016/]
[junit4] 2> 813907 T2475 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 813907 T2475 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 813908 T2475 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 813908 T2475 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 813909 T2475 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 813909 T2475 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 813910 T2475 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 813910 T2475 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 813911 T2475 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 813911 T2475 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4] 2> 813926 T2475 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 813927 T2475 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:48606/solr
[junit4] 2> 813927 T2475 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 813928 T2475 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 813938 T2531 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@409ea4d1 name:ZooKeeperConnection Watcher:127.0.0.1:48606 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 813939 T2475 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 813942 T2475 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4] 2> 813951 T2475 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 813953 T2533 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5e0fdd78 name:ZooKeeperConnection Watcher:127.0.0.1:48606/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 813954 T2475 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 813964 T2475 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 814967 T2475 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:48623_
[junit4] 2> 814995 T2475 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:48623_
[junit4] 2> 814999 T2517 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> 814999 T2504 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> 814999 T2497 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 815000 T2533 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 815000 T2497 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> 815000 T2504 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 815001 T2517 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 815009 T2498 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 815009 T2498 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:48616_",
[junit4] 2> "base_url":"http://127.0.0.1:48616"}
[junit4] 2> 815012 T2534 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 815013 T2534 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 815021 T2534 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 815022 T2498 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:48623_",
[junit4] 2> "base_url":"http://127.0.0.1:48623"}
[junit4] 2> 815022 T2498 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4] 2> 815022 T2498 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 815034 T2504 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> 815034 T2517 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> 815034 T2497 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> 815035 T2533 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> 816023 T2534 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 816023 T2534 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374743419016/collection1
[junit4] 2> 816023 T2534 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 816024 T2534 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 816024 T2534 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 816025 T2534 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374743419016/collection1/'
[junit4] 2> 816026 T2534 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374743419016/collection1/lib/classes/' to classloader
[junit4] 2> 816027 T2534 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374743419016/collection1/lib/README' to classloader
[junit4] 2> 816064 T2534 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4] 2> 816113 T2534 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 816214 T2534 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 816222 T2534 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 816645 T2534 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 816647 T2534 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 816647 T2534 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 816655 T2534 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 816658 T2534 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 816667 T2534 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 816671 T2534 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 816674 T2534 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 816674 T2534 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 816675 T2534 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 816675 T2534 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 816676 T2534 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 816676 T2534 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 816676 T2534 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 816676 T2534 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374743419016/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZkTest-1374743410424/jetty2/
[junit4] 2> 816676 T2534 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@4d88a387
[junit4] 2> 816677 T2534 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374743410424/jetty2
[junit4] 2> 816677 T2534 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZkTest-1374743410424/jetty2/index/
[junit4] 2> 816678 T2534 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZkTest-1374743410424/jetty2/index' doesn't exist. Creating new index...
[junit4] 2> 816678 T2534 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374743410424/jetty2/index
[junit4] 2> 816680 T2534 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@475d2300 lockFactory=org.apache.lucene.store.NativeFSLockFactory@4c62ecc6),segFN=segments_1,generation=1}
[junit4] 2> 816681 T2534 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 816684 T2534 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 816685 T2534 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 816685 T2534 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 816686 T2534 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 816686 T2534 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 816686 T2534 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 816686 T2534 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 816687 T2534 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 816687 T2534 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 816693 T2534 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 816698 T2534 oass.SolrIndexSearcher.<init> Opening Searcher@579ef6a3 main
[junit4] 2> 816699 T2534 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 816699 T2534 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 816703 T2535 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@579ef6a3 main{StandardDirectoryReader(segments_1:1)}
[junit4] 2> 816704 T2534 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 816704 T2534 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:48623 collection:collection1 shard:shard2
[junit4] 2> 816705 T2534 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=30000&socketTimeout=30000&retry=false
[junit4] 2> 816715 T2534 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4] 2> 816731 T2534 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
[junit4] 2> 816733 T2534 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 816734 T2534 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 816734 T2534 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:48623/collection1/
[junit4] 2> 816734 T2534 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 816734 T2534 oasc.SyncStrategy.syncToMe http://127.0.0.1:48623/collection1/ has no replicas
[junit4] 2> 816734 T2534 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:48623/collection1/ shard2
[junit4] 2> 816734 T2534 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4] 2> 818042 T2498 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 818057 T2517 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> 818057 T2533 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> 818057 T2504 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> 818057 T2497 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> 818115 T2534 oasc.ZkController.register We are http://127.0.0.1:48623/collection1/ and leader is http://127.0.0.1:48623/collection1/
[junit4] 2> 818115 T2534 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:48623
[junit4] 2> 818115 T2534 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 818115 T2534 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 818115 T2534 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 818117 T2534 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 818117 T2475 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J0
[junit4] 2> 818118 T2475 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 818118 T2475 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 818310 T2475 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 818313 T2475 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:37770
[junit4] 2> 818313 T2475 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 818314 T2475 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 818314 T2475 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374743423610
[junit4] 2> 818314 T2475 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374743423610/'
[junit4] 2> 818341 T2475 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374743423610/solr.xml
[junit4] 2> 818397 T2475 oasc.CoreContainer.<init> New CoreContainer 1878566879
[junit4] 2> 818398 T2475 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374743423610/]
[junit4] 2> 818399 T2475 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 818400 T2475 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 818400 T2475 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 818400 T2475 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 818401 T2475 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 818401 T2475 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 818401 T2475 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 818401 T2475 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 818402 T2475 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 818402 T2475 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4] 2> 818412 T2475 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 818413 T2475 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:48606/solr
[junit4] 2> 818413 T2475 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 818414 T2475 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 818416 T2547 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2dd55ae7 name:ZooKeeperConnection Watcher:127.0.0.1:48606 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 818417 T2475 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 818430 T2475 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4] 2> 818437 T2475 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 818438 T2549 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2ceea07f name:ZooKeeperConnection Watcher:127.0.0.1:48606/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 818438 T2475 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 818447 T2475 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 819449 T2475 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:37770_
[junit4] 2> 819451 T2475 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:37770_
[junit4] 2> 819453 T2517 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> 819453 T2504 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> 819453 T2497 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 819453 T2533 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> 819453 T2497 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> 819453 T2549 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 819454 T2517 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 819463 T2504 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 819463 T2533 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 819467 T2550 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 819467 T2550 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 819468 T2550 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 819567 T2498 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 819568 T2498 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:48623_",
[junit4] 2> "base_url":"http://127.0.0.1:48623"}
[junit4] 2> 819572 T2498 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:37770_",
[junit4] 2> "base_url":"http://127.0.0.1:37770"}
[junit4] 2> 819572 T2498 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4] 2> 819572 T2498 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 819584 T2517 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> 819584 T2549 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> 819584 T2497 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> 819584 T2504 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> 819584 T2533 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> 820469 T2550 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 820469 T2550 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374743423610/collection1
[junit4] 2> 820470 T2550 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 820470 T2550 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 820471 T2550 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 820472 T2550 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374743423610/collection1/'
[junit4] 2> 820474 T2550 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374743423610/collection1/lib/README' to classloader
[junit4] 2> 820474 T2550 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374743423610/collection1/lib/classes/' to classloader
[junit4] 2> 820529 T2550 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4] 2> 820590 T2550 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 820691 T2550 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 820699 T2550 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 821142 T2550 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 821143 T2550 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 821144 T2550 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 821154 T2550 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 821157 T2550 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 821171 T2550 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 821175 T2550 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 821179 T2550 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 821180 T2550 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 821180 T2550 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 821181 T2550 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 821181 T2550 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 821182 T2550 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 821182 T2550 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 821182 T2550 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374743423610/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZkTest-1374743410424/jetty3/
[junit4] 2> 821182 T2550 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@4d88a387
[junit4] 2> 821183 T2550 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374743410424/jetty3
[junit4] 2> 821183 T2550 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZkTest-1374743410424/jetty3/index/
[junit4] 2> 821184 T2550 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZkTest-1374743410424/jetty3/index' doesn't exist. Creating new index...
[junit4] 2> 821184 T2550 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374743410424/jetty3/index
[junit4] 2> 821186 T2550 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@2ff5256c lockFactory=org.apache.lucene.store.NativeFSLockFactory@4061f5db),segFN=segments_1,generation=1}
[junit4] 2> 821187 T2550 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 821190 T2550 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 821191 T2550 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 821191 T2550 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 821192 T2550 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 821192 T2550 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 821192 T2550 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 821193 T2550 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 821193 T2550 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 821194 T2550 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 821200 T2550 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 821205 T2550 oass.SolrIndexSearcher.<init> Opening Searcher@44766b2e main
[junit4] 2> 821206 T2550 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 821207 T2550 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 821210 T2551 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@44766b2e main{StandardDirectoryReader(segments_1:1)}
[junit4] 2> 821212 T2550 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 821212 T2550 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:37770 collection:collection1 shard:shard1
[junit4] 2> 821212 T2550 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=30000&socketTimeout=30000&retry=false
[junit4] 2> 821224 T2550 oasc.ZkController.register We are http://127.0.0.1:37770/collection1/ and leader is http://127.0.0.1:48616/collection1/
[junit4] 2> 821224 T2550 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:37770
[junit4] 2> 821224 T2550 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4] 2> 821224 T2550 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4] 2> ASYNC NEW_CORE C763 name=collection1 org.apache.solr.core.SolrCore@6be8e949 url=http://127.0.0.1:37770/collection1 node=127.0.0.1:37770_ C763_STATE=coll:collection1 core:collection1 props:{state=down, core=collection1, node_name=127.0.0.1:37770_, base_url=http://127.0.0.1:37770}
[junit4] 2> 821225 T2552 C763 P37770 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4] 2> 821225 T2550 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 821225 T2552 C763 P37770 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4] 2> 821226 T2552 C763 P37770 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4] 2> 821226 T2552 C763 P37770 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 821226 T2475 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J0
[junit4] 2> 821226 T2475 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 821227 T2475 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 821256 T2552 C763 P37770 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 821263 T2507 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: core_node3, state: recovering, checkLive: true, onlyIfLeader: true
[junit4] 2> 821404 T2475 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 821406 T2475 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:49412
[junit4] 2> 821407 T2475 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 821407 T2475 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 821407 T2475 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty4-1374743426718
[junit4] 2> 821408 T2475 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty4-1374743426718/'
[junit4] 2> 821433 T2475 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty4-1374743426718/solr.xml
[junit4] 2> 821481 T2475 oasc.CoreContainer.<init> New CoreContainer 1910288505
[junit4] 2> 821481 T2475 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty4-1374743426718/]
[junit4] 2> 821483 T2475 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 821483 T2475 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 821483 T2475 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 821483 T2475 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 821484 T2475 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 821484 T2475 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 821484 T2475 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 821485 T2475 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 821485 T2475 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 821485 T2475 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4] 2> 821495 T2475 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 821496 T2475 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:48606/solr
[junit4] 2> 821496 T2475 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 821497 T2475 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 821504 T2564 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4fc61255 name:ZooKeeperConnection Watcher:127.0.0.1:48606 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 821505 T2475 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 821516 T2475 oascsi.HttpClientUtil.createClient Creating new http client, config:ma
[...truncated too long message...]
ttp.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:1146)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
[junit4] 2> at java.lang.Thread.run(Thread.java:679)
[junit4] 2> NOTE: test params are: codec=Appending, sim=RandomSimilarityProvider(queryNorm=true,coord=crazy): {}, locale=it, timezone=HST
[junit4] 2> NOTE: FreeBSD 9.1-RELEASE-p3 amd64/Sun Microsystems Inc. 1.6.0_32 (64-bit)/cpus=16,threads=2,free=75883888,total=455016448
[junit4] 2> NOTE: All tests run in this JVM: [FastVectorHighlighterTest, TestGroupingSearch, TestBadConfig, TestLRUCache, AutoCommitTest, BasicFunctionalityTest, TestDocSet, StatelessScriptUpdateProcessorFactoryTest, SliceStateUpdateTest, AddSchemaFieldsUpdateProcessorFactoryTest, TestRandomDVFaceting, PeerSyncTest, TestPluginEnable, ShowFileRequestHandlerTest, QueryElevationComponentTest, AnalysisAfterCoreReloadTest, TestWriterPerf, ChaosMonkeyNothingIsSafeTest, HdfsRecoveryZkTest, ShardRoutingTest, SchemaVersionSpecificBehaviorTest, HdfsDirectoryTest, FileBasedSpellCheckerTest, UUIDFieldTest, LukeRequestHandlerTest, TestValueSourceCache, ClusterStateUpdateTest, DirectSolrConnectionTest, RegexBoostProcessorTest, DateFieldTest, TestLMDirichletSimilarityFactory, OverseerCollectionProcessorTest, IndexSchemaTest, TestQueryUtils, TestCharFilters, WordBreakSolrSpellCheckerTest, HdfsChaosMonkeySafeLeaderTest, SliceStateTest, DistributedQueryElevationComponentTest, ExternalFileFieldSortTest, TestJoin, TestPerFieldSimilarity, CoreAdminHandlerTest, ResourceLoaderTest, TestFaceting, TestExtendedDismaxParser, ZkCLITest, HdfsBasicDistributedZkTest, MoreLikeThisHandlerTest, UpdateRequestProcessorFactoryTest, LeaderElectionTest, TestPseudoReturnFields, SpatialFilterTest, TestSolrCoreProperties, TestSurroundQueryParser, TestSweetSpotSimilarityFactory, TestSort, TestFieldTypeResource, TestUniqueKeyFieldResource, BadComponentTest, ParsingFieldUpdateProcessorsTest, RAMDirectoryFactoryTest, QueryParsingTest, OverseerTest, TestMaxScoreQueryParser, TestQuerySenderListener, ScriptEngineTest, JsonLoaderTest, PolyFieldTest, TestCloudManagedSchemaAddField, TestFastLRUCache, TestManagedSchemaFieldResource, SolrIndexSplitterTest, CircularListTest, TestSolrIndexConfig, FieldMutatingUpdateProcessorTest, SuggesterTest, BasicDistributedZkTest]
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=BasicDistributedZkTest -Dtests.seed=C420AC0720679321 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=it -Dtests.timezone=HST -Dtests.file.encoding=ISO8859-1
[junit4] ERROR 0.00s J0 | BasicDistributedZkTest (suite) <<<
[junit4] > Throwable #1: com.carrotsearch.randomizedtesting.ThreadLeakError: 1 thread leaked from SUITE scope at org.apache.solr.cloud.BasicDistributedZkTest:
[junit4] > 1) Thread[id=2934, name=recoveryCmdExecutor-1117-thread-1, state=RUNNABLE, group=TGRP-BasicDistributedZkTest]
[junit4] > at java.net.PlainSocketImpl.socketConnect(Native Method)
[junit4] > at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:327)
[junit4] > at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:193)
[junit4] > at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:180)
[junit4] > at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:384)
[junit4] > at java.net.Socket.connect(Socket.java:546)
[junit4] > at org.apache.http.conn.scheme.PlainSocketFactory.connectSocket(PlainSocketFactory.java:127)
[junit4] > at org.apache.http.impl.conn.DefaultClientConnectionOperator.openConnection(DefaultClientConnectionOperator.java:180)
[junit4] > at org.apache.http.impl.conn.ManagedClientConnectionImpl.open(ManagedClientConnectionImpl.java:294)
[junit4] > at org.apache.http.impl.client.DefaultRequestDirector.tryConnect(DefaultRequestDirector.java:645)
[junit4] > at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:480)
[junit4] > at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:906)
[junit4] > at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:805)
[junit4] > at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:784)
[junit4] > at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:365)
[junit4] > at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:180)
[junit4] > at org.apache.solr.cloud.SyncStrategy$1.run(SyncStrategy.java:291)
[junit4] > at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1146)
[junit4] > at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
[junit4] > at java.lang.Thread.run(Thread.java:679)
[junit4] > at __randomizedtesting.SeedInfo.seed([C420AC0720679321]:0)Throwable #2: com.carrotsearch.randomizedtesting.ThreadLeakError: There are still zombie threads that couldn't be terminated:
[junit4] > 1) Thread[id=2934, name=recoveryCmdExecutor-1117-thread-1, state=RUNNABLE, group=TGRP-BasicDistributedZkTest]
[junit4] > at java.net.PlainSocketImpl.socketConnect(Native Method)
[junit4] > at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:327)
[junit4] > at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:193)
[junit4] > at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:180)
[junit4] > at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:384)
[junit4] > at java.net.Socket.connect(Socket.java:546)
[junit4] > at org.apache.http.conn.scheme.PlainSocketFactory.connectSocket(PlainSocketFactory.java:127)
[junit4] > at org.apache.http.impl.conn.DefaultClientConnectionOperator.openConnection(DefaultClientConnectionOperator.java:180)
[junit4] > at org.apache.http.impl.conn.ManagedClientConnectionImpl.open(ManagedClientConnectionImpl.java:294)
[junit4] > at org.apache.http.impl.client.DefaultRequestDirector.tryConnect(DefaultRequestDirector.java:645)
[junit4] > at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:480)
[junit4] > at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:906)
[junit4] > at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:805)
[junit4] > at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:784)
[junit4] > at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:365)
[junit4] > at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:180)
[junit4] > at org.apache.solr.cloud.SyncStrategy$1.run(SyncStrategy.java:291)
[junit4] > at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1146)
[junit4] > at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
[junit4] > at java.lang.Thread.run(Thread.java:679)
[junit4] > at __randomizedtesting.SeedInfo.seed([C420AC0720679321]:0)
[junit4] Completed on J0 in 229.17s, 1 test, 2 errors <<< FAILURES!
[...truncated 581 lines...]
BUILD FAILED
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/build.xml:395: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/build.xml:375: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/build.xml:39: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build.xml:181: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/common-build.xml:449: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/lucene/common-build.xml:1250: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/lucene/common-build.xml:893: There were test failures: 317 suites, 1337 tests, 2 suite-level errors, 659 ignored (5 assumptions)
Total time: 42 minutes 48 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure