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/22 12:18:18 UTC
[JENKINS] Lucene-Solr-Tests-4.x-Java6 - Build # 1818 - Failure
Build: https://builds.apache.org/job/Lucene-Solr-Tests-4.x-Java6/1818/
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=2386, name=recoveryCmdExecutor-1053-thread-1, state=RUNNABLE, group=TGRP-BasicDistributedZkTest] at java.net.PlainSocketImpl.socketConnect(Native Method) at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:327) at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:193) at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:180) at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:384) at java.net.Socket.connect(Socket.java:546) at org.apache.http.conn.scheme.PlainSocketFactory.connectSocket(PlainSocketFactory.java:127) at org.apache.http.impl.conn.DefaultClientConnectionOperator.openConnection(DefaultClientConnectionOperator.java:180) at org.apache.http.impl.conn.ManagedClientConnectionImpl.open(ManagedClientConnectionImpl.java:294) at org.apache.http.impl.client.DefaultRequestDirector.tryConnect(DefaultRequestDirector.java:645) at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:480) at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:906) at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:805) at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:784) at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:365) at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:180) at org.apache.solr.cloud.SyncStrategy$1.run(SyncStrategy.java:291) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1146) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) at java.lang.Thread.run(Thread.java:679)
Stack Trace:
com.carrotsearch.randomizedtesting.ThreadLeakError: 1 thread leaked from SUITE scope at org.apache.solr.cloud.BasicDistributedZkTest:
1) Thread[id=2386, name=recoveryCmdExecutor-1053-thread-1, state=RUNNABLE, group=TGRP-BasicDistributedZkTest]
at java.net.PlainSocketImpl.socketConnect(Native Method)
at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:327)
at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:193)
at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:180)
at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:384)
at java.net.Socket.connect(Socket.java:546)
at org.apache.http.conn.scheme.PlainSocketFactory.connectSocket(PlainSocketFactory.java:127)
at org.apache.http.impl.conn.DefaultClientConnectionOperator.openConnection(DefaultClientConnectionOperator.java:180)
at org.apache.http.impl.conn.ManagedClientConnectionImpl.open(ManagedClientConnectionImpl.java:294)
at org.apache.http.impl.client.DefaultRequestDirector.tryConnect(DefaultRequestDirector.java:645)
at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:480)
at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:906)
at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:805)
at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:784)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:365)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:180)
at org.apache.solr.cloud.SyncStrategy$1.run(SyncStrategy.java:291)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1146)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:679)
at __randomizedtesting.SeedInfo.seed([10689F25DE49F3E1]: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=2386, name=recoveryCmdExecutor-1053-thread-1, state=RUNNABLE, group=TGRP-BasicDistributedZkTest] at java.net.PlainSocketImpl.socketConnect(Native Method) at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:327) at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:193) at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:180) at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:384) at java.net.Socket.connect(Socket.java:546) at org.apache.http.conn.scheme.PlainSocketFactory.connectSocket(PlainSocketFactory.java:127) at org.apache.http.impl.conn.DefaultClientConnectionOperator.openConnection(DefaultClientConnectionOperator.java:180) at org.apache.http.impl.conn.ManagedClientConnectionImpl.open(ManagedClientConnectionImpl.java:294) at org.apache.http.impl.client.DefaultRequestDirector.tryConnect(DefaultRequestDirector.java:645) at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:480) at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:906) at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:805) at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:784) at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:365) at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:180) at org.apache.solr.cloud.SyncStrategy$1.run(SyncStrategy.java:291) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1146) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) at java.lang.Thread.run(Thread.java:679)
Stack Trace:
com.carrotsearch.randomizedtesting.ThreadLeakError: There are still zombie threads that couldn't be terminated:
1) Thread[id=2386, name=recoveryCmdExecutor-1053-thread-1, state=RUNNABLE, group=TGRP-BasicDistributedZkTest]
at java.net.PlainSocketImpl.socketConnect(Native Method)
at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:327)
at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:193)
at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:180)
at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:384)
at java.net.Socket.connect(Socket.java:546)
at org.apache.http.conn.scheme.PlainSocketFactory.connectSocket(PlainSocketFactory.java:127)
at org.apache.http.impl.conn.DefaultClientConnectionOperator.openConnection(DefaultClientConnectionOperator.java:180)
at org.apache.http.impl.conn.ManagedClientConnectionImpl.open(ManagedClientConnectionImpl.java:294)
at org.apache.http.impl.client.DefaultRequestDirector.tryConnect(DefaultRequestDirector.java:645)
at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:480)
at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:906)
at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:805)
at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:784)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:365)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:180)
at org.apache.solr.cloud.SyncStrategy$1.run(SyncStrategy.java:291)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1146)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:679)
at __randomizedtesting.SeedInfo.seed([10689F25DE49F3E1]:0)
Build Log:
[...truncated 9228 lines...]
[junit4] Suite: org.apache.solr.cloud.BasicDistributedZkTest
[junit4] 2> 656318 T1892 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /qy_j/og
[junit4] 2> 656323 T1892 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4] 2> Creating dataDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./solrtest-BasicDistributedZkTest-1374487803509
[junit4] 2> 656325 T1892 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 656325 T1893 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 656426 T1892 oasc.ZkTestServer.run start zk server on port:32154
[junit4] 2> 656426 T1892 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 656431 T1899 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@54e0eda5 name:ZooKeeperConnection Watcher:127.0.0.1:32154 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 656431 T1892 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 656432 T1892 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 656442 T1892 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 656448 T1901 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@162f785d name:ZooKeeperConnection Watcher:127.0.0.1:32154/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 656448 T1892 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 656449 T1892 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4] 2> 656452 T1892 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4] 2> 656462 T1892 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4] 2> 656464 T1892 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4] 2> 656466 T1892 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4] 2> 656467 T1892 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4] 2> 656478 T1892 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
[junit4] 2> 656479 T1892 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4] 2> 656582 T1892 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4] 2> 656583 T1892 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4] 2> 656586 T1892 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4] 2> 656587 T1892 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4] 2> 656595 T1892 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4] 2> 656596 T1892 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4] 2> 656599 T1892 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4] 2> 656599 T1892 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4] 2> 656602 T1892 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 656603 T1892 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 656605 T1892 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4] 2> 656606 T1892 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4] 2> 656613 T1892 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4] 2> 656614 T1892 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4] 2> 656890 T1892 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 656894 T1892 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:32157
[junit4] 2> 656895 T1892 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 656895 T1892 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 656896 T1892 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374487803802
[junit4] 2> 656896 T1892 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374487803802/'
[junit4] 2> 656934 T1892 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374487803802/solr.xml
[junit4] 2> 657008 T1892 oasc.CoreContainer.<init> New CoreContainer 294644373
[junit4] 2> 657009 T1892 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374487803802/]
[junit4] 2> 657011 T1892 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 657011 T1892 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 657012 T1892 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 657012 T1892 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 657013 T1892 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 657013 T1892 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 657014 T1892 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 657014 T1892 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 657014 T1892 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 657015 T1892 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4] 2> 657032 T1892 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 657033 T1892 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:32154/solr
[junit4] 2> 657033 T1892 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 657034 T1892 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 657037 T1912 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7f71e534 name:ZooKeeperConnection Watcher:127.0.0.1:32154 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 657037 T1892 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 657039 T1892 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4] 2> 657051 T1892 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 657053 T1914 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4a18cf4e name:ZooKeeperConnection Watcher:127.0.0.1:32154/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 657053 T1892 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 657055 T1892 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 657066 T1892 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 657069 T1892 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 657077 T1892 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:32157_qy_j%2Fog
[junit4] 2> 657078 T1892 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:32157_qy_j%2Fog
[junit4] 2> 657081 T1892 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 657085 T1892 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 657087 T1892 oasc.Overseer.start Overseer (id=90078432691224579-127.0.0.1:32157_qy_j%2Fog-n_0000000000) starting
[junit4] 2> 657091 T1892 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 657094 T1916 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 657094 T1892 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 657097 T1892 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 657099 T1892 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 657101 T1915 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 657106 T1917 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 657107 T1917 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 657108 T1917 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 658245 T612 oasc.OverseerCollectionProcessor.run WARN Overseer cannot talk to ZK
[junit4] 2> 658604 T1915 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 658605 T1915 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:32157_qy_j%2Fog",
[junit4] 2> "base_url":"http://127.0.0.1:32157/qy_j/og"}
[junit4] 2> 658606 T1915 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with numShards 1
[junit4] 2> 658606 T1915 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 658675 T1914 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> 658870 T627 oasc.OverseerCollectionProcessor.run WARN Overseer cannot talk to ZK
[junit4] 2> 659110 T1917 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 659110 T1917 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374487803802/collection1
[junit4] 2> 659110 T1917 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4] 2> 659111 T1917 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 659111 T1917 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4] 2> 659112 T1917 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374487803802/collection1/'
[junit4] 2> 659113 T1917 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374487803802/collection1/lib/README' to classloader
[junit4] 2> 659113 T1917 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374487803802/collection1/lib/classes/' to classloader
[junit4] 2> 659159 T1917 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_45
[junit4] 2> 659209 T1917 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 659310 T1917 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 659321 T1917 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 659970 T1917 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 659970 T1917 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 659971 T1917 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 659985 T1917 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 659990 T1917 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 660002 T1917 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 660008 T1917 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 660013 T1917 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 660014 T1917 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 660014 T1917 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 660014 T1917 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 660015 T1917 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 660015 T1917 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 660015 T1917 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 660016 T1917 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374487803802/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZkTest-1374487803509/control/data/
[junit4] 2> 660016 T1917 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@76027982
[junit4] 2> 660019 T1917 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374487803509/control/data
[junit4] 2> 660019 T1917 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZkTest-1374487803509/control/data/index/
[junit4] 2> 660020 T1917 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZkTest-1374487803509/control/data/index' doesn't exist. Creating new index...
[junit4] 2> 660020 T1917 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374487803509/control/data/index
[junit4] 2> 660025 T1917 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@554cc383 lockFactory=org.apache.lucene.store.NativeFSLockFactory@486b79d),segFN=segments_1,generation=1}
[junit4] 2> 660026 T1917 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 660030 T1917 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 660030 T1917 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 660031 T1917 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 660031 T1917 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 660032 T1917 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 660032 T1917 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 660032 T1917 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 660033 T1917 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 660033 T1917 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 660045 T1917 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 660053 T1917 oass.SolrIndexSearcher.<init> Opening Searcher@1d595930 main
[junit4] 2> 660055 T1917 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 660055 T1917 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 660058 T1918 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1d595930 main{StandardDirectoryReader(segments_1:1)}
[junit4] 2> 660059 T1917 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 660060 T1917 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:32157/qy_j/og collection:control_collection shard:shard1
[junit4] 2> 660060 T1917 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=30000&socketTimeout=30000&retry=false
[junit4] 2> 660078 T1917 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4] 2> 660128 T1917 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 660141 T1917 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 660141 T1917 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 660141 T1917 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:32157/qy_j/og/collection1/
[junit4] 2> 660142 T1917 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 660142 T1917 oasc.SyncStrategy.syncToMe http://127.0.0.1:32157/qy_j/og/collection1/ has no replicas
[junit4] 2> 660142 T1917 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:32157/qy_j/og/collection1/ shard1
[junit4] 2> 660142 T1917 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4] 2> 660203 T1915 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 660219 T1914 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> 660256 T1917 oasc.ZkController.register We are http://127.0.0.1:32157/qy_j/og/collection1/ and leader is http://127.0.0.1:32157/qy_j/og/collection1/
[junit4] 2> 660256 T1917 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:32157/qy_j/og
[junit4] 2> 660256 T1917 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 660256 T1917 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 660257 T1917 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 660259 T1917 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 660259 T1892 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0
[junit4] 2> 660260 T1892 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 660261 T1892 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 660271 T1892 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4] 2> 660273 T1892 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 660275 T1921 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7241f1f1 name:ZooKeeperConnection Watcher:127.0.0.1:32154/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 660275 T1892 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 660276 T1892 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 660278 T1892 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4] 2> 660557 T1892 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 660559 T1892 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:32161
[junit4] 2> 660560 T1892 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 660560 T1892 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 660561 T1892 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374487807464
[junit4] 2> 660561 T1892 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374487807464/'
[junit4] 2> 660598 T1892 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374487807464/solr.xml
[junit4] 2> 660676 T1892 oasc.CoreContainer.<init> New CoreContainer 657410764
[junit4] 2> 660676 T1892 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374487807464/]
[junit4] 2> 660678 T1892 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 660679 T1892 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 660679 T1892 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 660679 T1892 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 660680 T1892 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 660680 T1892 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 660681 T1892 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 660681 T1892 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 660681 T1892 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 660682 T1892 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4] 2> 660698 T1892 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 660699 T1892 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:32154/solr
[junit4] 2> 660699 T1892 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 660700 T1892 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 660702 T1932 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@11d7ab2d name:ZooKeeperConnection Watcher:127.0.0.1:32154 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 660703 T1892 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 660704 T1892 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4] 2> 660712 T1892 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 660718 T1934 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@125e3fe5 name:ZooKeeperConnection Watcher:127.0.0.1:32154/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 660719 T1892 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 660727 T1892 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 661723 T1915 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 661724 T1915 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:32157_qy_j%2Fog",
[junit4] 2> "base_url":"http://127.0.0.1:32157/qy_j/og"}
[junit4] 2> 661737 T1921 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> 661737 T1914 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> 661738 T1934 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> 661738 T1892 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:32161_qy_j%2Fog
[junit4] 2> 661746 T1892 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:32161_qy_j%2Fog
[junit4] 2> 661749 T1921 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> 661749 T1914 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> 661749 T1934 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> 661750 T1921 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 661750 T1914 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 661752 T1934 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 661758 T1935 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 661758 T1935 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 661759 T1935 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 663248 T1915 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 663249 T1915 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:32161_qy_j%2Fog",
[junit4] 2> "base_url":"http://127.0.0.1:32161/qy_j/og"}
[junit4] 2> 663249 T1915 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with numShards 2
[junit4] 2> 663249 T1915 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 663262 T1914 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> 663262 T1921 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> 663262 T1934 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> 663762 T1935 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 663762 T1935 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374487807464/collection1
[junit4] 2> 663762 T1935 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 663763 T1935 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 663763 T1935 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 663764 T1935 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374487807464/collection1/'
[junit4] 2> 663765 T1935 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374487807464/collection1/lib/classes/' to classloader
[junit4] 2> 663765 T1935 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374487807464/collection1/lib/README' to classloader
[junit4] 2> 663821 T1935 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_45
[junit4] 2> 663882 T1935 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 663983 T1935 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 663994 T1935 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 664636 T1935 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 664637 T1935 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 664637 T1935 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 664650 T1935 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 664655 T1935 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 664667 T1935 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 664672 T1935 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 664676 T1935 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 664677 T1935 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 664677 T1935 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 664678 T1935 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 664679 T1935 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 664679 T1935 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 664679 T1935 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 664680 T1935 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374487807464/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZkTest-1374487803509/jetty1/
[junit4] 2> 664680 T1935 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@76027982
[junit4] 2> 664682 T1935 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374487803509/jetty1
[junit4] 2> 664683 T1935 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZkTest-1374487803509/jetty1/index/
[junit4] 2> 664683 T1935 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZkTest-1374487803509/jetty1/index' doesn't exist. Creating new index...
[junit4] 2> 664684 T1935 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374487803509/jetty1/index
[junit4] 2> 664688 T1935 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@43183848 lockFactory=org.apache.lucene.store.NativeFSLockFactory@13828679),segFN=segments_1,generation=1}
[junit4] 2> 664688 T1935 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 664693 T1935 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 664693 T1935 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 664694 T1935 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 664694 T1935 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 664695 T1935 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 664695 T1935 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 664696 T1935 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 664696 T1935 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 664697 T1935 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 664707 T1935 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 664715 T1935 oass.SolrIndexSearcher.<init> Opening Searcher@24a3e92 main
[junit4] 2> 664716 T1935 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 664716 T1935 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 664721 T1936 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@24a3e92 main{StandardDirectoryReader(segments_1:1)}
[junit4] 2> 664723 T1935 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 664723 T1935 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:32161/qy_j/og collection:collection1 shard:shard1
[junit4] 2> 664723 T1935 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=30000&socketTimeout=30000&retry=false
[junit4] 2> 664741 T1935 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 664756 T1935 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 664767 T1935 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 664768 T1935 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 664768 T1935 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:32161/qy_j/og/collection1/
[junit4] 2> 664768 T1915 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 664768 T1935 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 664769 T1935 oasc.SyncStrategy.syncToMe http://127.0.0.1:32161/qy_j/og/collection1/ has no replicas
[junit4] 2> 664769 T1935 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:32161/qy_j/og/collection1/ shard1
[junit4] 2> 664769 T1935 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 664773 T1934 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> 664773 T1921 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> 664773 T1914 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> 666294 T1915 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 666311 T1914 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> 666311 T1921 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> 666311 T1934 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> 666322 T1935 oasc.ZkController.register We are http://127.0.0.1:32161/qy_j/og/collection1/ and leader is http://127.0.0.1:32161/qy_j/og/collection1/
[junit4] 2> 666322 T1935 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:32161/qy_j/og
[junit4] 2> 666322 T1935 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 666322 T1935 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 666323 T1935 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 666324 T1935 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 666325 T1892 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0
[junit4] 2> 666326 T1892 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 666326 T1892 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 666511 T1892 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 666513 T1892 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:32174
[junit4] 2> 666514 T1892 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 666514 T1892 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 666514 T1892 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374487813517
[junit4] 2> 666515 T1892 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374487813517/'
[junit4] 2> 666539 T1892 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374487813517/solr.xml
[junit4] 2> 666588 T1892 oasc.CoreContainer.<init> New CoreContainer 423490926
[junit4] 2> 666589 T1892 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374487813517/]
[junit4] 2> 666590 T1892 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 666590 T1892 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 666590 T1892 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 666591 T1892 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 666591 T1892 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 666591 T1892 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 666592 T1892 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 666592 T1892 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 666592 T1892 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 666592 T1892 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4] 2> 666602 T1892 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 666603 T1892 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:32154/solr
[junit4] 2> 666603 T1892 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 666604 T1892 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 666606 T1948 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@32bc15b4 name:ZooKeeperConnection Watcher:127.0.0.1:32154 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 666606 T1892 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 666608 T1892 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4] 2> 666614 T1892 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 666616 T1950 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@77d603a1 name:ZooKeeperConnection Watcher:127.0.0.1:32154/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 666616 T1892 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 666627 T1892 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 667630 T1892 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:32174_qy_j%2Fog
[junit4] 2> 667632 T1892 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:32174_qy_j%2Fog
[junit4] 2> 667634 T1914 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> 667634 T1921 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> 667634 T1934 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> 667635 T1950 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 667636 T1914 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 667643 T1921 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 667643 T1934 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 667649 T1951 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 667649 T1951 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 667651 T1951 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 667820 T1915 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 667821 T1915 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:32161_qy_j%2Fog",
[junit4] 2> "base_url":"http://127.0.0.1:32161/qy_j/og"}
[junit4] 2> 667824 T1915 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:32174_qy_j%2Fog",
[junit4] 2> "base_url":"http://127.0.0.1:32174/qy_j/og"}
[junit4] 2> 667824 T1915 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4] 2> 667825 T1915 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 667836 T1934 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> 667836 T1950 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> 667836 T1914 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> 667836 T1921 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> 668652 T1951 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 668652 T1951 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374487813517/collection1
[junit4] 2> 668652 T1951 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 668653 T1951 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 668653 T1951 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 668654 T1951 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374487813517/collection1/'
[junit4] 2> 668656 T1951 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374487813517/collection1/lib/README' to classloader
[junit4] 2> 668656 T1951 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374487813517/collection1/lib/classes/' to classloader
[junit4] 2> 668714 T1951 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_45
[junit4] 2> 668777 T1951 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 668878 T1951 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 668890 T1951 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 669236 T646 oasc.OverseerCollectionProcessor.run WARN Overseer cannot talk to ZK
[junit4] 2> 669452 T1951 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 669453 T1951 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 669453 T1951 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 669462 T1951 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 669465 T1951 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 669474 T1951 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 669477 T1951 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 669480 T1951 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 669481 T1951 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 669481 T1951 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 669481 T1951 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 669482 T1951 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 669482 T1951 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 669482 T1951 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 669482 T1951 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374487813517/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZkTest-1374487803509/jetty2/
[junit4] 2> 669483 T1951 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@76027982
[junit4] 2> 669485 T1951 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374487803509/jetty2
[junit4] 2> 669485 T1951 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZkTest-1374487803509/jetty2/index/
[junit4] 2> 669485 T1951 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZkTest-1374487803509/jetty2/index' doesn't exist. Creating new index...
[junit4] 2> 669486 T1951 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374487803509/jetty2/index
[junit4] 2> 669488 T1951 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@228dd56e lockFactory=org.apache.lucene.store.NativeFSLockFactory@15dc7c1),segFN=segments_1,generation=1}
[junit4] 2> 669488 T1951 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 669492 T1951 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 669492 T1951 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 669492 T1951 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 669493 T1951 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 669493 T1951 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 669493 T1951 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 669494 T1951 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 669494 T1951 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 669494 T1951 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 669501 T1951 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 669506 T1951 oass.SolrIndexSearcher.<init> Opening Searcher@6728331a main
[junit4] 2> 669507 T1951 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 669507 T1951 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 669510 T1952 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@6728331a main{StandardDirectoryReader(segments_1:1)}
[junit4] 2> 669512 T1951 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 669512 T1951 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:32174/qy_j/og collection:collection1 shard:shard2
[junit4] 2> 669512 T1951 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=30000&socketTimeout=30000&retry=false
[junit4] 2> 669523 T1951 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4] 2> 669537 T1951 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
[junit4] 2> 669539 T1951 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 669539 T1951 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 669539 T1951 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:32174/qy_j/og/collection1/
[junit4] 2> 669539 T1951 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 669540 T1951 oasc.SyncStrategy.syncToMe http://127.0.0.1:32174/qy_j/og/collection1/ has no replicas
[junit4] 2> 669540 T1951 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:32174/qy_j/og/collection1/ shard2
[junit4] 2> 669540 T1951 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4] 2> 670852 T1915 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 670880 T1934 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> 670880 T1914 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> 670880 T1950 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> 670880 T1921 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> 670920 T1951 oasc.ZkController.register We are http://127.0.0.1:32174/qy_j/og/collection1/ and leader is http://127.0.0.1:32174/qy_j/og/collection1/
[junit4] 2> 670920 T1951 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:32174/qy_j/og
[junit4] 2> 670920 T1951 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 670920 T1951 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 670920 T1951 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 670922 T1951 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 670922 T1892 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0
[junit4] 2> 670923 T1892 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 670923 T1892 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 671161 T1892 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 671164 T1892 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:32180
[junit4] 2> 671164 T1892 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 671165 T1892 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 671165 T1892 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374487818116
[junit4] 2> 671165 T1892 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374487818116/'
[junit4] 2> 671190 T1892 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374487818116/solr.xml
[junit4] 2> 671238 T1892 oasc.CoreContainer.<init> New CoreContainer 1510741613
[junit4] 2> 671239 T1892 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374487818116/]
[junit4] 2> 671240 T1892 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 671241 T1892 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 671241 T1892 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 671241 T1892 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 671241 T1892 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 671242 T1892 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 671242 T1892 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 671242 T1892 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 671243 T1892 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 671243 T1892 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4] 2> 671254 T1892 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 671254 T1892 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:32154/solr
[junit4] 2> 671255 T1892 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 671255 T1892 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 671257 T1964 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4f947c4a name:ZooKeeperConnection Watcher:127.0.0.1:32154 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 671258 T1892 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 671259 T1892 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4] 2> 671267 T1892 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 671268 T1966 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6dea14ca name:ZooKeeperConnection Watcher:127.0.0.1:32154/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 671268 T1892 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 671279 T1892 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 672281 T1892 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:32180_qy_j%2Fog
[junit4] 2> 672283 T1892 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:32180_qy_j%2Fog
[junit4] 2> 672285 T1914 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> 672285 T1921 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> 672285 T1934 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> 672286 T1966 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 672286 T1950 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 672286 T1950 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> 672286 T1914 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 672287 T1921 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 672287 T1934 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 672301 T1967 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 672301 T1967 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 672303 T1967 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 672393 T1915 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 672394 T1915 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:32174_qy_j%2Fog",
[junit4] 2> "base_url":"http://127.0.0.1:32174/qy_j/og"}
[junit4] 2> 672400 T1915 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:32180_qy_j%2Fog",
[junit4] 2> "base_url":"http://127.0.0.1:32180/qy_j/og"}
[junit4] 2> 672400 T1915 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4] 2> 672400 T1915 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 672411 T1934 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> 672411 T1914 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> 672411 T1921 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> 672411 T1950 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> 672411 T1966 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> 673304 T1967 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 673304 T1967 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374487818116/collection1
[junit4] 2> 673304 T1967 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 673305 T1967 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 673305 T1967 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 673306 T1967 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374487818116/collection1/'
[junit4] 2> 673308 T1967 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374487818116/collection1/lib/README' to classloader
[junit4] 2> 673308 T1967 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374487818116/collection1/lib/classes/' to classloader
[junit4] 2> 673363 T1967 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_45
[junit4] 2> 673384 T650 oasc.OverseerCollectionProcessor.run WARN Overseer cannot talk to ZK
[junit4] 2> 673424 T1967 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 673526 T1967 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 673534 T1967 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 673962 T1967 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 673963 T1967 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 673963 T1967 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 673972 T1967 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 673975 T1967 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 673986 T1967 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 673990 T1967 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 673993 T1967 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 673994 T1967 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 673994 T1967 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 673994 T1967 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 673995 T1967 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 673995 T1967 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 673995 T1967 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 673996 T1967 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374487818116/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZkTest-1374487803509/jetty3/
[junit4] 2> 673996 T1967 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@76027982
[junit4] 2> 673998 T1967 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374487803509/jetty3
[junit4] 2> 673998 T1967 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZkTest-1374487803509/jetty3/index/
[junit4] 2> 673998 T1967 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZkTest-1374487803509/jetty3/index' doesn't exist. Creating new index...
[junit4] 2> 673999 T1967 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374487803509/jetty3/index
[junit4] 2> 674001 T1967 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@296a13c9 lockFactory=org.apache.lucene.store.NativeFSLockFactory@42fcdcd),segFN=segments_1,generation=1}
[junit4] 2> 674001 T1967 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 674005 T1967 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 674005 T1967 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 674005 T1967 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 674006 T1967 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 674006 T1967 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 674006 T1967 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 674007 T1967 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 674007 T1967 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 674007 T1967 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 674014 T1967 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 674019 T1967 oass.SolrIndexSearcher.<init> Opening Searcher@293ef73d main
[junit4] 2> 674020 T1967 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 674020 T1967 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 674024 T1968 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@293ef73d main{StandardDirectoryReader(segments_1:1)}
[junit4] 2> 674025 T1967 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 674025 T1967 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:32180/qy_j/og collection:collection1 shard:shard1
[junit4] 2> 674026 T1967 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=30000&socketTimeout=30000&retry=false
[junit4] 2> 674042 T1967 oasc.ZkController.register We are http://127.0.0.1:32180/qy_j/og/collection1/ and leader is http://127.0.0.1:32161/qy_j/og/collection1/
[junit4] 2> 674042 T1967 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:32180/qy_j/og
[junit4] 2> 674043 T1967 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4] 2> 674043 T1967 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4] 2> ASYNC NEW_CORE C599 name=collection1 org.apache.solr.core.SolrCore@5d31bb3f url=http://127.0.0.1:32180/qy_j/og/collection1 node=127.0.0.1:32180_qy_j%2Fog C599_STATE=coll:collection1 core:collection1 props:{state=down, core=collection1, node_name=127.0.0.1:32180_qy_j%2Fog, base_url=http://127.0.0.1:32180/qy_j/og}
[junit4] 2> 674043 T1969 C599 P32180 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4] 2> 674043 T1967 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 674044 T1969 C599 P32180 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4] 2> 674045 T1969 C599 P32180 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4] 2> 674045 T1969 C599 P32180 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 674045 T1892 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0
[junit4] 2> 674046 T1892 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 674046 T1969 C599 P32180 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 674046 T1892 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 674060 T1924 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: core_node3, state: recovering, checkLive: true, onlyIfLeader: true
[junit4] 2> 674330 T1892 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 674334 T1892 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:32188
[junit4] 2> 674334 T1892 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 674335 T1892 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 674335 T1892 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty4-1374487821244
[junit4] 2> 674336 T1892 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0
[...truncated too long message...]
645)
[junit4] 2> at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:480)
[junit4] 2> at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:906)
[junit4] 2> at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:805)
[junit4] 2> at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:784)
[junit4] 2> at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:365)
[junit4] 2> at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:180)
[junit4] 2> at org.apache.solr.cloud.SyncStrategy$1.run(SyncStrategy.java:291)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1146)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
[junit4] 2> at java.lang.Thread.run(Thread.java:679)
[junit4] 2> NOTE: test params are: codec=FastCompressingStoredFields(storedFieldsFormat=CompressingStoredFieldsFormat(compressionMode=FAST, chunkSize=292), termVectorsFormat=CompressingTermVectorsFormat(compressionMode=FAST, chunkSize=292)), sim=DefaultSimilarity, locale=da_DK, timezone=America/Glace_Bay
[junit4] 2> NOTE: FreeBSD 9.1-RELEASE-p3 amd64/Sun Microsystems Inc. 1.6.0_32 (64-bit)/cpus=16,threads=2,free=85995832,total=423428096
[junit4] 2> NOTE: All tests run in this JVM: [UUIDFieldTest, MinimalSchemaTest, TestGroupingSearch, TestRandomDVFaceting, TestStressRecovery, TestPropInjectDefaults, TestSolrDeletionPolicy1, AliasIntegrationTest, SynonymTokenizerTest, TestXIncludeConfig, TestFastLRUCache, TermVectorComponentTest, MBeansHandlerTest, PluginInfoTest, TestMaxScoreQueryParser, TestSolrDeletionPolicy2, StatelessScriptUpdateProcessorFactoryTest, RegexBoostProcessorTest, TestSurroundQueryParser, TestShardHandlerFactory, PreAnalyzedFieldTest, TestFieldTypeCollectionResource, ShowFileRequestHandlerTest, ReturnFieldsTest, TestSolrIndexConfig, SuggesterFSTTest, TestDynamicFieldCollectionResource, HdfsUnloadDistributedZkTest, SliceStateTest, SuggesterTest, TestPhraseSuggestions, TestFunctionQuery, TestSolrQueryParserDefaultOperatorResource, BadComponentTest, StressHdfsTest, SolrTestCaseJ4Test, TestCharFilters, SoftAutoCommitTest, RAMDirectoryFactoryTest, FieldMutatingUpdateProcessorTest, ClusterStateUpdateTest, SimpleFacetsTest, BadCopyFieldTest, OverseerTest, TestQuerySenderListener, AnalysisAfterCoreReloadTest, ZkControllerTest, TestSolrQueryParserResource, ScriptEngineTest, TestCoreContainer, DateFieldTest, LegacyHTMLStripCharFilterTest, SystemInfoHandlerTest, TermsComponentTest, TestUniqueKeyFieldResource, TestSolrQueryParser, AddSchemaFieldsUpdateProcessorFactoryTest, DistributedTermsComponentTest, SliceStateUpdateTest, ExternalFileFieldSortTest, DocumentBuilderTest, CircularListTest, JsonLoaderTest, RecoveryZkTest, InfoHandlerTest, SearchHandlerTest, TestDefaultSearchFieldResource, TestJoin, PeerSyncTest, CachingDirectoryFactoryTest, LoggingHandlerTest, TestCopyFieldCollectionResource, CoreAdminHandlerTest, TestPseudoReturnFields, SchemaVersionSpecificBehaviorTest, TestAddFieldRealTimeGet, TestSolrXmlPersistence, LeaderElectionTest, BasicDistributedZkTest]
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=BasicDistributedZkTest -Dtests.seed=10689F25DE49F3E1 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=da_DK -Dtests.timezone=America/Glace_Bay -Dtests.file.encoding=ISO8859-1
[junit4] ERROR 0.00s J0 | BasicDistributedZkTest (suite) <<<
[junit4] > Throwable #1: com.carrotsearch.randomizedtesting.ThreadLeakError: 1 thread leaked from SUITE scope at org.apache.solr.cloud.BasicDistributedZkTest:
[junit4] > 1) Thread[id=2386, name=recoveryCmdExecutor-1053-thread-1, state=RUNNABLE, group=TGRP-BasicDistributedZkTest]
[junit4] > at java.net.PlainSocketImpl.socketConnect(Native Method)
[junit4] > at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:327)
[junit4] > at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:193)
[junit4] > at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:180)
[junit4] > at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:384)
[junit4] > at java.net.Socket.connect(Socket.java:546)
[junit4] > at org.apache.http.conn.scheme.PlainSocketFactory.connectSocket(PlainSocketFactory.java:127)
[junit4] > at org.apache.http.impl.conn.DefaultClientConnectionOperator.openConnection(DefaultClientConnectionOperator.java:180)
[junit4] > at org.apache.http.impl.conn.ManagedClientConnectionImpl.open(ManagedClientConnectionImpl.java:294)
[junit4] > at org.apache.http.impl.client.DefaultRequestDirector.tryConnect(DefaultRequestDirector.java:645)
[junit4] > at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:480)
[junit4] > at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:906)
[junit4] > at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:805)
[junit4] > at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:784)
[junit4] > at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:365)
[junit4] > at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:180)
[junit4] > at org.apache.solr.cloud.SyncStrategy$1.run(SyncStrategy.java:291)
[junit4] > at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1146)
[junit4] > at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
[junit4] > at java.lang.Thread.run(Thread.java:679)
[junit4] > at __randomizedtesting.SeedInfo.seed([10689F25DE49F3E1]:0)Throwable #2: com.carrotsearch.randomizedtesting.ThreadLeakError: There are still zombie threads that couldn't be terminated:
[junit4] > 1) Thread[id=2386, name=recoveryCmdExecutor-1053-thread-1, state=RUNNABLE, group=TGRP-BasicDistributedZkTest]
[junit4] > at java.net.PlainSocketImpl.socketConnect(Native Method)
[junit4] > at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:327)
[junit4] > at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:193)
[junit4] > at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:180)
[junit4] > at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:384)
[junit4] > at java.net.Socket.connect(Socket.java:546)
[junit4] > at org.apache.http.conn.scheme.PlainSocketFactory.connectSocket(PlainSocketFactory.java:127)
[junit4] > at org.apache.http.impl.conn.DefaultClientConnectionOperator.openConnection(DefaultClientConnectionOperator.java:180)
[junit4] > at org.apache.http.impl.conn.ManagedClientConnectionImpl.open(ManagedClientConnectionImpl.java:294)
[junit4] > at org.apache.http.impl.client.DefaultRequestDirector.tryConnect(DefaultRequestDirector.java:645)
[junit4] > at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:480)
[junit4] > at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:906)
[junit4] > at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:805)
[junit4] > at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:784)
[junit4] > at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:365)
[junit4] > at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:180)
[junit4] > at org.apache.solr.cloud.SyncStrategy$1.run(SyncStrategy.java:291)
[junit4] > at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1146)
[junit4] > at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
[junit4] > at java.lang.Thread.run(Thread.java:679)
[junit4] > at __randomizedtesting.SeedInfo.seed([10689F25DE49F3E1]:0)
[junit4] Completed on J0 in 410.21s, 1 test, 2 errors <<< FAILURES!
[...truncated 485 lines...]
BUILD FAILED
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/build.xml:395: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/build.xml:375: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/build.xml:39: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build.xml:181: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/common-build.xml:449: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/lucene/common-build.xml:1250: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/lucene/common-build.xml:893: There were test failures: 319 suites, 1345 tests, 2 suite-level errors, 647 ignored (2 assumptions)
Total time: 40 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