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 12:53:48 UTC
[JENKINS] Lucene-Solr-Tests-4.x-Java7 - Build # 1435 - Still
Failing
Build: https://builds.apache.org/job/Lucene-Solr-Tests-4.x-Java7/1435/
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=1493, name=recoveryCmdExecutor-739-thread-1, state=RUNNABLE, group=TGRP-BasicDistributedZkTest] at java.net.PlainSocketImpl.socketConnect(Native Method) at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:339) at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:200) at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:182) at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:391) at java.net.Socket.connect(Socket.java:579) at org.apache.http.conn.scheme.PlainSocketFactory.connectSocket(PlainSocketFactory.java:127) at org.apache.http.impl.conn.DefaultClientConnectionOperator.openConnection(DefaultClientConnectionOperator.java:180) at org.apache.http.impl.conn.ManagedClientConnectionImpl.open(ManagedClientConnectionImpl.java:294) at org.apache.http.impl.client.DefaultRequestDirector.tryConnect(DefaultRequestDirector.java:645) at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:480) at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:906) at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:805) at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:784) at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:365) at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:180) at org.apache.solr.cloud.SyncStrategy$1.run(SyncStrategy.java:291) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) at java.lang.Thread.run(Thread.java:722)
Stack Trace:
com.carrotsearch.randomizedtesting.ThreadLeakError: 1 thread leaked from SUITE scope at org.apache.solr.cloud.BasicDistributedZkTest:
1) Thread[id=1493, name=recoveryCmdExecutor-739-thread-1, state=RUNNABLE, group=TGRP-BasicDistributedZkTest]
at java.net.PlainSocketImpl.socketConnect(Native Method)
at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:339)
at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:200)
at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:182)
at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:391)
at java.net.Socket.connect(Socket.java:579)
at org.apache.http.conn.scheme.PlainSocketFactory.connectSocket(PlainSocketFactory.java:127)
at org.apache.http.impl.conn.DefaultClientConnectionOperator.openConnection(DefaultClientConnectionOperator.java:180)
at org.apache.http.impl.conn.ManagedClientConnectionImpl.open(ManagedClientConnectionImpl.java:294)
at org.apache.http.impl.client.DefaultRequestDirector.tryConnect(DefaultRequestDirector.java:645)
at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:480)
at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:906)
at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:805)
at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:784)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:365)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:180)
at org.apache.solr.cloud.SyncStrategy$1.run(SyncStrategy.java:291)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:722)
at __randomizedtesting.SeedInfo.seed([48E82B663A9E2689]: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=1493, name=recoveryCmdExecutor-739-thread-1, state=RUNNABLE, group=TGRP-BasicDistributedZkTest] at java.net.PlainSocketImpl.socketConnect(Native Method) at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:339) at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:200) at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:182) at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:391) at java.net.Socket.connect(Socket.java:579) at org.apache.http.conn.scheme.PlainSocketFactory.connectSocket(PlainSocketFactory.java:127) at org.apache.http.impl.conn.DefaultClientConnectionOperator.openConnection(DefaultClientConnectionOperator.java:180) at org.apache.http.impl.conn.ManagedClientConnectionImpl.open(ManagedClientConnectionImpl.java:294) at org.apache.http.impl.client.DefaultRequestDirector.tryConnect(DefaultRequestDirector.java:645) at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:480) at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:906) at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:805) at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:784) at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:365) at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:180) at org.apache.solr.cloud.SyncStrategy$1.run(SyncStrategy.java:291) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) at java.lang.Thread.run(Thread.java:722)
Stack Trace:
com.carrotsearch.randomizedtesting.ThreadLeakError: There are still zombie threads that couldn't be terminated:
1) Thread[id=1493, name=recoveryCmdExecutor-739-thread-1, state=RUNNABLE, group=TGRP-BasicDistributedZkTest]
at java.net.PlainSocketImpl.socketConnect(Native Method)
at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:339)
at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:200)
at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:182)
at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:391)
at java.net.Socket.connect(Socket.java:579)
at org.apache.http.conn.scheme.PlainSocketFactory.connectSocket(PlainSocketFactory.java:127)
at org.apache.http.impl.conn.DefaultClientConnectionOperator.openConnection(DefaultClientConnectionOperator.java:180)
at org.apache.http.impl.conn.ManagedClientConnectionImpl.open(ManagedClientConnectionImpl.java:294)
at org.apache.http.impl.client.DefaultRequestDirector.tryConnect(DefaultRequestDirector.java:645)
at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:480)
at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:906)
at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:805)
at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:784)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:365)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:180)
at org.apache.solr.cloud.SyncStrategy$1.run(SyncStrategy.java:291)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:722)
at __randomizedtesting.SeedInfo.seed([48E82B663A9E2689]:0)
Build Log:
[...truncated 9440 lines...]
[junit4] Suite: org.apache.solr.cloud.BasicDistributedZkTest
[junit4] 2> 354850 T1053 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /qh/bz
[junit4] 2> 354855 T1053 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4] 2> Creating dataDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./solrtest-BasicDistributedZkTest-1374575981162
[junit4] 2> 354857 T1053 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 354858 T1054 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 354959 T1053 oasc.ZkTestServer.run start zk server on port:24751
[junit4] 2> 354960 T1053 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 354965 T1060 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4d1e3c9e name:ZooKeeperConnection Watcher:127.0.0.1:24751 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 354965 T1053 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 354965 T1053 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 354980 T1053 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 354982 T1062 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1728ae41 name:ZooKeeperConnection Watcher:127.0.0.1:24751/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 354983 T1053 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 354983 T1053 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4] 2> 354994 T1053 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4] 2> 354998 T1053 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4] 2> 355001 T1053 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4] 2> 355010 T1053 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4] 2> 355011 T1053 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4] 2> 355018 T1053 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
[junit4] 2> 355019 T1053 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4] 2> 355123 T1053 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4] 2> 355124 T1053 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4] 2> 355128 T1053 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4] 2> 355129 T1053 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4] 2> 355133 T1053 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4] 2> 355134 T1053 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4] 2> 355138 T1053 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4] 2> 355138 T1053 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4] 2> 355142 T1053 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 355143 T1053 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 355147 T1053 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4] 2> 355147 T1053 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4] 2> 355151 T1053 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4] 2> 355152 T1053 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4] 2> 355433 T1053 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 355438 T1053 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:36274
[junit4] 2> 355439 T1053 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 355440 T1053 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 355440 T1053 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374575981463
[junit4] 2> 355441 T1053 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374575981463/'
[junit4] 2> 355477 T1053 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374575981463/solr.xml
[junit4] 2> 355579 T1053 oasc.CoreContainer.<init> New CoreContainer 395343906
[junit4] 2> 355580 T1053 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374575981463/]
[junit4] 2> 355581 T1053 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 355582 T1053 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 355583 T1053 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 355583 T1053 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 355584 T1053 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 355584 T1053 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 355585 T1053 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 355585 T1053 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 355585 T1053 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 355586 T1053 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4] 2> 355605 T1053 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 355606 T1053 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:24751/solr
[junit4] 2> 355606 T1053 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 355607 T1053 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 355611 T1073 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3c48d749 name:ZooKeeperConnection Watcher:127.0.0.1:24751 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 355612 T1053 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 355627 T1053 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4] 2> 355641 T1053 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 355644 T1075 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@15b0d31 name:ZooKeeperConnection Watcher:127.0.0.1:24751/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 355644 T1053 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 355647 T1053 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 355657 T1053 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 355661 T1053 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 355664 T1053 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:36274_qh%2Fbz
[junit4] 2> 355671 T1053 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:36274_qh%2Fbz
[junit4] 2> 355675 T1053 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 355689 T1053 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 355693 T1053 oasc.Overseer.start Overseer (id=90084211501957123-127.0.0.1:36274_qh%2Fbz-n_0000000000) starting
[junit4] 2> 355704 T1053 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 355714 T1077 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 355715 T1053 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 355718 T1053 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 355725 T1053 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 355729 T1076 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 355733 T1078 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 355734 T1078 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 355735 T1078 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 357233 T1076 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 357234 T1076 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:36274_qh%2Fbz",
[junit4] 2> "base_url":"http://127.0.0.1:36274/qh/bz"}
[junit4] 2> 357235 T1076 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with numShards 1
[junit4] 2> 357235 T1076 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 357240 T1075 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> 357738 T1078 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 357738 T1078 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374575981463/collection1
[junit4] 2> 357738 T1078 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4] 2> 357739 T1078 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 357739 T1078 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4] 2> 357741 T1078 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374575981463/collection1/'
[junit4] 2> 357742 T1078 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374575981463/collection1/lib/README' to classloader
[junit4] 2> 357743 T1078 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374575981463/collection1/lib/classes/' to classloader
[junit4] 2> 357809 T1078 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_45
[junit4] 2> 357869 T1078 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 357971 T1078 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 357984 T1078 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 358654 T1078 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 358654 T1078 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 358655 T1078 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 358664 T1078 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 358668 T1078 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 358696 T1078 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 358702 T1078 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 358706 T1078 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 358708 T1078 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 358708 T1078 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 358708 T1078 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 358710 T1078 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 358710 T1078 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 358710 T1078 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 358710 T1078 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1374575981463/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZkTest-1374575981162/control/data/
[junit4] 2> 358711 T1078 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2055ea0a
[junit4] 2> 358711 T1078 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374575981162/control/data
[junit4] 2> 358712 T1078 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZkTest-1374575981162/control/data/index/
[junit4] 2> 358712 T1078 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZkTest-1374575981162/control/data/index' doesn't exist. Creating new index...
[junit4] 2> 358712 T1078 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374575981162/control/data/index
[junit4] 2> 358715 T1078 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@75aee9f0 lockFactory=org.apache.lucene.store.NativeFSLockFactory@59ed9ae1),segFN=segments_1,generation=1}
[junit4] 2> 358716 T1078 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 358719 T1078 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 358719 T1078 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 358720 T1078 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 358720 T1078 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 358720 T1078 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 358721 T1078 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 358721 T1078 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 358721 T1078 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 358721 T1078 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 358732 T1078 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 358737 T1078 oass.SolrIndexSearcher.<init> Opening Searcher@4917f2d5 main
[junit4] 2> 358738 T1078 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 358738 T1078 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 358741 T1079 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@4917f2d5 main{StandardDirectoryReader(segments_1:1)}
[junit4] 2> 358742 T1078 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 358742 T1078 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:36274/qh/bz collection:control_collection shard:shard1
[junit4] 2> 358742 T1078 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=30000&socketTimeout=30000&retry=false
[junit4] 2> 358755 T1078 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4] 2> 358780 T1078 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 358784 T1078 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 358784 T1078 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 358784 T1078 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:36274/qh/bz/collection1/
[junit4] 2> 358785 T1078 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 358785 T1078 oasc.SyncStrategy.syncToMe http://127.0.0.1:36274/qh/bz/collection1/ has no replicas
[junit4] 2> 358785 T1078 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:36274/qh/bz/collection1/ shard1
[junit4] 2> 358785 T1078 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4] 2> 360256 T1076 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 360280 T1075 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> 360323 T1078 oasc.ZkController.register We are http://127.0.0.1:36274/qh/bz/collection1/ and leader is http://127.0.0.1:36274/qh/bz/collection1/
[junit4] 2> 360323 T1078 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:36274/qh/bz
[junit4] 2> 360323 T1078 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 360323 T1078 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 360324 T1078 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 360326 T1078 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 360327 T1053 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0
[junit4] 2> 360327 T1053 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 360328 T1053 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 360341 T1053 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4] 2> 360343 T1053 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 360345 T1082 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4518d51a name:ZooKeeperConnection Watcher:127.0.0.1:24751/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 360345 T1053 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 360347 T1053 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 360350 T1053 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4] 2> 360627 T1053 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 360630 T1053 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:36664
[junit4] 2> 360630 T1053 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 360631 T1053 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 360631 T1053 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374575986657
[junit4] 2> 360632 T1053 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374575986657/'
[junit4] 2> 360668 T1053 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374575986657/solr.xml
[junit4] 2> 360756 T1053 oasc.CoreContainer.<init> New CoreContainer 456065093
[junit4] 2> 360757 T1053 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374575986657/]
[junit4] 2> 360759 T1053 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 360760 T1053 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 360760 T1053 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 360760 T1053 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 360761 T1053 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 360761 T1053 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 360762 T1053 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 360762 T1053 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 360763 T1053 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 360763 T1053 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4] 2> 360780 T1053 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 360781 T1053 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:24751/solr
[junit4] 2> 360781 T1053 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 360782 T1053 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 360786 T1093 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@44e2d898 name:ZooKeeperConnection Watcher:127.0.0.1:24751 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 360786 T1053 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 360805 T1053 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4] 2> 360817 T1053 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 360820 T1095 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1521bef name:ZooKeeperConnection Watcher:127.0.0.1:24751/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 360820 T1053 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 360833 T1053 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 361795 T1076 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 361797 T1076 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:36274_qh%2Fbz",
[junit4] 2> "base_url":"http://127.0.0.1:36274/qh/bz"}
[junit4] 2> 361812 T1095 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> 361812 T1082 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> 361812 T1075 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> 361837 T1053 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:36664_qh%2Fbz
[junit4] 2> 361839 T1053 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:36664_qh%2Fbz
[junit4] 2> 361843 T1082 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 361843 T1095 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 361843 T1075 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 361843 T1095 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> 361843 T1082 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> 361843 T1075 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> 361857 T1096 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 361858 T1096 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 361859 T1096 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 363318 T1076 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 363320 T1076 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:36664_qh%2Fbz",
[junit4] 2> "base_url":"http://127.0.0.1:36664/qh/bz"}
[junit4] 2> 363320 T1076 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with numShards 2
[junit4] 2> 363320 T1076 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 363335 T1095 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> 363335 T1082 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> 363335 T1075 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> 363862 T1096 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 363862 T1096 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374575986657/collection1
[junit4] 2> 363862 T1096 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 363863 T1096 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 363864 T1096 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 363865 T1096 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374575986657/collection1/'
[junit4] 2> 363867 T1096 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374575986657/collection1/lib/README' to classloader
[junit4] 2> 363867 T1096 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374575986657/collection1/lib/classes/' to classloader
[junit4] 2> 363922 T1096 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_45
[junit4] 2> 363983 T1096 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 364085 T1096 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 364098 T1096 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 364777 T1096 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 364778 T1096 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 364779 T1096 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 364791 T1096 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 364795 T1096 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 364813 T1096 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 364818 T1096 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 364823 T1096 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 364824 T1096 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 364824 T1096 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 364825 T1096 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 364826 T1096 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 364826 T1096 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 364827 T1096 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 364827 T1096 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1374575986657/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZkTest-1374575981162/jetty1/
[junit4] 2> 364827 T1096 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2055ea0a
[junit4] 2> 364828 T1096 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374575981162/jetty1
[junit4] 2> 364829 T1096 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZkTest-1374575981162/jetty1/index/
[junit4] 2> 364829 T1096 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZkTest-1374575981162/jetty1/index' doesn't exist. Creating new index...
[junit4] 2> 364829 T1096 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374575981162/jetty1/index
[junit4] 2> 364833 T1096 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@52646030 lockFactory=org.apache.lucene.store.NativeFSLockFactory@48474b98),segFN=segments_1,generation=1}
[junit4] 2> 364833 T1096 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 364838 T1096 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 364839 T1096 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 364840 T1096 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 364840 T1096 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 364841 T1096 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 364841 T1096 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 364841 T1096 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 364842 T1096 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 364843 T1096 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 364859 T1096 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 364866 T1096 oass.SolrIndexSearcher.<init> Opening Searcher@87f1c51 main
[junit4] 2> 364867 T1096 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 364868 T1096 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 364872 T1097 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@87f1c51 main{StandardDirectoryReader(segments_1:1)}
[junit4] 2> 364875 T1096 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 364875 T1096 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:36664/qh/bz collection:collection1 shard:shard1
[junit4] 2> 364875 T1096 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=30000&socketTimeout=30000&retry=false
[junit4] 2> 364894 T1096 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 364918 T1096 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 364928 T1096 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 364929 T1096 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 364929 T1096 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:36664/qh/bz/collection1/
[junit4] 2> 364929 T1096 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 364930 T1096 oasc.SyncStrategy.syncToMe http://127.0.0.1:36664/qh/bz/collection1/ has no replicas
[junit4] 2> 364930 T1096 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:36664/qh/bz/collection1/ shard1
[junit4] 2> 364930 T1096 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 366343 T1076 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 366362 T1075 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> 366362 T1082 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> 366362 T1095 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> 366375 T1096 oasc.ZkController.register We are http://127.0.0.1:36664/qh/bz/collection1/ and leader is http://127.0.0.1:36664/qh/bz/collection1/
[junit4] 2> 366375 T1096 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:36664/qh/bz
[junit4] 2> 366375 T1096 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 366375 T1096 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 366376 T1096 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 366378 T1096 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 366379 T1053 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0
[junit4] 2> 366379 T1053 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 366380 T1053 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 366675 T1053 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 366678 T1053 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:52661
[junit4] 2> 366679 T1053 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 366679 T1053 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 366680 T1053 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374575992699
[junit4] 2> 366680 T1053 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374575992699/'
[junit4] 2> 366716 T1053 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374575992699/solr.xml
[junit4] 2> 366805 T1053 oasc.CoreContainer.<init> New CoreContainer 938258175
[junit4] 2> 366805 T1053 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374575992699/]
[junit4] 2> 366807 T1053 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 366808 T1053 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 366808 T1053 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 366809 T1053 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 366809 T1053 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 366810 T1053 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 366810 T1053 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 366811 T1053 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 366811 T1053 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 366812 T1053 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4] 2> 366830 T1053 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 366831 T1053 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:24751/solr
[junit4] 2> 366831 T1053 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 366832 T1053 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 366836 T1109 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4fbe6d4d name:ZooKeeperConnection Watcher:127.0.0.1:24751 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 366836 T1053 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 366852 T1053 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4] 2> 366865 T1053 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 366868 T1111 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@20db220d name:ZooKeeperConnection Watcher:127.0.0.1:24751/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 366868 T1053 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 366878 T1053 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 367874 T1076 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 367875 T1076 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:36664_qh%2Fbz",
[junit4] 2> "base_url":"http://127.0.0.1:36664/qh/bz"}
[junit4] 2> 367913 T1053 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:52661_qh%2Fbz
[junit4] 2> 367915 T1053 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:52661_qh%2Fbz
[junit4] 2> 367928 T1095 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 367928 T1082 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 367928 T1095 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> 367928 T1111 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 367928 T1082 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> 367929 T1111 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> 367930 T1095 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> 367937 T1082 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> 367938 T1075 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 367938 T1075 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> 367939 T1075 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> 367944 T1112 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 367944 T1112 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 367946 T1112 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 369440 T1076 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 369442 T1076 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:52661_qh%2Fbz",
[junit4] 2> "base_url":"http://127.0.0.1:52661/qh/bz"}
[junit4] 2> 369442 T1076 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4] 2> 369442 T1076 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 369461 T1095 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> 369461 T1082 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> 369461 T1111 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> 369461 T1075 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> 369948 T1112 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 369948 T1112 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374575992699/collection1
[junit4] 2> 369948 T1112 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 369949 T1112 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 369949 T1112 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 369950 T1112 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374575992699/collection1/'
[junit4] 2> 369952 T1112 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374575992699/collection1/lib/README' to classloader
[junit4] 2> 369953 T1112 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374575992699/collection1/lib/classes/' to classloader
[junit4] 2> 370007 T1112 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_45
[junit4] 2> 370068 T1112 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 370170 T1112 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 370183 T1112 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 370848 T1112 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 370849 T1112 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 370850 T1112 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 370862 T1112 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 370866 T1112 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 370883 T1112 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 370888 T1112 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 370893 T1112 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 370894 T1112 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 370895 T1112 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 370895 T1112 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 370896 T1112 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 370896 T1112 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 370897 T1112 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 370897 T1112 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1374575992699/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZkTest-1374575981162/jetty2/
[junit4] 2> 370898 T1112 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2055ea0a
[junit4] 2> 370899 T1112 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374575981162/jetty2
[junit4] 2> 370899 T1112 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZkTest-1374575981162/jetty2/index/
[junit4] 2> 370899 T1112 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZkTest-1374575981162/jetty2/index' doesn't exist. Creating new index...
[junit4] 2> 370900 T1112 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374575981162/jetty2/index
[junit4] 2> 370903 T1112 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@214d105e lockFactory=org.apache.lucene.store.NativeFSLockFactory@dad9d1a),segFN=segments_1,generation=1}
[junit4] 2> 370904 T1112 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 370909 T1112 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 370909 T1112 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 370910 T1112 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 370910 T1112 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 370911 T1112 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 370911 T1112 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 370912 T1112 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 370912 T1112 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 370913 T1112 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 370929 T1112 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 370936 T1112 oass.SolrIndexSearcher.<init> Opening Searcher@6d52026f main
[junit4] 2> 370938 T1112 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 370938 T1112 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 370943 T1113 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@6d52026f main{StandardDirectoryReader(segments_1:1)}
[junit4] 2> 370945 T1112 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 370945 T1112 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:52661/qh/bz collection:collection1 shard:shard2
[junit4] 2> 370945 T1112 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=30000&socketTimeout=30000&retry=false
[junit4] 2> 370963 T1112 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4] 2> 370981 T1112 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
[junit4] 2> 370990 T1112 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 370990 T1112 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 370990 T1112 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:52661/qh/bz/collection1/
[junit4] 2> 370991 T1112 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 370991 T1112 oasc.SyncStrategy.syncToMe http://127.0.0.1:52661/qh/bz/collection1/ has no replicas
[junit4] 2> 370991 T1112 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:52661/qh/bz/collection1/ shard2
[junit4] 2> 370992 T1112 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4] 2> 372470 T1076 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 372488 T1095 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> 372489 T1082 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> 372489 T1111 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> 372488 T1075 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> 372534 T1112 oasc.ZkController.register We are http://127.0.0.1:52661/qh/bz/collection1/ and leader is http://127.0.0.1:52661/qh/bz/collection1/
[junit4] 2> 372534 T1112 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:52661/qh/bz
[junit4] 2> 372534 T1112 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 372534 T1112 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 372535 T1112 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 372537 T1112 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 372538 T1053 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0
[junit4] 2> 372539 T1053 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 372539 T1053 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 372827 T1053 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 372830 T1053 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:16047
[junit4] 2> 372831 T1053 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 372831 T1053 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 372832 T1053 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374575998856
[junit4] 2> 372832 T1053 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374575998856/'
[junit4] 2> 372868 T1053 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374575998856/solr.xml
[junit4] 2> 372956 T1053 oasc.CoreContainer.<init> New CoreContainer 225434670
[junit4] 2> 372957 T1053 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374575998856/]
[junit4] 2> 372959 T1053 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 372959 T1053 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 372960 T1053 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 372960 T1053 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 372961 T1053 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 372961 T1053 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 372962 T1053 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 372962 T1053 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 372963 T1053 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 372963 T1053 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4] 2> 372980 T1053 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 372981 T1053 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:24751/solr
[junit4] 2> 372981 T1053 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 372982 T1053 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 372986 T1125 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3ac9b832 name:ZooKeeperConnection Watcher:127.0.0.1:24751 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 372986 T1053 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 373004 T1053 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4] 2> 373016 T1053 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 373018 T1127 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@75c7af15 name:ZooKeeperConnection Watcher:127.0.0.1:24751/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 373019 T1053 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 373031 T1053 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 373996 T1076 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 373998 T1076 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:52661_qh%2Fbz",
[junit4] 2> "base_url":"http://127.0.0.1:52661/qh/bz"}
[junit4] 2> 374014 T1127 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> 374014 T1111 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> 374014 T1082 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> 374014 T1095 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> 374014 T1075 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> 374035 T1053 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:16047_qh%2Fbz
[junit4] 2> 374037 T1053 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:16047_qh%2Fbz
[junit4] 2> 374040 T1127 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> 374041 T1095 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 374041 T1075 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 374041 T1082 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 374041 T1075 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> 374041 T1111 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 374041 T1095 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> 374042 T1111 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> 374042 T1082 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> 374043 T1127 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 374052 T1128 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 374052 T1128 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 374054 T1128 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 375520 T1076 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 375522 T1076 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:16047_qh%2Fbz",
[junit4] 2> "base_url":"http://127.0.0.1:16047/qh/bz"}
[junit4] 2> 375522 T1076 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4] 2> 375522 T1076 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 375537 T1127 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> 375537 T1082 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> 375537 T1111 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> 375537 T1075 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> 375537 T1095 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> 376056 T1128 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 376056 T1128 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374575998856/collection1
[junit4] 2> 376056 T1128 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 376057 T1128 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 376058 T1128 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 376059 T1128 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374575998856/collection1/'
[junit4] 2> 376060 T1128 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374575998856/collection1/lib/classes/' to classloader
[junit4] 2> 376061 T1128 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374575998856/collection1/lib/README' to classloader
[junit4] 2> 376116 T1128 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_45
[junit4] 2> 376177 T1128 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 376278 T1128 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 376291 T1128 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 376919 T1128 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 376920 T1128 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 376921 T1128 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 376933 T1128 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 376938 T1128 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 376955 T1128 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 376960 T1128 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 376965 T1128 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 376966 T1128 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 376966 T1128 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 376967 T1128 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 376968 T1128 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 376968 T1128 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 376969 T1128 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 376969 T1128 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1374575998856/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZkTest-1374575981162/jetty3/
[junit4] 2> 376969 T1128 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2055ea0a
[junit4] 2> 376970 T1128 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374575981162/jetty3
[junit4] 2> 376971 T1128 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZkTest-1374575981162/jetty3/index/
[junit4] 2> 376971 T1128 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZkTest-1374575981162/jetty3/index' doesn't exist. Creating new index...
[junit4] 2> 376971 T1128 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1374575981162/jetty3/index
[junit4] 2> 376975 T1128 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@4708e16b lockFactory=org.apache.lucene.store.NativeFSLockFactory@27248f62),segFN=segments_1,generation=1}
[junit4] 2> 376975 T1128 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 376980 T1128 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 376981 T1128 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 376981 T1128 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 376982 T1128 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 376983 T1128 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 376983 T1128 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 376983 T1128 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 376984 T1128 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 376984 T1128 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 377001 T1128 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 377008 T1128 oass.SolrIndexSearcher.<init> Opening Searcher@3d4afebe main
[junit4] 2> 377009 T1128 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 377010 T1128 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 377014 T1129 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@3d4afebe main{StandardDirectoryReader(segments_1:1)}
[junit4] 2> 377017 T1128 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 377017 T1128 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:16047/qh/bz collection:collection1 shard:shard1
[junit4] 2> 377017 T1128 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=30000&socketTimeout=30000&retry=false
[junit4] 2> 377036 T1128 oasc.ZkController.register We are http://127.0.0.1:16047/qh/bz/collection1/ and leader is http://127.0.0.1:36664/qh/bz/collection1/
[junit4] 2> 377037 T1128 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:16047/qh/bz
[junit4] 2> 377037 T1128 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4] 2> 377037 T1128 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4] 2> ASYNC NEW_CORE C359 name=collection1 org.apache.solr.core.SolrCore@6a2d4829 url=http://127.0.0.1:16047/qh/bz/collection1 node=127.0.0.1:16047_qh%2Fbz C359_STATE=coll:collection1 core:collection1 props:{state=down, core=collection1, node_name=127.0.0.1:16047_qh%2Fbz, base_url=http://127.0.0.1:16047/qh/bz}
[junit4] 2> 377037 T1130 C359 P16047 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4] 2> 377038 T1128 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 377038 T1130 C359 P16047 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4] 2> 377039 T1130 C359 P16047 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4] 2> 377039 T1130 C359 P16047 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 377039 T1053 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0
[junit4] 2> 377040 T1053 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 377040 T1130 C359 P16047 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 377041 T1053 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnec
[...truncated too long message...]
93, name=recoveryCmdExecutor-739-thread-1, state=RUNNABLE, group=TGRP-BasicDistributedZkTest]
[junit4] 2> at java.net.PlainSocketImpl.socketConnect(Native Method)
[junit4] 2> at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:339)
[junit4] 2> at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:200)
[junit4] 2> at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:182)
[junit4] 2> at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:391)
[junit4] 2> at java.net.Socket.connect(Socket.java:579)
[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:1145)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
[junit4] 2> at java.lang.Thread.run(Thread.java:722)
[junit4] 2> NOTE: test params are: codec=Appending, sim=RandomSimilarityProvider(queryNorm=false,coord=yes): {}, locale=es_CL, timezone=America/Atka
[junit4] 2> NOTE: FreeBSD 9.1-RELEASE-p3 amd64/Oracle Corporation 1.7.0_21 (64-bit)/cpus=16,threads=2,free=110216888,total=343932928
[junit4] 2> NOTE: All tests run in this JVM: [TestStressVersions, SolrCoreTest, PrimUtilsTest, ZkNodePropsTest, TestFieldCollectionResource, DateFieldTest, SortByFunctionTest, SolrCoreCheckLockOnStartupTest, SpatialFilterTest, TestRealTimeGet, TestSolrXmlPersistence, SystemInfoHandlerTest, TestReload, TestAtomicUpdateErrorCases, TestBinaryField, TestIndexingPerformance, RequestHandlersTest, TestPseudoReturnFields, ResourceLoaderTest, PolyFieldTest, BadIndexSchemaTest, ZkCLITest, SimpleFacetsTest, TestRecovery, TestValueSourceCache, TestLuceneMatchVersion, CoreContainerCoreInitFailuresTest, ShowFileRequestHandlerTest, JSONWriterTest, PreAnalyzedFieldTest, TestFunctionQuery, OutputWriterTest, PrimitiveFieldTypeTest, TestPerFieldSimilarity, TestQuerySenderListener, AliasIntegrationTest, XmlUpdateRequestHandlerTest, TestRandomFaceting, TestWriterPerf, BasicDistributedZkTest]
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=BasicDistributedZkTest -Dtests.seed=48E82B663A9E2689 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=es_CL -Dtests.timezone=America/Atka -Dtests.file.encoding=UTF-8
[junit4] ERROR 0.00s J0 | BasicDistributedZkTest (suite) <<<
[junit4] > Throwable #1: com.carrotsearch.randomizedtesting.ThreadLeakError: 1 thread leaked from SUITE scope at org.apache.solr.cloud.BasicDistributedZkTest:
[junit4] > 1) Thread[id=1493, name=recoveryCmdExecutor-739-thread-1, state=RUNNABLE, group=TGRP-BasicDistributedZkTest]
[junit4] > at java.net.PlainSocketImpl.socketConnect(Native Method)
[junit4] > at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:339)
[junit4] > at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:200)
[junit4] > at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:182)
[junit4] > at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:391)
[junit4] > at java.net.Socket.connect(Socket.java:579)
[junit4] > at org.apache.http.conn.scheme.PlainSocketFactory.connectSocket(PlainSocketFactory.java:127)
[junit4] > at org.apache.http.impl.conn.DefaultClientConnectionOperator.openConnection(DefaultClientConnectionOperator.java:180)
[junit4] > at org.apache.http.impl.conn.ManagedClientConnectionImpl.open(ManagedClientConnectionImpl.java:294)
[junit4] > at org.apache.http.impl.client.DefaultRequestDirector.tryConnect(DefaultRequestDirector.java:645)
[junit4] > at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:480)
[junit4] > at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:906)
[junit4] > at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:805)
[junit4] > at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:784)
[junit4] > at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:365)
[junit4] > at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:180)
[junit4] > at org.apache.solr.cloud.SyncStrategy$1.run(SyncStrategy.java:291)
[junit4] > at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
[junit4] > at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
[junit4] > at java.lang.Thread.run(Thread.java:722)
[junit4] > at __randomizedtesting.SeedInfo.seed([48E82B663A9E2689]:0)Throwable #2: com.carrotsearch.randomizedtesting.ThreadLeakError: There are still zombie threads that couldn't be terminated:
[junit4] > 1) Thread[id=1493, name=recoveryCmdExecutor-739-thread-1, state=RUNNABLE, group=TGRP-BasicDistributedZkTest]
[junit4] > at java.net.PlainSocketImpl.socketConnect(Native Method)
[junit4] > at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:339)
[junit4] > at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:200)
[junit4] > at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:182)
[junit4] > at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:391)
[junit4] > at java.net.Socket.connect(Socket.java:579)
[junit4] > at org.apache.http.conn.scheme.PlainSocketFactory.connectSocket(PlainSocketFactory.java:127)
[junit4] > at org.apache.http.impl.conn.DefaultClientConnectionOperator.openConnection(DefaultClientConnectionOperator.java:180)
[junit4] > at org.apache.http.impl.conn.ManagedClientConnectionImpl.open(ManagedClientConnectionImpl.java:294)
[junit4] > at org.apache.http.impl.client.DefaultRequestDirector.tryConnect(DefaultRequestDirector.java:645)
[junit4] > at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:480)
[junit4] > at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:906)
[junit4] > at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:805)
[junit4] > at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:784)
[junit4] > at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:365)
[junit4] > at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:180)
[junit4] > at org.apache.solr.cloud.SyncStrategy$1.run(SyncStrategy.java:291)
[junit4] > at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
[junit4] > at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
[junit4] > at java.lang.Thread.run(Thread.java:722)
[junit4] > at __randomizedtesting.SeedInfo.seed([48E82B663A9E2689]:0)
[junit4] Completed on J0 in 392.44s, 1 test, 2 errors <<< FAILURES!
[...truncated 760 lines...]
BUILD FAILED
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/build.xml:395: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/build.xml:375: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/build.xml:39: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build.xml:181: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/common-build.xml:449: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/lucene/common-build.xml:1250: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/lucene/common-build.xml:893: There were test failures: 319 suites, 1345 tests, 2 suite-level errors, 809 ignored
Total time: 42 minutes 56 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure