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/23 05:30:38 UTC
[JENKINS] Lucene-Solr-Tests-4.4-Java6 - Build # 42 - Still Failing
Build: https://builds.apache.org/job/Lucene-Solr-Tests-4.4-Java6/42/
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=2960, name=recoveryCmdExecutor-1417-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=2960, name=recoveryCmdExecutor-1417-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([384521C26DCC4024]: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=2960, name=recoveryCmdExecutor-1417-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=2960, name=recoveryCmdExecutor-1417-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([384521C26DCC4024]:0)
Build Log:
[...truncated 9086 lines...]
[junit4] Suite: org.apache.solr.cloud.BasicDistributedZkTest
[junit4] 2> 1016211 T2476 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /_m/
[junit4] 2> 1016217 T2476 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4] 2> Creating dataDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZkTest-1374549818977
[junit4] 2> 1016219 T2476 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 1016219 T2477 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 1016320 T2476 oasc.ZkTestServer.run start zk server on port:52623
[junit4] 2> 1016321 T2476 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1016326 T2483 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4c63fba3 name:ZooKeeperConnection Watcher:127.0.0.1:52623 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1016326 T2476 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1016327 T2476 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 1016341 T2476 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1016343 T2485 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2ff0ae59 name:ZooKeeperConnection Watcher:127.0.0.1:52623/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1016344 T2476 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1016344 T2476 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4] 2> 1016369 T2476 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4] 2> 1016373 T2476 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4] 2> 1016394 T2476 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4] 2> 1016398 T2476 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4] 2> 1016399 T2476 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4] 2> 1016457 T2476 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
[junit4] 2> 1016458 T2476 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4] 2> 1016571 T2476 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4] 2> 1016583 T2476 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4] 2> 1016878 T2476 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4] 2> 1016879 T2476 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4] 2> 1016885 T2476 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4] 2> 1016886 T2476 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4] 2> 1016891 T2476 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4] 2> 1016892 T2476 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4] 2> 1016921 T2476 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 1016922 T2476 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 1016926 T2476 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4] 2> 1016927 T2476 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4] 2> 1016930 T2476 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4] 2> 1016938 T2476 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4] 2> 1017283 T2476 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 1017288 T2476 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:52626
[junit4] 2> 1017289 T2476 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 1017289 T2476 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1017290 T2476 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374549819702
[junit4] 2> 1017290 T2476 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374549819702/'
[junit4] 2> 1017353 T2476 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374549819702/solr.xml
[junit4] 2> 1017429 T2476 oasc.CoreContainer.<init> New CoreContainer 199276426
[junit4] 2> 1017430 T2476 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374549819702/]
[junit4] 2> 1017432 T2476 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 1017432 T2476 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 1017433 T2476 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 1017433 T2476 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 1017434 T2476 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 1017434 T2476 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 1017435 T2476 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 1017435 T2476 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 1017436 T2476 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 1017436 T2476 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4] 2> 1017453 T2476 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 1017453 T2476 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:52623/solr
[junit4] 2> 1017454 T2476 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 1017455 T2476 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1017460 T2496 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4e31cb1d name:ZooKeeperConnection Watcher:127.0.0.1:52623 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1017460 T2476 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1017505 T2476 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4] 2> 1017518 T2476 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1017521 T2498 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@50063592 name:ZooKeeperConnection Watcher:127.0.0.1:52623/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1017521 T2476 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1017547 T2476 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 1017566 T2476 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 1017570 T2476 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 1017585 T2476 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:52626__m
[junit4] 2> 1017587 T2476 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:52626__m
[junit4] 2> 1017591 T2476 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 1017631 T2476 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 1017634 T2476 oasc.Overseer.start Overseer (id=90082496936935427-127.0.0.1:52626__m-n_0000000000) starting
[junit4] 2> 1017653 T2476 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 1017683 T2500 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 1017684 T2476 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 1017696 T2476 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 1017698 T2476 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1017701 T2499 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 1017705 T2501 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 1017706 T2501 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1017707 T2501 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 1019206 T2499 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1019207 T2499 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:52626__m",
[junit4] 2> "base_url":"http://127.0.0.1:52626/_m"}
[junit4] 2> 1019207 T2499 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with numShards 1
[junit4] 2> 1019207 T2499 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 1019232 T2498 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> 1019709 T2501 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 1019709 T2501 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374549819702/collection1
[junit4] 2> 1019709 T2501 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4] 2> 1019710 T2501 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 1019711 T2501 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4] 2> 1019712 T2501 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374549819702/collection1/'
[junit4] 2> 1019714 T2501 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374549819702/collection1/lib/classes/' to classloader
[junit4] 2> 1019715 T2501 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374549819702/collection1/lib/README' to classloader
[junit4] 2> 1019771 T2501 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4] 2> 1019909 T2501 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 1020011 T2501 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 1020028 T2501 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 1020833 T2501 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 1020834 T2501 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 1020835 T2501 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 1020855 T2501 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 1020859 T2501 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 1020875 T2501 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1020880 T2501 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1020885 T2501 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 1020887 T2501 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 1020887 T2501 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 1020887 T2501 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 1020888 T2501 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 1020889 T2501 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 1020889 T2501 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 1020889 T2501 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374549819702/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZkTest-1374549818976/control/data/
[junit4] 2> 1020890 T2501 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@6a24eafa
[junit4] 2> 1020890 T2501 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374549818976/control/data
[junit4] 2> 1020891 T2501 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZkTest-1374549818976/control/data/index/
[junit4] 2> 1020891 T2501 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZkTest-1374549818976/control/data/index' doesn't exist. Creating new index...
[junit4] 2> 1020891 T2501 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374549818976/control/data/index
[junit4] 2> 1020896 T2501 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@27c58846 lockFactory=org.apache.lucene.store.NativeFSLockFactory@3616c3a8),segFN=segments_1,generation=1}
[junit4] 2> 1020896 T2501 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1020900 T2501 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 1020901 T2501 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 1020901 T2501 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1020902 T2501 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 1020902 T2501 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 1020903 T2501 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 1020903 T2501 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 1020904 T2501 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 1020904 T2501 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 1020914 T2501 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 1020921 T2501 oass.SolrIndexSearcher.<init> Opening Searcher@70ee33c1 main
[junit4] 2> 1020930 T2501 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 1020930 T2501 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 1020934 T2502 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@70ee33c1 main{StandardDirectoryReader(segments_1:1)}
[junit4] 2> 1020935 T2501 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 1020935 T2501 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:52626/_m collection:control_collection shard:shard1
[junit4] 2> 1020936 T2501 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=30000&socketTimeout=30000&retry=false
[junit4] 2> 1020956 T2501 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4] 2> 1020995 T2501 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 1021022 T2501 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 1021023 T2501 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 1021023 T2501 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:52626/_m/collection1/
[junit4] 2> 1021023 T2501 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 1021024 T2501 oasc.SyncStrategy.syncToMe http://127.0.0.1:52626/_m/collection1/ has no replicas
[junit4] 2> 1021024 T2501 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:52626/_m/collection1/ shard1
[junit4] 2> 1021024 T2501 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4] 2> 1022247 T2499 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1022336 T2498 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> 1022407 T2501 oasc.ZkController.register We are http://127.0.0.1:52626/_m/collection1/ and leader is http://127.0.0.1:52626/_m/collection1/
[junit4] 2> 1022407 T2501 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:52626/_m
[junit4] 2> 1022407 T2501 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 1022407 T2501 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 1022408 T2501 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1022410 T2501 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1022411 T2476 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J1
[junit4] 2> 1022412 T2476 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 1022413 T2476 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 1022424 T2476 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4] 2> 1022425 T2476 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1022427 T2505 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@cc19332 name:ZooKeeperConnection Watcher:127.0.0.1:52623/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1022428 T2476 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1022430 T2476 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1022432 T2476 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4] 2> 1022814 T2476 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 1022817 T2476 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:52630
[junit4] 2> 1022818 T2476 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 1022818 T2476 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1022819 T2476 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374549825192
[junit4] 2> 1022819 T2476 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374549825192/'
[junit4] 2> 1022857 T2476 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374549825192/solr.xml
[junit4] 2> 1022950 T2476 oasc.CoreContainer.<init> New CoreContainer 1627552441
[junit4] 2> 1022951 T2476 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374549825192/]
[junit4] 2> 1022953 T2476 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 1022953 T2476 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 1022954 T2476 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 1022954 T2476 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 1022955 T2476 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 1022955 T2476 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 1022956 T2476 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 1022956 T2476 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 1022957 T2476 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 1022957 T2476 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4] 2> 1022994 T2476 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 1022995 T2476 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:52623/solr
[junit4] 2> 1022996 T2476 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 1022997 T2476 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1023007 T2516 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@69c73970 name:ZooKeeperConnection Watcher:127.0.0.1:52623 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1023008 T2476 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1023039 T2476 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4] 2> 1023051 T2476 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1023054 T2518 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@70932ee4 name:ZooKeeperConnection Watcher:127.0.0.1:52623/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1023054 T2476 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1023101 T2476 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1023867 T2499 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1023868 T2499 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:52626__m",
[junit4] 2> "base_url":"http://127.0.0.1:52626/_m"}
[junit4] 2> 1023914 T2498 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> 1023914 T2518 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> 1023914 T2505 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> 1024105 T2476 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:52630__m
[junit4] 2> 1024108 T2476 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:52630__m
[junit4] 2> 1024131 T2505 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> 1024131 T2518 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> 1024132 T2498 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1024132 T2498 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> 1024133 T2505 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1024134 T2518 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1024145 T2519 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 1024145 T2519 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1024159 T2519 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 1025425 T2499 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1025426 T2499 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:52630__m",
[junit4] 2> "base_url":"http://127.0.0.1:52630/_m"}
[junit4] 2> 1025426 T2499 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with numShards 2
[junit4] 2> 1025426 T2499 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 1025445 T2505 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> 1025445 T2518 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> 1025445 T2498 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> 1026162 T2519 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 1026162 T2519 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374549825192/collection1
[junit4] 2> 1026162 T2519 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 1026163 T2519 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 1026164 T2519 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 1026165 T2519 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374549825192/collection1/'
[junit4] 2> 1026167 T2519 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374549825192/collection1/lib/README' to classloader
[junit4] 2> 1026167 T2519 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374549825192/collection1/lib/classes/' to classloader
[junit4] 2> 1026254 T2519 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4] 2> 1026349 T2519 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 1026452 T2519 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 1026465 T2519 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 1027251 T2519 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 1027251 T2519 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 1027252 T2519 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 1027278 T2519 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 1027283 T2519 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 1027298 T2519 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1027304 T2519 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1027309 T2519 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 1027310 T2519 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 1027310 T2519 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 1027311 T2519 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 1027312 T2519 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 1027312 T2519 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 1027312 T2519 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 1027313 T2519 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374549825192/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZkTest-1374549818976/jetty1/
[junit4] 2> 1027313 T2519 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@6a24eafa
[junit4] 2> 1027314 T2519 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374549818976/jetty1
[junit4] 2> 1027314 T2519 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZkTest-1374549818976/jetty1/index/
[junit4] 2> 1027315 T2519 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZkTest-1374549818976/jetty1/index' doesn't exist. Creating new index...
[junit4] 2> 1027315 T2519 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374549818976/jetty1/index
[junit4] 2> 1027319 T2519 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@12ec8a62 lockFactory=org.apache.lucene.store.NativeFSLockFactory@31d5b497),segFN=segments_1,generation=1}
[junit4] 2> 1027319 T2519 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1027324 T2519 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 1027324 T2519 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 1027325 T2519 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1027326 T2519 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 1027326 T2519 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 1027326 T2519 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 1027327 T2519 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 1027327 T2519 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 1027328 T2519 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 1027338 T2519 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 1027345 T2519 oass.SolrIndexSearcher.<init> Opening Searcher@9755dd1 main
[junit4] 2> 1027347 T2519 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 1027347 T2519 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 1027352 T2520 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@9755dd1 main{StandardDirectoryReader(segments_1:1)}
[junit4] 2> 1027354 T2519 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 1027354 T2519 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:52630/_m collection:collection1 shard:shard1
[junit4] 2> 1027354 T2519 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=30000&socketTimeout=30000&retry=false
[junit4] 2> 1027371 T2519 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1027410 T2519 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 1027417 T2519 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 1027417 T2519 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 1027418 T2519 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:52630/_m/collection1/
[junit4] 2> 1027418 T2519 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 1027418 T2519 oasc.SyncStrategy.syncToMe http://127.0.0.1:52630/_m/collection1/ has no replicas
[junit4] 2> 1027418 T2519 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:52630/_m/collection1/ shard1
[junit4] 2> 1027419 T2519 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1028457 T2499 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1028527 T2505 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> 1028527 T2498 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> 1028527 T2518 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> 1028572 T2519 oasc.ZkController.register We are http://127.0.0.1:52630/_m/collection1/ and leader is http://127.0.0.1:52630/_m/collection1/
[junit4] 2> 1028572 T2519 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:52630/_m
[junit4] 2> 1028572 T2519 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 1028572 T2519 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 1028573 T2519 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1028576 T2519 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1028577 T2476 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J1
[junit4] 2> 1028578 T2476 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 1028578 T2476 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 1028871 T2476 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 1028874 T2476 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:52633
[junit4] 2> 1028875 T2476 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 1028875 T2476 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1028876 T2476 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374549831348
[junit4] 2> 1028876 T2476 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374549831348/'
[junit4] 2> 1028912 T2476 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374549831348/solr.xml
[junit4] 2> 1028990 T2476 oasc.CoreContainer.<init> New CoreContainer 686655823
[junit4] 2> 1028991 T2476 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374549831348/]
[junit4] 2> 1028993 T2476 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 1028993 T2476 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 1028994 T2476 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 1028994 T2476 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 1028995 T2476 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 1028995 T2476 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 1028996 T2476 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 1028996 T2476 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 1028997 T2476 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 1028997 T2476 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4] 2> 1029014 T2476 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 1029015 T2476 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:52623/solr
[junit4] 2> 1029015 T2476 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 1029016 T2476 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1029022 T2532 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2d1b687 name:ZooKeeperConnection Watcher:127.0.0.1:52623 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1029023 T2476 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1029043 T2476 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4] 2> 1029055 T2476 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1029058 T2534 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@195201e3 name:ZooKeeperConnection Watcher:127.0.0.1:52623/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1029058 T2476 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1029073 T2476 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1030052 T2499 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1030053 T2499 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:52630__m",
[junit4] 2> "base_url":"http://127.0.0.1:52630/_m"}
[junit4] 2> 1030073 T2505 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> 1030073 T2518 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> 1030073 T2498 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> 1030073 T2534 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> 1030094 T2476 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:52633__m
[junit4] 2> 1030100 T2476 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:52633__m
[junit4] 2> 1030108 T2505 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> 1030108 T2534 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> 1030108 T2518 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> 1030109 T2498 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 1030109 T2498 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> 1030110 T2505 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 1030110 T2534 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 1030111 T2518 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 1030117 T2535 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 1030117 T2535 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1030123 T2535 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 1031597 T2499 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1031599 T2499 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:52633__m",
[junit4] 2> "base_url":"http://127.0.0.1:52633/_m"}
[junit4] 2> 1031599 T2499 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4] 2> 1031599 T2499 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 1031792 T2505 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> 1031792 T2534 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> 1031792 T2518 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> 1031792 T2498 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> 1032126 T2535 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 1032126 T2535 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374549831348/collection1
[junit4] 2> 1032126 T2535 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 1032127 T2535 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 1032128 T2535 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 1032129 T2535 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374549831348/collection1/'
[junit4] 2> 1032131 T2535 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374549831348/collection1/lib/classes/' to classloader
[junit4] 2> 1032131 T2535 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374549831348/collection1/lib/README' to classloader
[junit4] 2> 1032191 T2535 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4] 2> 1032263 T2535 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 1032366 T2535 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 1032378 T2535 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 1033131 T2535 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 1033131 T2535 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 1033132 T2535 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 1033145 T2535 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 1033150 T2535 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 1033165 T2535 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1033173 T2535 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1033178 T2535 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 1033179 T2535 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 1033179 T2535 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 1033179 T2535 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 1033181 T2535 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 1033181 T2535 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 1033181 T2535 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 1033182 T2535 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374549831348/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZkTest-1374549818976/jetty2/
[junit4] 2> 1033182 T2535 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@6a24eafa
[junit4] 2> 1033183 T2535 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374549818976/jetty2
[junit4] 2> 1033183 T2535 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZkTest-1374549818976/jetty2/index/
[junit4] 2> 1033183 T2535 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZkTest-1374549818976/jetty2/index' doesn't exist. Creating new index...
[junit4] 2> 1033184 T2535 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374549818976/jetty2/index
[junit4] 2> 1033187 T2535 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@27453268 lockFactory=org.apache.lucene.store.NativeFSLockFactory@6d89d9eb),segFN=segments_1,generation=1}
[junit4] 2> 1033188 T2535 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1033192 T2535 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 1033193 T2535 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 1033193 T2535 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1033194 T2535 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 1033195 T2535 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 1033195 T2535 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 1033195 T2535 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 1033196 T2535 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 1033197 T2535 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 1033206 T2535 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 1033217 T2535 oass.SolrIndexSearcher.<init> Opening Searcher@4c122519 main
[junit4] 2> 1033226 T2535 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 1033227 T2535 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 1033231 T2536 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@4c122519 main{StandardDirectoryReader(segments_1:1)}
[junit4] 2> 1033233 T2535 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 1033234 T2535 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:52633/_m collection:collection1 shard:shard2
[junit4] 2> 1033234 T2535 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=30000&socketTimeout=30000&retry=false
[junit4] 2> 1033255 T2535 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4] 2> 1033352 T2535 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
[junit4] 2> 1033394 T2535 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 1033394 T2535 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 1033394 T2535 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:52633/_m/collection1/
[junit4] 2> 1033395 T2535 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 1033395 T2535 oasc.SyncStrategy.syncToMe http://127.0.0.1:52633/_m/collection1/ has no replicas
[junit4] 2> 1033395 T2535 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:52633/_m/collection1/ shard2
[junit4] 2> 1033396 T2535 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4] 2> 1034856 T2499 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1034907 T2505 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> 1034907 T2518 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> 1034907 T2534 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> 1034907 T2498 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> 1034971 T2535 oasc.ZkController.register We are http://127.0.0.1:52633/_m/collection1/ and leader is http://127.0.0.1:52633/_m/collection1/
[junit4] 2> 1034971 T2535 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:52633/_m
[junit4] 2> 1034971 T2535 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 1034971 T2535 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 1034972 T2535 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1034978 T2535 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1034979 T2476 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J1
[junit4] 2> 1034980 T2476 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 1034980 T2476 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 1035335 T2476 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 1035339 T2476 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:52636
[junit4] 2> 1035339 T2476 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 1035340 T2476 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1035340 T2476 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374549837750
[junit4] 2> 1035341 T2476 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374549837750/'
[junit4] 2> 1035406 T2476 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374549837750/solr.xml
[junit4] 2> 1035507 T2476 oasc.CoreContainer.<init> New CoreContainer 1185845148
[junit4] 2> 1035508 T2476 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374549837750/]
[junit4] 2> 1035510 T2476 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 1035510 T2476 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 1035511 T2476 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 1035511 T2476 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 1035512 T2476 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 1035512 T2476 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 1035513 T2476 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 1035513 T2476 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 1035514 T2476 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 1035514 T2476 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4] 2> 1035538 T2476 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 1035539 T2476 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:52623/solr
[junit4] 2> 1035539 T2476 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 1035540 T2476 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1035544 T2548 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6e566f04 name:ZooKeeperConnection Watcher:127.0.0.1:52623 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1035544 T2476 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1035571 T2476 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4] 2> 1035583 T2476 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1035586 T2550 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6bf7754f name:ZooKeeperConnection Watcher:127.0.0.1:52623/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1035586 T2476 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1035603 T2476 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1036464 T2499 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1036465 T2499 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:52633__m",
[junit4] 2> "base_url":"http://127.0.0.1:52633/_m"}
[junit4] 2> 1036504 T2505 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> 1036504 T2534 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> 1036504 T2518 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> 1036504 T2498 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> 1036504 T2550 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> 1036608 T2476 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:52636__m
[junit4] 2> 1036626 T2476 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:52636__m
[junit4] 2> 1036760 T2518 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> 1036760 T2534 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> 1036760 T2505 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> 1036761 T2498 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 1036761 T2550 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 1036762 T2498 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> 1036762 T2550 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> 1036763 T2518 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 1036763 T2534 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 1036764 T2505 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 1036770 T2551 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 1036770 T2551 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1036776 T2551 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 1038012 T2499 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1038013 T2499 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:52636__m",
[junit4] 2> "base_url":"http://127.0.0.1:52636/_m"}
[junit4] 2> 1038013 T2499 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4] 2> 1038013 T2499 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 1038194 T2550 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> 1038194 T2518 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> 1038194 T2534 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> 1038194 T2498 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> 1038194 T2505 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> 1038778 T2551 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 1038778 T2551 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374549837750/collection1
[junit4] 2> 1038778 T2551 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 1038779 T2551 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 1038780 T2551 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 1038781 T2551 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374549837750/collection1/'
[junit4] 2> 1038783 T2551 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374549837750/collection1/lib/classes/' to classloader
[junit4] 2> 1038783 T2551 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374549837750/collection1/lib/README' to classloader
[junit4] 2> 1038837 T2551 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4] 2> 1038936 T2551 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 1039038 T2551 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 1039051 T2551 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 1039888 T2551 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 1039888 T2551 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 1039889 T2551 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 1039902 T2551 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 1039907 T2551 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 1039927 T2551 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1039934 T2551 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1039939 T2551 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 1039941 T2551 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 1039941 T2551 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 1039941 T2551 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 1039942 T2551 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 1039943 T2551 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 1039943 T2551 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 1039943 T2551 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374549837750/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZkTest-1374549818976/jetty3/
[junit4] 2> 1039944 T2551 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@6a24eafa
[junit4] 2> 1039945 T2551 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374549818976/jetty3
[junit4] 2> 1039945 T2551 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZkTest-1374549818976/jetty3/index/
[junit4] 2> 1039945 T2551 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZkTest-1374549818976/jetty3/index' doesn't exist. Creating new index...
[junit4] 2> 1039946 T2551 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374549818976/jetty3/index
[junit4] 2> 1039949 T2551 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@54b0b8f7 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1ea1cf1e),segFN=segments_1,generation=1}
[junit4] 2> 1039949 T2551 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1039954 T2551 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 1039955 T2551 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 1039955 T2551 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1039956 T2551 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 1039957 T2551 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 1039957 T2551 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 1039957 T2551 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 1039958 T2551 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 1039958 T2551 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 1039970 T2551 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 1039978 T2551 oass.SolrIndexSearcher.<init> Opening Searcher@127de660 main
[junit4] 2> 1039979 T2551 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 1039979 T2551 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 1039984 T2552 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@127de660 main{StandardDirectoryReader(segments_1:1)}
[junit4] 2> 1039986 T2551 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 1039986 T2551 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:52636/_m collection:collection1 shard:shard1
[junit4] 2> 1039987 T2551 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=30000&socketTimeout=30000&retry=false
[junit4] 2> 1040017 T2551 oasc.ZkController.register We are http://127.0.0.1:52636/_m/collection1/ and leader is http://127.0.0.1:52630/_m/collection1/
[junit4] 2> 1040017 T2551 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:52636/_m
[junit4] 2> 1040018 T2551 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4] 2> 1040018 T2551 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4] 2> ASYNC NEW_CORE C1608 name=collection1 org.apache.solr.core.SolrCore@35775d14 url=http://127.0.0.1:52636/_m/collection1 node=127.0.0.1:52636__m C1608_STATE=coll:collection1 core:collection1 props:{state=down, core=collection1, node_name=127.0.0.1:52636__m, base_url=http://127.0.0.1:52636/_m}
[junit4] 2> 1040019 T2553 C1608 P52636 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4] 2> 1040019 T2551 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1040020 T2553 C1608 P52636 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4] 2> 1040020 T2553 C1608 P52636 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4] 2> 1040021 T2553 C1608 P52636 oasc.ZkController.publish numShards not found on descriptor - readi
[...truncated too long message...]
onImpl.open(ManagedClientConnectionImpl.java:294)
[junit4] 2> at org.apache.http.impl.client.DefaultRequestDirector.tryConnect(DefaultRequestDirector.java:645)
[junit4] 2> at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:480)
[junit4] 2> at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:906)
[junit4] 2> at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:805)
[junit4] 2> at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:784)
[junit4] 2> at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:365)
[junit4] 2> at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:180)
[junit4] 2> at org.apache.solr.cloud.SyncStrategy$1.run(SyncStrategy.java:291)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1146)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
[junit4] 2> at java.lang.Thread.run(Thread.java:679)
[junit4] 2> NOTE: test params are: codec=Asserting, sim=RandomSimilarityProvider(queryNorm=true,coord=crazy): {}, locale=de_CH, timezone=PST8PDT
[junit4] 2> NOTE: FreeBSD 9.1-RELEASE-p3 amd64/Sun Microsystems Inc. 1.6.0_32 (64-bit)/cpus=16,threads=2,free=157544584,total=443219968
[junit4] 2> NOTE: All tests run in this JVM: [CoreAdminCreateDiscoverTest, UpdateParamsTest, LeaderElectionIntegrationTest, TestDefaultSearchFieldResource, TestHashPartitioner, ChaosMonkeySafeLeaderTest, SimplePostToolTest, BasicDistributedZk2Test, TestManagedSchema, IndexReaderFactoryTest, SuggesterWFSTTest, TestElisionMultitermQuery, TestDynamicFieldResource, IndexBasedSpellCheckerTest, CurrencyFieldXmlFileTest, TestCSVResponseWriter, SpellCheckCollatorTest, StatsComponentTest, TestComponentsName, TestAddFieldRealTimeGet, TestBM25SimilarityFactory, TestSystemIdResolver, TestIndexSearcher, TestArbitraryIndexDir, DOMUtilTest, NumericFieldsTest, TestCodecSupport, SuggesterTSTTest, HighlighterTest, ZkNodePropsTest, TestPartialUpdateDeduplication, NotRequiredUniqueKeyTest, TestDistributedGrouping, TestWordDelimiterFilterFactory, TestStressReorder, SolrPluginUtilsTest, TestClassNameShortening, DisMaxRequestHandlerTest, TestStressLucene, TestZkChroot, TestRecovery, BadIndexSchemaTest, OpenCloseCoreStressTest, SpellPossibilityIteratorTest, NoCacheHeaderTest, BasicHdfsTest, PathHierarchyTokenizerFactoryTest, XmlUpdateRequestHandlerTest, DateMathParserTest, CurrencyFieldOpenExchangeTest, DirectSolrSpellCheckerTest, SolrCoreCheckLockOnStartupTest, DefaultValueUpdateProcessorTest, TestDefaultSimilarityFactory, TestSuggestSpellingConverter, TestSchemaVersionResource, TestOmitPositions, SolrRequestParserTest, TestDistributedSearch, DirectUpdateHandlerTest, StandardRequestHandlerTest, TestUtils, CachingDirectoryFactoryTest, RequestHandlersTest, SolrCmdDistributorTest, TestCollationField, HardAutoCommitTest, TestSchemaNameResource, PingRequestHandlerTest, QueryResultKeyTest, OutputWriterTest, TestRTGBase, OpenExchangeRatesOrgProviderTest, TestAnalyzedSuggestions, SpellCheckComponentTest, TermVectorComponentDistributedTest, BasicDistributedZkTest]
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=BasicDistributedZkTest -Dtests.seed=384521C26DCC4024 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=de_CH -Dtests.timezone=PST8PDT -Dtests.file.encoding=ISO8859-1
[junit4] ERROR 0.00s J1 | 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=2960, name=recoveryCmdExecutor-1417-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([384521C26DCC4024]:0)Throwable #2: com.carrotsearch.randomizedtesting.ThreadLeakError: There are still zombie threads that couldn't be terminated:
[junit4] > 1) Thread[id=2960, name=recoveryCmdExecutor-1417-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([384521C26DCC4024]:0)
[junit4] Completed on J1 in 230.70s, 1 test, 2 errors <<< FAILURES!
[...truncated 548 lines...]
BUILD FAILED
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/build.xml:395: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/build.xml:375: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/build.xml:39: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build.xml:181: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/common-build.xml:449: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/lucene/common-build.xml:1250: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/lucene/common-build.xml:893: There were test failures: 317 suites, 1337 tests, 2 suite-level errors, 612 ignored (5 assumptions)
Total time: 45 minutes 37 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure
[JENKINS] Lucene-Solr-Tests-4.4-Java6 - Build # 43 - Still Failing
Posted by Apache Jenkins Server <je...@builds.apache.org>.
Build: https://builds.apache.org/job/Lucene-Solr-Tests-4.4-Java6/43/
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=3020, name=recoveryCmdExecutor-1261-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=3020, name=recoveryCmdExecutor-1261-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([35AD0F7F06EAF33F]: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=3020, name=recoveryCmdExecutor-1261-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=3020, name=recoveryCmdExecutor-1261-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([35AD0F7F06EAF33F]:0)
Build Log:
[...truncated 9079 lines...]
[junit4] Suite: org.apache.solr.cloud.BasicDistributedZkTest
[junit4] 2> 864446 T2532 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /hl/
[junit4] 2> 864450 T2532 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4] 2> Creating dataDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J0/./solrtest-BasicDistributedZkTest-1374573662777
[junit4] 2> 864452 T2532 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 864453 T2533 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 864554 T2532 oasc.ZkTestServer.run start zk server on port:45648
[junit4] 2> 864554 T2532 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 864583 T2539 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@51964eca name:ZooKeeperConnection Watcher:127.0.0.1:45648 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 864584 T2532 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 864584 T2532 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 864602 T2532 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 864603 T2541 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@36eb16bf name:ZooKeeperConnection Watcher:127.0.0.1:45648/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 864604 T2532 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 864604 T2532 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4] 2> 864615 T2532 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4] 2> 864617 T2532 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4] 2> 864619 T2532 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4] 2> 864628 T2532 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4] 2> 864628 T2532 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4] 2> 864642 T2532 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
[junit4] 2> 864643 T2532 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4] 2> 864746 T2532 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4] 2> 864747 T2532 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4] 2> 864750 T2532 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4] 2> 864750 T2532 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4] 2> 864760 T2532 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4] 2> 864761 T2532 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4] 2> 864764 T2532 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4] 2> 864764 T2532 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4] 2> 864767 T2532 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 864768 T2532 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 864775 T2532 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4] 2> 864776 T2532 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4] 2> 864778 T2532 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4] 2> 864779 T2532 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4] 2> 865052 T2532 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 865056 T2532 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:45653
[junit4] 2> 865057 T2532 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 865057 T2532 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 865058 T2532 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374573663114
[junit4] 2> 865058 T2532 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374573663114/'
[junit4] 2> 865094 T2532 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374573663114/solr.xml
[junit4] 2> 865164 T2532 oasc.CoreContainer.<init> New CoreContainer 1117383453
[junit4] 2> 865165 T2532 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374573663114/]
[junit4] 2> 865166 T2532 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 865167 T2532 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 865167 T2532 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 865168 T2532 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 865168 T2532 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 865169 T2532 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 865169 T2532 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 865169 T2532 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 865170 T2532 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 865170 T2532 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4] 2> 865187 T2532 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 865187 T2532 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:45648/solr
[junit4] 2> 865188 T2532 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 865189 T2532 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 865191 T2552 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@71adf14 name:ZooKeeperConnection Watcher:127.0.0.1:45648 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 865192 T2532 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 865203 T2532 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4] 2> 865215 T2532 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 865216 T2554 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4837ce5a name:ZooKeeperConnection Watcher:127.0.0.1:45648/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 865217 T2532 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 865223 T2532 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 865227 T2532 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 865237 T2532 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 865239 T2532 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:45653_hl
[junit4] 2> 865246 T2532 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:45653_hl
[junit4] 2> 865248 T2532 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 865266 T2532 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 865269 T2532 oasc.Overseer.start Overseer (id=90084059564343299-127.0.0.1:45653_hl-n_0000000000) starting
[junit4] 2> 865281 T2532 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 865293 T2556 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 865294 T2532 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 865296 T2532 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 865297 T2532 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 865299 T2555 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 865304 T2557 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 865304 T2557 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 865305 T2557 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 866802 T2555 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 866803 T2555 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:45653_hl",
[junit4] 2> "base_url":"http://127.0.0.1:45653/hl"}
[junit4] 2> 866803 T2555 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with numShards 1
[junit4] 2> 866803 T2555 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 866827 T2554 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> 867307 T2557 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 867307 T2557 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374573663114/collection1
[junit4] 2> 867307 T2557 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4] 2> 867308 T2557 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 867308 T2557 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4] 2> 867310 T2557 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374573663114/collection1/'
[junit4] 2> 867312 T2557 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374573663114/collection1/lib/README' to classloader
[junit4] 2> 867312 T2557 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374573663114/collection1/lib/classes/' to classloader
[junit4] 2> 867374 T2557 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4] 2> 867444 T2557 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 867545 T2557 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 867557 T2557 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 868256 T2557 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 868256 T2557 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 868257 T2557 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 868270 T2557 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 868274 T2557 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 868287 T2557 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 868291 T2557 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 868295 T2557 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 868296 T2557 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 868297 T2557 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 868297 T2557 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 868298 T2557 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 868298 T2557 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 868298 T2557 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 868299 T2557 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374573663114/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZkTest-1374573662776/control/data/
[junit4] 2> 868299 T2557 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@6f978b94
[junit4] 2> 868300 T2557 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374573662776/control/data
[junit4] 2> 868300 T2557 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZkTest-1374573662776/control/data/index/
[junit4] 2> 868300 T2557 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZkTest-1374573662776/control/data/index' doesn't exist. Creating new index...
[junit4] 2> 868301 T2557 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374573662776/control/data/index
[junit4] 2> 868305 T2557 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@2a4d29fe lockFactory=org.apache.lucene.store.NativeFSLockFactory@1827d33e),segFN=segments_1,generation=1}
[junit4] 2> 868305 T2557 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 868309 T2557 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 868309 T2557 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 868310 T2557 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 868310 T2557 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 868311 T2557 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 868311 T2557 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 868311 T2557 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 868312 T2557 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 868312 T2557 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 868321 T2557 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 868328 T2557 oass.SolrIndexSearcher.<init> Opening Searcher@3d24a549 main
[junit4] 2> 868330 T2557 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 868330 T2557 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 868333 T2558 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@3d24a549 main{StandardDirectoryReader(segments_1:1)}
[junit4] 2> 868334 T2557 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 868334 T2557 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:45653/hl collection:control_collection shard:shard1
[junit4] 2> 868334 T2557 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=30000&socketTimeout=30000&retry=false
[junit4] 2> 868349 T2557 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4] 2> 868355 T2557 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 868358 T2557 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 868358 T2557 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 868358 T2557 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:45653/hl/collection1/
[junit4] 2> 868358 T2557 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 868359 T2557 oasc.SyncStrategy.syncToMe http://127.0.0.1:45653/hl/collection1/ has no replicas
[junit4] 2> 868359 T2557 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:45653/hl/collection1/ shard1
[junit4] 2> 868359 T2557 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4] 2> 869833 T2555 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 869859 T2554 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> 869905 T2557 oasc.ZkController.register We are http://127.0.0.1:45653/hl/collection1/ and leader is http://127.0.0.1:45653/hl/collection1/
[junit4] 2> 869905 T2557 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:45653/hl
[junit4] 2> 869905 T2557 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 869905 T2557 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 869906 T2557 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 869913 T2557 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 869914 T2532 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J0
[junit4] 2> 869914 T2532 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 869915 T2532 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 869924 T2532 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4] 2> 869925 T2532 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 869928 T2561 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4ec3724d name:ZooKeeperConnection Watcher:127.0.0.1:45648/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 869928 T2532 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 869929 T2532 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 869931 T2532 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4] 2> 870200 T2532 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 870203 T2532 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:48543
[junit4] 2> 870204 T2532 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 870204 T2532 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 870205 T2532 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374573668256
[junit4] 2> 870205 T2532 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374573668256/'
[junit4] 2> 870242 T2532 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374573668256/solr.xml
[junit4] 2> 870351 T2532 oasc.CoreContainer.<init> New CoreContainer 1255344109
[junit4] 2> 870352 T2532 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374573668256/]
[junit4] 2> 870354 T2532 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 870355 T2532 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 870355 T2532 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 870356 T2532 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 870356 T2532 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 870357 T2532 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 870357 T2532 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 870357 T2532 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 870358 T2532 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 870358 T2532 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4] 2> 870384 T2532 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 870385 T2532 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:45648/solr
[junit4] 2> 870385 T2532 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 870386 T2532 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 870390 T2572 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@64ad7efb name:ZooKeeperConnection Watcher:127.0.0.1:45648 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 870390 T2532 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 870393 T2532 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4] 2> 870410 T2532 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 870413 T2574 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2a7a879c name:ZooKeeperConnection Watcher:127.0.0.1:45648/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 870413 T2532 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 870425 T2532 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 871365 T2555 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 871366 T2555 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:45653_hl",
[junit4] 2> "base_url":"http://127.0.0.1:45653/hl"}
[junit4] 2> 871383 T2574 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> 871383 T2561 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> 871383 T2554 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> 871429 T2532 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:48543_hl
[junit4] 2> 871432 T2532 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:48543_hl
[junit4] 2> 871435 T2574 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> 871436 T2554 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 871436 T2561 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 871436 T2554 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> 871436 T2561 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> 871438 T2574 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 871448 T2575 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 871449 T2575 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 871451 T2575 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 872888 T2555 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 872889 T2555 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:48543_hl",
[junit4] 2> "base_url":"http://127.0.0.1:48543/hl"}
[junit4] 2> 872889 T2555 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with numShards 2
[junit4] 2> 872889 T2555 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 872906 T2554 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> 872906 T2561 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> 872906 T2574 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> 873453 T2575 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 873453 T2575 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374573668256/collection1
[junit4] 2> 873453 T2575 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 873454 T2575 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 873454 T2575 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 873456 T2575 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374573668256/collection1/'
[junit4] 2> 873457 T2575 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374573668256/collection1/lib/README' to classloader
[junit4] 2> 873458 T2575 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374573668256/collection1/lib/classes/' to classloader
[junit4] 2> 873516 T2575 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4] 2> 873576 T2575 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 873677 T2575 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 873688 T2575 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 874300 T2575 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 874300 T2575 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 874301 T2575 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 874314 T2575 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 874318 T2575 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 874330 T2575 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 874335 T2575 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 874339 T2575 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 874340 T2575 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 874340 T2575 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 874341 T2575 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 874341 T2575 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 874342 T2575 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 874342 T2575 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 874342 T2575 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374573668256/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZkTest-1374573662776/jetty1/
[junit4] 2> 874343 T2575 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@6f978b94
[junit4] 2> 874344 T2575 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374573662776/jetty1
[junit4] 2> 874344 T2575 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZkTest-1374573662776/jetty1/index/
[junit4] 2> 874344 T2575 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZkTest-1374573662776/jetty1/index' doesn't exist. Creating new index...
[junit4] 2> 874344 T2575 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374573662776/jetty1/index
[junit4] 2> 874348 T2575 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@21e5faa3 lockFactory=org.apache.lucene.store.NativeFSLockFactory@247918b8),segFN=segments_1,generation=1}
[junit4] 2> 874348 T2575 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 874352 T2575 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 874352 T2575 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 874353 T2575 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 874354 T2575 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 874354 T2575 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 874354 T2575 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 874355 T2575 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 874355 T2575 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 874356 T2575 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 874365 T2575 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 874372 T2575 oass.SolrIndexSearcher.<init> Opening Searcher@5d9fd5d3 main
[junit4] 2> 874373 T2575 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 874373 T2575 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 874378 T2576 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@5d9fd5d3 main{StandardDirectoryReader(segments_1:1)}
[junit4] 2> 874379 T2575 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 874379 T2575 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:48543/hl collection:collection1 shard:shard1
[junit4] 2> 874380 T2575 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=30000&socketTimeout=30000&retry=false
[junit4] 2> 874395 T2575 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 874414 T2575 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 874417 T2575 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 874417 T2575 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 874417 T2575 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:48543/hl/collection1/
[junit4] 2> 874417 T2575 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 874418 T2575 oasc.SyncStrategy.syncToMe http://127.0.0.1:48543/hl/collection1/ has no replicas
[junit4] 2> 874418 T2575 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:48543/hl/collection1/ shard1
[junit4] 2> 874418 T2575 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 875915 T2555 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 875940 T2554 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> 875940 T2561 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> 875940 T2574 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> 875953 T2575 oasc.ZkController.register We are http://127.0.0.1:48543/hl/collection1/ and leader is http://127.0.0.1:48543/hl/collection1/
[junit4] 2> 875953 T2575 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:48543/hl
[junit4] 2> 875953 T2575 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 875953 T2575 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 875954 T2575 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 875955 T2575 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 875956 T2532 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J0
[junit4] 2> 875957 T2532 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 875957 T2532 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 876232 T2532 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 876235 T2532 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:48566
[junit4] 2> 876236 T2532 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 876236 T2532 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 876237 T2532 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374573674293
[junit4] 2> 876237 T2532 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374573674293/'
[junit4] 2> 876273 T2532 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374573674293/solr.xml
[junit4] 2> 876343 T2532 oasc.CoreContainer.<init> New CoreContainer 1802833028
[junit4] 2> 876344 T2532 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374573674293/]
[junit4] 2> 876345 T2532 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 876346 T2532 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 876346 T2532 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 876347 T2532 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 876347 T2532 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 876348 T2532 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 876348 T2532 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 876348 T2532 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 876349 T2532 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 876349 T2532 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4] 2> 876366 T2532 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 876366 T2532 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:45648/solr
[junit4] 2> 876367 T2532 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 876368 T2532 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 876371 T2588 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5188e539 name:ZooKeeperConnection Watcher:127.0.0.1:45648 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 876371 T2532 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 876385 T2532 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4] 2> 876397 T2532 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 876398 T2590 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1f394ed8 name:ZooKeeperConnection Watcher:127.0.0.1:45648/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 876399 T2532 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 876408 T2532 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 877411 T2532 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:48566_hl
[junit4] 2> 877419 T2532 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:48566_hl
[junit4] 2> 877450 T2574 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> 877451 T2561 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 877451 T2554 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 877451 T2561 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> 877451 T2590 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 877451 T2554 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> 877452 T2574 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 877465 T2555 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 877466 T2555 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:48543_hl",
[junit4] 2> "base_url":"http://127.0.0.1:48543/hl"}
[junit4] 2> 877470 T2591 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 877471 T2591 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 877473 T2591 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 877481 T2555 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:48566_hl",
[junit4] 2> "base_url":"http://127.0.0.1:48566/hl"}
[junit4] 2> 877481 T2555 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4] 2> 877481 T2555 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 877486 T2561 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> 877486 T2574 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> 877486 T2590 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> 877498 T2554 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> 878474 T2591 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 878474 T2591 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374573674293/collection1
[junit4] 2> 878474 T2591 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 878475 T2591 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 878475 T2591 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 878477 T2591 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374573674293/collection1/'
[junit4] 2> 878478 T2591 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374573674293/collection1/lib/README' to classloader
[junit4] 2> 878479 T2591 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374573674293/collection1/lib/classes/' to classloader
[junit4] 2> 878532 T2591 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4] 2> 878596 T2591 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 878698 T2591 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 878709 T2591 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 879398 T2591 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 879398 T2591 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 879399 T2591 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 879412 T2591 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 879417 T2591 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 879431 T2591 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 879436 T2591 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 879442 T2591 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 879443 T2591 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 879443 T2591 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 879443 T2591 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 879444 T2591 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 879445 T2591 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 879445 T2591 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 879445 T2591 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374573674293/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZkTest-1374573662776/jetty2/
[junit4] 2> 879446 T2591 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@6f978b94
[junit4] 2> 879447 T2591 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374573662776/jetty2
[junit4] 2> 879447 T2591 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZkTest-1374573662776/jetty2/index/
[junit4] 2> 879447 T2591 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZkTest-1374573662776/jetty2/index' doesn't exist. Creating new index...
[junit4] 2> 879448 T2591 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374573662776/jetty2/index
[junit4] 2> 879451 T2591 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@392c2607 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1a2d16c7),segFN=segments_1,generation=1}
[junit4] 2> 879452 T2591 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 879455 T2591 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 879456 T2591 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 879456 T2591 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 879457 T2591 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 879458 T2591 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 879458 T2591 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 879458 T2591 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 879459 T2591 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 879459 T2591 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 879469 T2591 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 879476 T2591 oass.SolrIndexSearcher.<init> Opening Searcher@70eaf971 main
[junit4] 2> 879478 T2591 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 879478 T2591 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 879482 T2592 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@70eaf971 main{StandardDirectoryReader(segments_1:1)}
[junit4] 2> 879484 T2591 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 879484 T2591 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:48566/hl collection:collection1 shard:shard2
[junit4] 2> 879485 T2591 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=30000&socketTimeout=30000&retry=false
[junit4] 2> 879500 T2591 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4] 2> 879517 T2591 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
[junit4] 2> 879524 T2591 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 879525 T2591 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 879525 T2591 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:48566/hl/collection1/
[junit4] 2> 879525 T2591 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 879525 T2591 oasc.SyncStrategy.syncToMe http://127.0.0.1:48566/hl/collection1/ has no replicas
[junit4] 2> 879526 T2591 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:48566/hl/collection1/ shard2
[junit4] 2> 879526 T2591 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4] 2> 880501 T2555 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 880521 T2554 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> 880521 T2574 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> 880521 T2590 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> 880521 T2561 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> 880560 T2591 oasc.ZkController.register We are http://127.0.0.1:48566/hl/collection1/ and leader is http://127.0.0.1:48566/hl/collection1/
[junit4] 2> 880560 T2591 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:48566/hl
[junit4] 2> 880561 T2591 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 880561 T2591 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 880561 T2591 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 880563 T2591 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 880565 T2532 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J0
[junit4] 2> 880565 T2532 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 880566 T2532 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 881094 T2532 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 881098 T2532 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:48610
[junit4] 2> 881098 T2532 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 881099 T2532 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 881100 T2532 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374573678902
[junit4] 2> 881100 T2532 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374573678902/'
[junit4] 2> 881162 T2532 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374573678902/solr.xml
[junit4] 2> 881241 T2532 oasc.CoreContainer.<init> New CoreContainer 320186832
[junit4] 2> 881242 T2532 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374573678902/]
[junit4] 2> 881243 T2532 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 881244 T2532 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 881244 T2532 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 881245 T2532 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 881245 T2532 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 881245 T2532 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 881246 T2532 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 881246 T2532 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 881247 T2532 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 881247 T2532 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4] 2> 881264 T2532 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 881265 T2532 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:45648/solr
[junit4] 2> 881265 T2532 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 881266 T2532 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 881268 T2604 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@733fa079 name:ZooKeeperConnection Watcher:127.0.0.1:45648 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 881269 T2532 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 881270 T2532 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4] 2> 881283 T2532 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 881285 T2606 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@163f71b4 name:ZooKeeperConnection Watcher:127.0.0.1:45648/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 881285 T2532 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 881289 T2532 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 882027 T2555 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 882028 T2555 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:48566_hl",
[junit4] 2> "base_url":"http://127.0.0.1:48566/hl"}
[junit4] 2> 882108 T2561 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> 882108 T2574 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> 882108 T2590 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> 882108 T2606 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> 882108 T2554 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> 882291 T2532 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:48610_hl
[junit4] 2> 882293 T2532 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:48610_hl
[junit4] 2> 882331 T2590 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> 882331 T2606 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> 882331 T2574 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> 882332 T2554 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 882332 T2561 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 882333 T2590 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 882333 T2561 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> 882333 T2554 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> 882334 T2606 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 882334 T2574 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 882339 T2607 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 882339 T2607 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 882341 T2607 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 883612 T2555 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 883613 T2555 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:48610_hl",
[junit4] 2> "base_url":"http://127.0.0.1:48610/hl"}
[junit4] 2> 883613 T2555 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4] 2> 883613 T2555 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 883650 T2554 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> 883651 T2590 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> 883651 T2574 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> 883651 T2606 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> 883650 T2561 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> 884343 T2607 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 884343 T2607 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374573678902/collection1
[junit4] 2> 884343 T2607 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 884344 T2607 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 884344 T2607 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 884345 T2607 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374573678902/collection1/'
[junit4] 2> 884347 T2607 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374573678902/collection1/lib/classes/' to classloader
[junit4] 2> 884347 T2607 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374573678902/collection1/lib/README' to classloader
[junit4] 2> 884399 T2607 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4] 2> 884458 T2607 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 884559 T2607 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 884570 T2607 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 885183 T2607 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 885183 T2607 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 885184 T2607 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 885197 T2607 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 885201 T2607 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 885213 T2607 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 885218 T2607 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 885222 T2607 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 885223 T2607 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 885224 T2607 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 885224 T2607 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 885225 T2607 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 885225 T2607 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 885226 T2607 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 885226 T2607 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374573678902/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZkTest-1374573662776/jetty3/
[junit4] 2> 885226 T2607 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@6f978b94
[junit4] 2> 885227 T2607 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374573662776/jetty3
[junit4] 2> 885228 T2607 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZkTest-1374573662776/jetty3/index/
[junit4] 2> 885228 T2607 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZkTest-1374573662776/jetty3/index' doesn't exist. Creating new index...
[junit4] 2> 885228 T2607 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374573662776/jetty3/index
[junit4] 2> 885232 T2607 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@58d728cd lockFactory=org.apache.lucene.store.NativeFSLockFactory@2b772bf3),segFN=segments_1,generation=1}
[junit4] 2> 885232 T2607 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 885236 T2607 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 885236 T2607 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 885237 T2607 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 885237 T2607 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 885238 T2607 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 885238 T2607 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 885239 T2607 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 885239 T2607 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 885240 T2607 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 885249 T2607 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 885256 T2607 oass.SolrIndexSearcher.<init> Opening Searcher@3220d75e main
[junit4] 2> 885257 T2607 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 885258 T2607 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 885262 T2608 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@3220d75e main{StandardDirectoryReader(segments_1:1)}
[junit4] 2> 885263 T2607 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 885263 T2607 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:48610/hl collection:collection1 shard:shard1
[junit4] 2> 885264 T2607 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=30000&socketTimeout=30000&retry=false
[junit4] 2> 885285 T2607 oasc.ZkController.register We are http://127.0.0.1:48610/hl/collection1/ and leader is http://127.0.0.1:48543/hl/collection1/
[junit4] 2> 885285 T2607 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:48610/hl
[junit4] 2> 885285 T2607 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4] 2> 885285 T2607 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4] 2> ASYNC NEW_CORE C689 name=collection1 org.apache.solr.core.SolrCore@533a7ed2 url=http://127.0.0.1:48610/hl/collection1 node=127.0.0.1:48610_hl C689_STATE=coll:collection1 core:collection1 props:{state=down, core=collection1, node_name=127.0.0.1:48610_hl, base_url=http://127.0.0.1:48610/hl}
[junit4] 2> 885286 T2609 C689 P48610 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4] 2> 885287 T2609 C689 P48610 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4] 2> 885287 T2607 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 885287 T2609 C689 P48610 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4] 2> 885287 T2609 C689 P48610 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 885288 T2532 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J0
[junit4] 2> 885289 T2609 C689 P48610 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 885289 T2532 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 885289 T2532 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 885303 T2564 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: core_node3, state: recovering, checkLive: true, onlyIfLeader: true
[junit4] 2> 885630 T2532 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 885633 T2532 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:48627
[junit4] 2> 885634 T2532 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 885634 T2532 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 885634 T2532 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty4-1374573683627
[junit4] 2> 885635 T2532 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty4-137
[...truncated too long message...]
ractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:193)
[junit4] 2> at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:180)
[junit4] 2> at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:384)
[junit4] 2> at java.net.Socket.connect(Socket.java:546)
[junit4] 2> at org.apache.http.conn.scheme.PlainSocketFactory.connectSocket(PlainSocketFactory.java:127)
[junit4] 2> at org.apache.http.impl.conn.DefaultClientConnectionOperator.openConnection(DefaultClientConnectionOperator.java:180)
[junit4] 2> at org.apache.http.impl.conn.ManagedClientConnectionImpl.open(ManagedClientConnectionImpl.java:294)
[junit4] 2> at org.apache.http.impl.client.DefaultRequestDirector.tryConnect(DefaultRequestDirector.java:645)
[junit4] 2> at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:480)
[junit4] 2> at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:906)
[junit4] 2> at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:805)
[junit4] 2> at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:784)
[junit4] 2> at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:365)
[junit4] 2> at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:180)
[junit4] 2> at org.apache.solr.cloud.SyncStrategy$1.run(SyncStrategy.java:291)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1146)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
[junit4] 2> at java.lang.Thread.run(Thread.java:679)
[junit4] 2> NOTE: test params are: codec=Appending, sim=RandomSimilarityProvider(queryNorm=false,coord=crazy): {}, locale=lv, timezone=America/Santarem
[junit4] 2> NOTE: FreeBSD 9.1-RELEASE-p3 amd64/Sun Microsystems Inc. 1.6.0_32 (64-bit)/cpus=16,threads=2,free=250724416,total=418709504
[junit4] 2> NOTE: All tests run in this JVM: [BasicFunctionalityTest, RegexBoostProcessorTest, UnloadDistributedZkTest, TestMaxScoreQueryParser, RecoveryZkTest, TestFieldTypeCollectionResource, TestFastWriter, ZkControllerTest, TestWriterPerf, TestPHPSerializedResponseWriter, RAMDirectoryFactoryTest, OverseerTest, TestReplicationHandler, TestReloadAndDeleteDocs, TestFieldCollectionResource, TestCharFilters, BlockDirectoryTest, TestSolrIndexConfig, TestFuzzyAnalyzedSuggestions, SyncSliceTest, TestBadConfig, HdfsUnloadDistributedZkTest, TestRemoteStreaming, QueryElevationComponentTest, PrimUtilsTest, SynonymTokenizerTest, SimpleFacetsTest, ClusterStateUpdateTest, CacheHeaderTest, SuggesterFSTTest, AddSchemaFieldsUpdateProcessorFactoryTest, TermsComponentTest, ResponseLogComponentTest, BlockCacheTest, SoftAutoCommitTest, TestStressRecovery, SpellingQueryConverterTest, MBeansHandlerTest, HdfsRecoveryZkTest, CSVRequestHandlerTest, TestSweetSpotSimilarityFactory, QueryParsingTest, TestReversedWildcardFilterFactory, PolyFieldTest, TestSort, UUIDFieldTest, DateFieldTest, TestStressVersions, ChaosMonkeyNothingIsSafeTest, SOLR749Test, TestLFUCache, BasicDistributedZkTest]
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=BasicDistributedZkTest -Dtests.seed=35AD0F7F06EAF33F -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=lv -Dtests.timezone=America/Santarem -Dtests.file.encoding=US-ASCII
[junit4] ERROR 0.00s J0 | BasicDistributedZkTest (suite) <<<
[junit4] > Throwable #1: com.carrotsearch.randomizedtesting.ThreadLeakError: 1 thread leaked from SUITE scope at org.apache.solr.cloud.BasicDistributedZkTest:
[junit4] > 1) Thread[id=3020, name=recoveryCmdExecutor-1261-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([35AD0F7F06EAF33F]:0)Throwable #2: com.carrotsearch.randomizedtesting.ThreadLeakError: There are still zombie threads that couldn't be terminated:
[junit4] > 1) Thread[id=3020, name=recoveryCmdExecutor-1261-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([35AD0F7F06EAF33F]:0)
[junit4] Completed on J0 in 214.15s, 1 test, 2 errors <<< FAILURES!
[...truncated 557 lines...]
BUILD FAILED
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/build.xml:395: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/build.xml:375: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/build.xml:39: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/build.xml:181: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/solr/common-build.xml:449: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/lucene/common-build.xml:1250: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.4-Java6/lucene/common-build.xml:893: There were test failures: 317 suites, 1337 tests, 2 suite-level errors, 776 ignored (4 assumptions)
Total time: 43 minutes 47 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure