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/19 12:27:57 UTC
[JENKINS] Lucene-Solr-Tests-trunk-Java7 - Build # 4156 - Still
Failing
Build: https://builds.apache.org/job/Lucene-Solr-Tests-trunk-Java7/4156/
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=2191, name=recoveryCmdExecutor-1277-thread-1, state=RUNNABLE, group=TGRP-BasicDistributedZkTest] at java.net.PlainSocketImpl.socketConnect(Native Method) at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:339) at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:200) at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:182) at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:391) at java.net.Socket.connect(Socket.java:579) at org.apache.http.conn.scheme.PlainSocketFactory.connectSocket(PlainSocketFactory.java:127) at org.apache.http.impl.conn.DefaultClientConnectionOperator.openConnection(DefaultClientConnectionOperator.java:180) at org.apache.http.impl.conn.ManagedClientConnectionImpl.open(ManagedClientConnectionImpl.java:294) at org.apache.http.impl.client.DefaultRequestDirector.tryConnect(DefaultRequestDirector.java:645) at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:480) at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:906) at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:805) at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:784) at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:365) at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:180) at org.apache.solr.cloud.SyncStrategy$1.run(SyncStrategy.java:291) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) at java.lang.Thread.run(Thread.java:722)
Stack Trace:
com.carrotsearch.randomizedtesting.ThreadLeakError: 1 thread leaked from SUITE scope at org.apache.solr.cloud.BasicDistributedZkTest:
1) Thread[id=2191, name=recoveryCmdExecutor-1277-thread-1, state=RUNNABLE, group=TGRP-BasicDistributedZkTest]
at java.net.PlainSocketImpl.socketConnect(Native Method)
at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:339)
at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:200)
at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:182)
at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:391)
at java.net.Socket.connect(Socket.java:579)
at org.apache.http.conn.scheme.PlainSocketFactory.connectSocket(PlainSocketFactory.java:127)
at org.apache.http.impl.conn.DefaultClientConnectionOperator.openConnection(DefaultClientConnectionOperator.java:180)
at org.apache.http.impl.conn.ManagedClientConnectionImpl.open(ManagedClientConnectionImpl.java:294)
at org.apache.http.impl.client.DefaultRequestDirector.tryConnect(DefaultRequestDirector.java:645)
at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:480)
at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:906)
at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:805)
at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:784)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:365)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:180)
at org.apache.solr.cloud.SyncStrategy$1.run(SyncStrategy.java:291)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:722)
at __randomizedtesting.SeedInfo.seed([CD7E1ABE224415F8]: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=2191, name=recoveryCmdExecutor-1277-thread-1, state=RUNNABLE, group=TGRP-BasicDistributedZkTest] at java.net.PlainSocketImpl.socketConnect(Native Method) at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:339) at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:200) at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:182) at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:391) at java.net.Socket.connect(Socket.java:579) at org.apache.http.conn.scheme.PlainSocketFactory.connectSocket(PlainSocketFactory.java:127) at org.apache.http.impl.conn.DefaultClientConnectionOperator.openConnection(DefaultClientConnectionOperator.java:180) at org.apache.http.impl.conn.ManagedClientConnectionImpl.open(ManagedClientConnectionImpl.java:294) at org.apache.http.impl.client.DefaultRequestDirector.tryConnect(DefaultRequestDirector.java:645) at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:480) at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:906) at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:805) at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:784) at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:365) at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:180) at org.apache.solr.cloud.SyncStrategy$1.run(SyncStrategy.java:291) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) at java.lang.Thread.run(Thread.java:722)
Stack Trace:
com.carrotsearch.randomizedtesting.ThreadLeakError: There are still zombie threads that couldn't be terminated:
1) Thread[id=2191, name=recoveryCmdExecutor-1277-thread-1, state=RUNNABLE, group=TGRP-BasicDistributedZkTest]
at java.net.PlainSocketImpl.socketConnect(Native Method)
at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:339)
at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:200)
at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:182)
at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:391)
at java.net.Socket.connect(Socket.java:579)
at org.apache.http.conn.scheme.PlainSocketFactory.connectSocket(PlainSocketFactory.java:127)
at org.apache.http.impl.conn.DefaultClientConnectionOperator.openConnection(DefaultClientConnectionOperator.java:180)
at org.apache.http.impl.conn.ManagedClientConnectionImpl.open(ManagedClientConnectionImpl.java:294)
at org.apache.http.impl.client.DefaultRequestDirector.tryConnect(DefaultRequestDirector.java:645)
at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:480)
at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:906)
at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:805)
at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:784)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:365)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:180)
at org.apache.solr.cloud.SyncStrategy$1.run(SyncStrategy.java:291)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:722)
at __randomizedtesting.SeedInfo.seed([CD7E1ABE224415F8]:0)
Build Log:
[...truncated 9683 lines...]
[junit4] Suite: org.apache.solr.cloud.BasicDistributedZkTest
[junit4] 2> 696417 T1699 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
[junit4] 2> 696423 T1699 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4] 2> Creating dataDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./solrtest-BasicDistributedZkTest-1374228757340
[junit4] 2> 696425 T1699 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 696426 T1700 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 696527 T1699 oasc.ZkTestServer.run start zk server on port:44209
[junit4] 2> 696528 T1699 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 696537 T1706 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@27d5c17e name:ZooKeeperConnection Watcher:127.0.0.1:44209 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 696537 T1699 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 696538 T1699 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 696551 T1699 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 696554 T1708 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@55a5d368 name:ZooKeeperConnection Watcher:127.0.0.1:44209/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 696554 T1699 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 696555 T1699 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4] 2> 696565 T1699 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4] 2> 696568 T1699 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4] 2> 696571 T1699 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4] 2> 696575 T1699 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4] 2> 696576 T1699 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4] 2> 696587 T1699 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
[junit4] 2> 696588 T1699 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4] 2> 696697 T1699 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4] 2> 696698 T1699 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4] 2> 696703 T1699 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4] 2> 696703 T1699 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4] 2> 696707 T1699 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4] 2> 696708 T1699 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4] 2> 696711 T1699 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4] 2> 696712 T1699 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4] 2> 696716 T1699 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 696717 T1699 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 696720 T1699 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4] 2> 696721 T1699 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4] 2> 696725 T1699 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4] 2> 696725 T1699 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4] 2> 697004 T1699 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 697009 T1699 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:45450
[junit4] 2> 697010 T1699 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 697010 T1699 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 697011 T1699 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374228757646
[junit4] 2> 697011 T1699 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374228757646/'
[junit4] 2> 697051 T1699 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374228757646/solr.xml
[junit4] 2> 697144 T1699 oasc.CoreContainer.<init> New CoreContainer 374754549
[junit4] 2> 697145 T1699 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374228757646/]
[junit4] 2> 697147 T1699 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 697147 T1699 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 697148 T1699 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 697148 T1699 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 697149 T1699 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 697149 T1699 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 697150 T1699 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 697151 T1699 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 697151 T1699 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 697152 T1699 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4] 2> 697168 T1699 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 697169 T1699 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:44209/solr
[junit4] 2> 697169 T1699 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 697170 T1699 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 697174 T1719 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5edf9ef0 name:ZooKeeperConnection Watcher:127.0.0.1:44209 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 697174 T1699 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 697185 T1699 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4] 2> 697196 T1699 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 697199 T1721 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5ee94c7f name:ZooKeeperConnection Watcher:127.0.0.1:44209/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 697199 T1699 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 697202 T1699 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 697212 T1699 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 697216 T1699 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 697219 T1699 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:45450_
[junit4] 2> 697226 T1699 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:45450_
[junit4] 2> 697231 T1699 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 697244 T1699 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 697253 T1699 oasc.Overseer.start Overseer (id=90061455841492995-127.0.0.1:45450_-n_0000000000) starting
[junit4] 2> 697259 T1699 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 697271 T1723 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 697272 T1699 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 697276 T1699 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 697278 T1699 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 697282 T1722 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 697289 T1724 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 697289 T1724 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 697291 T1724 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 698787 T1722 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 698788 T1722 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:45450_",
[junit4] 2> "base_url":"http://127.0.0.1:45450"}
[junit4] 2> 698789 T1722 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with numShards 1
[junit4] 2> 698789 T1722 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 698803 T1721 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> 699293 T1724 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 699293 T1724 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374228757646/collection1
[junit4] 2> 699293 T1724 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4] 2> 699294 T1724 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 699295 T1724 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4] 2> 699296 T1724 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374228757646/collection1/'
[junit4] 2> 699297 T1724 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374228757646/collection1/lib/README' to classloader
[junit4] 2> 699298 T1724 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374228757646/collection1/lib/classes/' to classloader
[junit4] 2> 699357 T1724 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 699421 T1724 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 699522 T1724 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 699534 T1724 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 700198 T1724 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 700211 T1724 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 700215 T1724 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 700232 T1724 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 700238 T1724 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 700259 T1724 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 700261 T1724 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 700261 T1724 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 700262 T1724 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 700263 T1724 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 700263 T1724 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 700264 T1724 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 700264 T1724 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374228757646/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZkTest-1374228757339/control/data/
[junit4] 2> 700264 T1724 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@24d0bcec
[junit4] 2> 700266 T1724 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374228757339/control/data
[junit4] 2> 700266 T1724 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZkTest-1374228757339/control/data/index/
[junit4] 2> 700266 T1724 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZkTest-1374228757339/control/data/index' doesn't exist. Creating new index...
[junit4] 2> 700267 T1724 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374228757339/control/data/index
[junit4] 2> 700271 T1724 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@7540064f lockFactory=org.apache.lucene.store.NativeFSLockFactory@6293b190),segFN=segments_1,generation=1}
[junit4] 2> 700272 T1724 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 700277 T1724 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 700277 T1724 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 700278 T1724 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 700279 T1724 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 700279 T1724 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 700280 T1724 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 700280 T1724 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 700281 T1724 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 700281 T1724 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 700297 T1724 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 700305 T1724 oass.SolrIndexSearcher.<init> Opening Searcher@3a76ef83 main
[junit4] 2> 700307 T1724 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 700307 T1724 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 700311 T1725 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@3a76ef83 main{StandardDirectoryReader(segments_1:1)}
[junit4] 2> 700313 T1724 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 700313 T1724 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:45450 collection:control_collection shard:shard1
[junit4] 2> 700313 T1724 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=30000&socketTimeout=30000&retry=false
[junit4] 2> 700331 T1724 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4] 2> 700418 T1724 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 700475 T1724 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 700476 T1724 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 700476 T1724 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:45450/collection1/
[junit4] 2> 700476 T1724 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 700476 T1724 oasc.SyncStrategy.syncToMe http://127.0.0.1:45450/collection1/ has no replicas
[junit4] 2> 700477 T1724 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:45450/collection1/ shard1
[junit4] 2> 700477 T1724 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4] 2> 701811 T1722 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 701836 T1721 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> 701870 T1724 oasc.ZkController.register We are http://127.0.0.1:45450/collection1/ and leader is http://127.0.0.1:45450/collection1/
[junit4] 2> 701870 T1724 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:45450
[junit4] 2> 701870 T1724 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 701870 T1724 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 701871 T1724 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 701873 T1724 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 701874 T1699 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0
[junit4] 2> 701875 T1699 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 701875 T1699 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 701886 T1699 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4] 2> 701887 T1699 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 701890 T1728 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@78508f6e name:ZooKeeperConnection Watcher:127.0.0.1:44209/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 701890 T1699 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 701892 T1699 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 701895 T1699 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4] 2> 702183 T1699 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 702186 T1699 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:59037
[junit4] 2> 702187 T1699 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 702188 T1699 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 702188 T1699 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374228762811
[junit4] 2> 702189 T1699 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374228762811/'
[junit4] 2> 702229 T1699 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374228762811/solr.xml
[junit4] 2> 702322 T1699 oasc.CoreContainer.<init> New CoreContainer 276006115
[junit4] 2> 702323 T1699 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374228762811/]
[junit4] 2> 702325 T1699 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 702325 T1699 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 702326 T1699 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 702326 T1699 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 702327 T1699 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 702327 T1699 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 702328 T1699 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 702328 T1699 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 702329 T1699 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 702330 T1699 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4] 2> 702345 T1699 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 702346 T1699 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:44209/solr
[junit4] 2> 702347 T1699 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 702348 T1699 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 702351 T1739 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@39e76774 name:ZooKeeperConnection Watcher:127.0.0.1:44209 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 702351 T1699 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 702354 T1699 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4] 2> 702365 T1699 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 702367 T1741 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@aba0a5b name:ZooKeeperConnection Watcher:127.0.0.1:44209/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 702367 T1699 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 702379 T1699 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 703349 T1722 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 703350 T1722 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:45450_",
[junit4] 2> "base_url":"http://127.0.0.1:45450"}
[junit4] 2> 703367 T1728 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> 703367 T1721 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> 703367 T1741 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> 703383 T1699 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:59037_
[junit4] 2> 703385 T1699 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:59037_
[junit4] 2> 703388 T1741 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 1)
[junit4] 2> 703389 T1728 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 703389 T1721 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 703389 T1728 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> 703389 T1721 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> 703390 T1741 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 703398 T1742 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 703399 T1742 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 703400 T1742 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 704874 T1722 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 704875 T1722 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:59037_",
[junit4] 2> "base_url":"http://127.0.0.1:59037"}
[junit4] 2> 704876 T1722 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with numShards 2
[junit4] 2> 704876 T1722 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 704892 T1728 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> 704892 T1721 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> 704892 T1741 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> 705403 T1742 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 705403 T1742 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374228762811/collection1
[junit4] 2> 705404 T1742 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 705405 T1742 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 705405 T1742 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 705406 T1742 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374228762811/collection1/'
[junit4] 2> 705408 T1742 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374228762811/collection1/lib/README' to classloader
[junit4] 2> 705408 T1742 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374228762811/collection1/lib/classes/' to classloader
[junit4] 2> 705467 T1742 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 705531 T1742 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 705633 T1742 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 705645 T1742 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 706321 T1742 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 706334 T1742 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 706339 T1742 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 706355 T1742 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 706360 T1742 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 706365 T1742 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 706366 T1742 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 706367 T1742 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 706367 T1742 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 706368 T1742 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 706369 T1742 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 706369 T1742 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 706369 T1742 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374228762811/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZkTest-1374228757339/jetty1/
[junit4] 2> 706370 T1742 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@24d0bcec
[junit4] 2> 706371 T1742 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374228757339/jetty1
[junit4] 2> 706371 T1742 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZkTest-1374228757339/jetty1/index/
[junit4] 2> 706371 T1742 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZkTest-1374228757339/jetty1/index' doesn't exist. Creating new index...
[junit4] 2> 706372 T1742 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374228757339/jetty1/index
[junit4] 2> 706376 T1742 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@6fbbdb28 lockFactory=org.apache.lucene.store.NativeFSLockFactory@6b80debb),segFN=segments_1,generation=1}
[junit4] 2> 706376 T1742 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 706382 T1742 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 706383 T1742 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 706383 T1742 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 706384 T1742 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 706385 T1742 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 706385 T1742 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 706386 T1742 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 706386 T1742 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 706387 T1742 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 706403 T1742 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 706411 T1742 oass.SolrIndexSearcher.<init> Opening Searcher@12ca433c main
[junit4] 2> 706412 T1742 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 706412 T1742 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 706417 T1743 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@12ca433c main{StandardDirectoryReader(segments_1:1)}
[junit4] 2> 706420 T1742 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 706420 T1742 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:59037 collection:collection1 shard:shard1
[junit4] 2> 706420 T1742 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=30000&socketTimeout=30000&retry=false
[junit4] 2> 706438 T1742 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 706486 T1742 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 706496 T1742 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 706497 T1742 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 706497 T1742 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:59037/collection1/
[junit4] 2> 706497 T1742 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 706498 T1742 oasc.SyncStrategy.syncToMe http://127.0.0.1:59037/collection1/ has no replicas
[junit4] 2> 706498 T1742 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:59037/collection1/ shard1
[junit4] 2> 706498 T1742 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 707900 T1722 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 707919 T1728 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> 707919 T1721 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> 707919 T1741 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> 707942 T1742 oasc.ZkController.register We are http://127.0.0.1:59037/collection1/ and leader is http://127.0.0.1:59037/collection1/
[junit4] 2> 707942 T1742 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:59037
[junit4] 2> 707942 T1742 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 707943 T1742 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 707943 T1742 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 707945 T1742 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 707946 T1699 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0
[junit4] 2> 707947 T1699 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 707947 T1699 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 708234 T1699 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 708238 T1699 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:15366
[junit4] 2> 708238 T1699 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 708239 T1699 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 708240 T1699 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374228768872
[junit4] 2> 708240 T1699 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374228768872/'
[junit4] 2> 708279 T1699 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374228768872/solr.xml
[junit4] 2> 708371 T1699 oasc.CoreContainer.<init> New CoreContainer 1844267783
[junit4] 2> 708372 T1699 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374228768872/]
[junit4] 2> 708374 T1699 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 708375 T1699 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 708375 T1699 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 708376 T1699 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 708376 T1699 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 708377 T1699 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 708377 T1699 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 708378 T1699 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 708378 T1699 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 708379 T1699 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4] 2> 708394 T1699 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 708395 T1699 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:44209/solr
[junit4] 2> 708396 T1699 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 708397 T1699 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 708400 T1755 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@319e02e7 name:ZooKeeperConnection Watcher:127.0.0.1:44209 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 708401 T1699 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 708414 T1699 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4] 2> 708425 T1699 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 708427 T1757 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@51254f93 name:ZooKeeperConnection Watcher:127.0.0.1:44209/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 708427 T1699 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 708437 T1699 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 709426 T1722 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 709427 T1722 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:59037_",
[junit4] 2> "base_url":"http://127.0.0.1:59037"}
[junit4] 2> 709442 T1757 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> 709443 T1721 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> 709443 T1699 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:15366_
[junit4] 2> 709443 T1741 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> 709442 T1728 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> 709451 T1699 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:15366_
[junit4] 2> 709454 T1757 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> 709454 T1741 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> 709454 T1728 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 709454 T1721 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 709454 T1728 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> 709455 T1721 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> 709456 T1757 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 709456 T1741 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 709464 T1758 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 709465 T1758 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 709466 T1758 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 710954 T1722 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 710955 T1722 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:15366_",
[junit4] 2> "base_url":"http://127.0.0.1:15366"}
[junit4] 2> 710956 T1722 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4] 2> 710956 T1722 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 710975 T1728 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> 710975 T1721 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> 710975 T1741 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> 710975 T1757 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> 711469 T1758 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 711469 T1758 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374228768872/collection1
[junit4] 2> 711469 T1758 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 711470 T1758 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 711470 T1758 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 711472 T1758 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374228768872/collection1/'
[junit4] 2> 711473 T1758 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374228768872/collection1/lib/README' to classloader
[junit4] 2> 711474 T1758 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374228768872/collection1/lib/classes/' to classloader
[junit4] 2> 711532 T1758 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 711596 T1758 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 711698 T1758 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 711710 T1758 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 712389 T1758 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 712402 T1758 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 712406 T1758 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 712422 T1758 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 712427 T1758 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 712432 T1758 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 712433 T1758 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 712434 T1758 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 712434 T1758 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 712435 T1758 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 712435 T1758 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 712436 T1758 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 712436 T1758 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374228768872/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZkTest-1374228757339/jetty2/
[junit4] 2> 712437 T1758 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@24d0bcec
[junit4] 2> 712438 T1758 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374228757339/jetty2
[junit4] 2> 712438 T1758 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZkTest-1374228757339/jetty2/index/
[junit4] 2> 712438 T1758 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZkTest-1374228757339/jetty2/index' doesn't exist. Creating new index...
[junit4] 2> 712439 T1758 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374228757339/jetty2/index
[junit4] 2> 712443 T1758 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@68ad180d lockFactory=org.apache.lucene.store.NativeFSLockFactory@674525e1),segFN=segments_1,generation=1}
[junit4] 2> 712443 T1758 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 712449 T1758 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 712450 T1758 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 712450 T1758 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 712451 T1758 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 712452 T1758 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 712452 T1758 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 712453 T1758 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 712453 T1758 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 712454 T1758 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 712469 T1758 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 712476 T1758 oass.SolrIndexSearcher.<init> Opening Searcher@7adcc6c2 main
[junit4] 2> 712477 T1758 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 712478 T1758 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 712482 T1759 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@7adcc6c2 main{StandardDirectoryReader(segments_1:1)}
[junit4] 2> 712484 T1758 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 712485 T1758 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:15366 collection:collection1 shard:shard2
[junit4] 2> 712485 T1758 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=30000&socketTimeout=30000&retry=false
[junit4] 2> 712501 T1758 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4] 2> 712519 T1758 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
[junit4] 2> 712528 T1758 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 712529 T1758 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 712529 T1758 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:15366/collection1/
[junit4] 2> 712529 T1758 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 712530 T1758 oasc.SyncStrategy.syncToMe http://127.0.0.1:15366/collection1/ has no replicas
[junit4] 2> 712530 T1758 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:15366/collection1/ shard2
[junit4] 2> 712530 T1758 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4] 2> 713982 T1722 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 714003 T1757 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> 714003 T1721 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> 714003 T1741 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> 714003 T1728 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> 714023 T1758 oasc.ZkController.register We are http://127.0.0.1:15366/collection1/ and leader is http://127.0.0.1:15366/collection1/
[junit4] 2> 714023 T1758 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:15366
[junit4] 2> 714023 T1758 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 714023 T1758 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 714024 T1758 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 714026 T1758 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 714027 T1699 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0
[junit4] 2> 714028 T1699 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 714028 T1699 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 714323 T1699 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 714327 T1699 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:64712
[junit4] 2> 714328 T1699 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 714328 T1699 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 714329 T1699 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374228774955
[junit4] 2> 714329 T1699 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374228774955/'
[junit4] 2> 714368 T1699 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374228774955/solr.xml
[junit4] 2> 714459 T1699 oasc.CoreContainer.<init> New CoreContainer 1286251438
[junit4] 2> 714460 T1699 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374228774955/]
[junit4] 2> 714462 T1699 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 714463 T1699 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 714463 T1699 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 714464 T1699 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 714464 T1699 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 714465 T1699 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 714465 T1699 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 714466 T1699 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 714466 T1699 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 714467 T1699 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4] 2> 714484 T1699 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 714484 T1699 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:44209/solr
[junit4] 2> 714485 T1699 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 714486 T1699 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 714489 T1771 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1deda4be name:ZooKeeperConnection Watcher:127.0.0.1:44209 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 714490 T1699 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 714508 T1699 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4] 2> 714519 T1699 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 714521 T1773 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@ac32379 name:ZooKeeperConnection Watcher:127.0.0.1:44209/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 714521 T1699 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 714531 T1699 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 715511 T1722 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 715512 T1722 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:15366_",
[junit4] 2> "base_url":"http://127.0.0.1:15366"}
[junit4] 2> 715536 T1757 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> 715536 T1699 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:64712_
[junit4] 2> 715536 T1741 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> 715536 T1721 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> 715536 T1773 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> 715536 T1728 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> 715539 T1699 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:64712_
[junit4] 2> 715548 T1757 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> 715548 T1741 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> 715549 T1773 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 715548 T1728 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 715549 T1721 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 715549 T1773 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> 715549 T1721 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> 715549 T1728 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> 715550 T1757 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 715550 T1741 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 715559 T1774 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 715559 T1774 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 715561 T1774 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 717049 T1722 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 717050 T1722 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:64712_",
[junit4] 2> "base_url":"http://127.0.0.1:64712"}
[junit4] 2> 717050 T1722 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4] 2> 717051 T1722 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 717067 T1728 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> 717068 T1741 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> 717068 T1757 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> 717068 T1773 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> 717068 T1721 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> 717563 T1774 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 717563 T1774 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374228774955/collection1
[junit4] 2> 717563 T1774 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 717564 T1774 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 717565 T1774 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 717566 T1774 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374228774955/collection1/'
[junit4] 2> 717567 T1774 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374228774955/collection1/lib/README' to classloader
[junit4] 2> 717568 T1774 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374228774955/collection1/lib/classes/' to classloader
[junit4] 2> 717627 T1774 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 717709 T1774 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 717810 T1774 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 717822 T1774 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 718491 T1774 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 718504 T1774 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 718508 T1774 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 718525 T1774 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 718530 T1774 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 718535 T1774 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 718536 T1774 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 718536 T1774 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 718537 T1774 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 718538 T1774 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 718538 T1774 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 718539 T1774 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 718539 T1774 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374228774955/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZkTest-1374228757339/jetty3/
[junit4] 2> 718539 T1774 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@24d0bcec
[junit4] 2> 718540 T1774 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374228757339/jetty3
[junit4] 2> 718541 T1774 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZkTest-1374228757339/jetty3/index/
[junit4] 2> 718541 T1774 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZkTest-1374228757339/jetty3/index' doesn't exist. Creating new index...
[junit4] 2> 718542 T1774 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374228757339/jetty3/index
[junit4] 2> 718545 T1774 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@2ecc99ae lockFactory=org.apache.lucene.store.NativeFSLockFactory@616dc776),segFN=segments_1,generation=1}
[junit4] 2> 718546 T1774 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 718552 T1774 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 718552 T1774 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 718553 T1774 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 718554 T1774 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 718555 T1774 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 718555 T1774 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 718555 T1774 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 718556 T1774 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 718556 T1774 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 718573 T1774 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 718581 T1774 oass.SolrIndexSearcher.<init> Opening Searcher@6499da7c main
[junit4] 2> 718582 T1774 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 718583 T1774 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 718587 T1775 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@6499da7c main{StandardDirectoryReader(segments_1:1)}
[junit4] 2> 718590 T1774 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 718590 T1774 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:64712 collection:collection1 shard:shard1
[junit4] 2> 718590 T1774 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=30000&socketTimeout=30000&retry=false
[junit4] 2> 718611 T1774 oasc.ZkController.register We are http://127.0.0.1:64712/collection1/ and leader is http://127.0.0.1:59037/collection1/
[junit4] 2> 718611 T1774 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:64712
[junit4] 2> 718612 T1774 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4] 2> 718612 T1774 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4] 2> ASYNC NEW_CORE C485 name=collection1 org.apache.solr.core.SolrCore@7308bcfa url=http://127.0.0.1:64712/collection1 node=127.0.0.1:64712_ C485_STATE=coll:collection1 core:collection1 props:{state=down, core=collection1, node_name=127.0.0.1:64712_, base_url=http://127.0.0.1:64712}
[junit4] 2> 718612 T1776 C485 P64712 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4] 2> 718613 T1776 C485 P64712 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4] 2> 718613 T1774 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 718614 T1776 C485 P64712 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4] 2> 718614 T1776 C485 P64712 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 718615 T1699 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0
[junit4] 2> 718615 T1699 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 718615 T1776 C485 P64712 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 718616 T1699 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 718630 T1731 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: core_node3, state: recovering, checkLive: true, onlyIfLeader: true
[junit4] 2> 718903 T1699 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 718907 T1699 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:49106
[junit4] 2> 718908 T1699 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 718908 T1699 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 718909 T1699 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty4-1374228779544
[junit4] 2> 718909 T1699 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty4-1374228779544/'
[junit4] 2> 7189
[...truncated too long message...]
me=Lucene41WithOrds), foo_i=PostingsFormat(name=SimpleText), regex_dup_B_s=Pulsing41(freqCutoff=20 minBlockSize=67 maxBlockSize=159), multiDefault=Pulsing41(freqCutoff=20 minBlockSize=67 maxBlockSize=159), n_tf1=Pulsing41(freqCutoff=20 minBlockSize=67 maxBlockSize=159), n_dt1=PostingsFormat(name=SimpleText), genre_s=PostingsFormat(name=Lucene41WithOrds), author_t=Pulsing41(freqCutoff=20 minBlockSize=67 maxBlockSize=159), range_facet_l=Pulsing41(freqCutoff=20 minBlockSize=67 maxBlockSize=159), n_ti1=PostingsFormat(name=Lucene41WithOrds), text=PostingsFormat(name=TestBloomFilteredLucene41Postings), _version_=PostingsFormat(name=SimpleText), val_i=PostingsFormat(name=Lucene41WithOrds), SubjectTerms_mfacet=PostingsFormat(name=SimpleText), series_t=Pulsing41(freqCutoff=20 minBlockSize=67 maxBlockSize=159), a_t=Pulsing41(freqCutoff=20 minBlockSize=67 maxBlockSize=159), n_tdt1=PostingsFormat(name=SimpleText), regex_dup_A_s=PostingsFormat(name=TestBloomFilteredLucene41Postings), price=PostingsFormat(name=TestBloomFilteredLucene41Postings), other_tl1=Pulsing41(freqCutoff=20 minBlockSize=67 maxBlockSize=159), n_l1=Pulsing41(freqCutoff=20 minBlockSize=67 maxBlockSize=159), a_si=PostingsFormat(name=SimpleText), inStock=PostingsFormat(name=TestBloomFilteredLucene41Postings)}, docValues:{timestamp=DocValuesFormat(name=Lucene42)}, sim=RandomSimilarityProvider(queryNorm=true,coord=no): {}, locale=et_EE, timezone=America/Guayaquil
[junit4] 2> NOTE: FreeBSD 9.1-RELEASE-p3 amd64/Oracle Corporation 1.7.0_21 (64-bit)/cpus=16,threads=2,free=66364280,total=332398592
[junit4] 2> NOTE: All tests run in this JVM: [TestSolrXmlPersistence, StressHdfsTest, InfoHandlerTest, AnalysisAfterCoreReloadTest, ShardRoutingTest, TestFieldResource, BadCopyFieldTest, ExternalFileFieldSortTest, TestFastWriter, TestJoin, TestSchemaNameResource, TestFunctionQuery, RAMDirectoryFactoryTest, PrimitiveFieldTypeTest, ScriptEngineTest, TestIBSimilarityFactory, AddSchemaFieldsUpdateProcessorFactoryTest, LegacyHTMLStripCharFilterTest, TestFaceting, SolrIndexSplitterTest, BadComponentTest, QueryParsingTest, AlternateDirectoryTest, SyncSliceTest, FieldMutatingUpdateProcessorTest, TestStressRecovery, DirectUpdateHandlerOptimizeTest, LoggingHandlerTest, TestFieldTypeCollectionResource, DistributedSpellCheckComponentTest, TestValueSourceCache, SimpleFacetsTest, TestQueryUtils, DistributedTermsComponentTest, TestLRUCache, TestSerializedLuceneMatchVersion, AssignTest, TestBadConfig, TestGroupingSearch, TestPluginEnable, TestRemoteStreaming, TestDefaultSearchFieldResource, TestExtendedDismaxParser, DocumentBuilderTest, ChaosMonkeyNothingIsSafeTest, BasicFunctionalityTest, MoreLikeThisHandlerTest, TestSurroundQueryParser, MBeansHandlerTest, ResourceLoaderTest, SliceStateUpdateTest, TestPhraseSuggestions, CacheHeaderTest, TestPerFieldSimilarity, TestSweetSpotSimilarityFactory, CoreAdminHandlerTest, TestSolrQueryParser, TestFuzzyAnalyzedSuggestions, FileBasedSpellCheckerTest, TestDocumentBuilder, UpdateRequestProcessorFactoryTest, TestSolrCoreProperties, TestSolrQueryParserResource, AutoCommitTest, DocValuesTest, TestPHPSerializedResponseWriter, TestCharFilters, CachingDirectoryFactoryTest, DirectSolrConnectionTest, TestSort, PolyFieldTest, ParsingFieldUpdateProcessorsTest, RegexBoostProcessorTest, TestDocSet, ZkControllerTest, DateFieldTest, BasicDistributedZkTest]
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=BasicDistributedZkTest -Dtests.seed=CD7E1ABE224415F8 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=et_EE -Dtests.timezone=America/Guayaquil -Dtests.file.encoding=UTF-8
[junit4] ERROR 0.00s J0 | BasicDistributedZkTest (suite) <<<
[junit4] > Throwable #1: com.carrotsearch.randomizedtesting.ThreadLeakError: 1 thread leaked from SUITE scope at org.apache.solr.cloud.BasicDistributedZkTest:
[junit4] > 1) Thread[id=2191, name=recoveryCmdExecutor-1277-thread-1, state=RUNNABLE, group=TGRP-BasicDistributedZkTest]
[junit4] > at java.net.PlainSocketImpl.socketConnect(Native Method)
[junit4] > at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:339)
[junit4] > at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:200)
[junit4] > at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:182)
[junit4] > at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:391)
[junit4] > at java.net.Socket.connect(Socket.java:579)
[junit4] > at org.apache.http.conn.scheme.PlainSocketFactory.connectSocket(PlainSocketFactory.java:127)
[junit4] > at org.apache.http.impl.conn.DefaultClientConnectionOperator.openConnection(DefaultClientConnectionOperator.java:180)
[junit4] > at org.apache.http.impl.conn.ManagedClientConnectionImpl.open(ManagedClientConnectionImpl.java:294)
[junit4] > at org.apache.http.impl.client.DefaultRequestDirector.tryConnect(DefaultRequestDirector.java:645)
[junit4] > at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:480)
[junit4] > at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:906)
[junit4] > at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:805)
[junit4] > at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:784)
[junit4] > at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:365)
[junit4] > at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:180)
[junit4] > at org.apache.solr.cloud.SyncStrategy$1.run(SyncStrategy.java:291)
[junit4] > at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
[junit4] > at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
[junit4] > at java.lang.Thread.run(Thread.java:722)
[junit4] > at __randomizedtesting.SeedInfo.seed([CD7E1ABE224415F8]:0)Throwable #2: com.carrotsearch.randomizedtesting.ThreadLeakError: There are still zombie threads that couldn't be terminated:
[junit4] > 1) Thread[id=2191, name=recoveryCmdExecutor-1277-thread-1, state=RUNNABLE, group=TGRP-BasicDistributedZkTest]
[junit4] > at java.net.PlainSocketImpl.socketConnect(Native Method)
[junit4] > at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:339)
[junit4] > at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:200)
[junit4] > at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:182)
[junit4] > at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:391)
[junit4] > at java.net.Socket.connect(Socket.java:579)
[junit4] > at org.apache.http.conn.scheme.PlainSocketFactory.connectSocket(PlainSocketFactory.java:127)
[junit4] > at org.apache.http.impl.conn.DefaultClientConnectionOperator.openConnection(DefaultClientConnectionOperator.java:180)
[junit4] > at org.apache.http.impl.conn.ManagedClientConnectionImpl.open(ManagedClientConnectionImpl.java:294)
[junit4] > at org.apache.http.impl.client.DefaultRequestDirector.tryConnect(DefaultRequestDirector.java:645)
[junit4] > at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:480)
[junit4] > at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:906)
[junit4] > at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:805)
[junit4] > at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:784)
[junit4] > at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:365)
[junit4] > at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:180)
[junit4] > at org.apache.solr.cloud.SyncStrategy$1.run(SyncStrategy.java:291)
[junit4] > at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
[junit4] > at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
[junit4] > at java.lang.Thread.run(Thread.java:722)
[junit4] > at __randomizedtesting.SeedInfo.seed([CD7E1ABE224415F8]:0)
[junit4] Completed on J0 in 587.70s, 1 test, 2 errors <<< FAILURES!
[...truncated 486 lines...]
BUILD FAILED
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/build.xml:389: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/build.xml:369: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/build.xml:39: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build.xml:181: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/common-build.xml:449: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/lucene/common-build.xml:1247: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/lucene/common-build.xml:890: There were test failures: 318 suites, 1342 tests, 2 suite-level errors, 641 ignored (5 assumptions)
Total time: 47 minutes 5 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure