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/15 07:26:29 UTC
[JENKINS] Lucene-Solr-NightlyTests-4.4 - Build # 5 - Failure
Build: https://builds.apache.org/job/Lucene-Solr-NightlyTests-4.4/5/
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=2293, name=recoveryCmdExecutor-995-thread-1, state=RUNNABLE, group=TGRP-BasicDistributedZkTest] at java.net.PlainSocketImpl.socketConnect(Native Method) at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:327) at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:193) at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:180) at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:384) at java.net.Socket.connect(Socket.java:546) at org.apache.http.conn.scheme.PlainSocketFactory.connectSocket(PlainSocketFactory.java:127) at org.apache.http.impl.conn.DefaultClientConnectionOperator.openConnection(DefaultClientConnectionOperator.java:180) at org.apache.http.impl.conn.ManagedClientConnectionImpl.open(ManagedClientConnectionImpl.java:294) at org.apache.http.impl.client.DefaultRequestDirector.tryConnect(DefaultRequestDirector.java:645) at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:480) at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:906) at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:805) at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:784) at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:365) at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:180) at org.apache.solr.cloud.SyncStrategy$1.run(SyncStrategy.java:291) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1146) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) at java.lang.Thread.run(Thread.java:679)
Stack Trace:
com.carrotsearch.randomizedtesting.ThreadLeakError: 1 thread leaked from SUITE scope at org.apache.solr.cloud.BasicDistributedZkTest:
1) Thread[id=2293, name=recoveryCmdExecutor-995-thread-1, state=RUNNABLE, group=TGRP-BasicDistributedZkTest]
at java.net.PlainSocketImpl.socketConnect(Native Method)
at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:327)
at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:193)
at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:180)
at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:384)
at java.net.Socket.connect(Socket.java:546)
at org.apache.http.conn.scheme.PlainSocketFactory.connectSocket(PlainSocketFactory.java:127)
at org.apache.http.impl.conn.DefaultClientConnectionOperator.openConnection(DefaultClientConnectionOperator.java:180)
at org.apache.http.impl.conn.ManagedClientConnectionImpl.open(ManagedClientConnectionImpl.java:294)
at org.apache.http.impl.client.DefaultRequestDirector.tryConnect(DefaultRequestDirector.java:645)
at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:480)
at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:906)
at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:805)
at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:784)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:365)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:180)
at org.apache.solr.cloud.SyncStrategy$1.run(SyncStrategy.java:291)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1146)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:679)
at __randomizedtesting.SeedInfo.seed([A37D2D93108F855A]: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=2293, name=recoveryCmdExecutor-995-thread-1, state=RUNNABLE, group=TGRP-BasicDistributedZkTest] at java.net.PlainSocketImpl.socketConnect(Native Method) at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:327) at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:193) at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:180) at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:384) at java.net.Socket.connect(Socket.java:546) at org.apache.http.conn.scheme.PlainSocketFactory.connectSocket(PlainSocketFactory.java:127) at org.apache.http.impl.conn.DefaultClientConnectionOperator.openConnection(DefaultClientConnectionOperator.java:180) at org.apache.http.impl.conn.ManagedClientConnectionImpl.open(ManagedClientConnectionImpl.java:294) at org.apache.http.impl.client.DefaultRequestDirector.tryConnect(DefaultRequestDirector.java:645) at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:480) at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:906) at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:805) at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:784) at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:365) at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:180) at org.apache.solr.cloud.SyncStrategy$1.run(SyncStrategy.java:291) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1146) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) at java.lang.Thread.run(Thread.java:679)
Stack Trace:
com.carrotsearch.randomizedtesting.ThreadLeakError: There are still zombie threads that couldn't be terminated:
1) Thread[id=2293, name=recoveryCmdExecutor-995-thread-1, state=RUNNABLE, group=TGRP-BasicDistributedZkTest]
at java.net.PlainSocketImpl.socketConnect(Native Method)
at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:327)
at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:193)
at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:180)
at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:384)
at java.net.Socket.connect(Socket.java:546)
at org.apache.http.conn.scheme.PlainSocketFactory.connectSocket(PlainSocketFactory.java:127)
at org.apache.http.impl.conn.DefaultClientConnectionOperator.openConnection(DefaultClientConnectionOperator.java:180)
at org.apache.http.impl.conn.ManagedClientConnectionImpl.open(ManagedClientConnectionImpl.java:294)
at org.apache.http.impl.client.DefaultRequestDirector.tryConnect(DefaultRequestDirector.java:645)
at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:480)
at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:906)
at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:805)
at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:784)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:365)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:180)
at org.apache.solr.cloud.SyncStrategy$1.run(SyncStrategy.java:291)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1146)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:679)
at __randomizedtesting.SeedInfo.seed([A37D2D93108F855A]:0)
Build Log:
[...truncated 9182 lines...]
[junit4] Suite: org.apache.solr.cloud.BasicDistributedZkTest
[junit4] 2> 942225 T1787 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
[junit4] 2> 942230 T1787 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4] 2> Creating dataDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/solr/build/solr-core/test/J0/./solrtest-BasicDistributedZkTest-1373865423780
[junit4] 2> 942231 T1787 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 942232 T1788 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 942333 T1787 oasc.ZkTestServer.run start zk server on port:60568
[junit4] 2> 942334 T1787 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 942364 T1794 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@637c285b name:ZooKeeperConnection Watcher:127.0.0.1:60568 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 942364 T1787 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 942365 T1787 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 942370 T1787 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 942372 T1796 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4c769fcf name:ZooKeeperConnection Watcher:127.0.0.1:60568/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 942372 T1787 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 942373 T1787 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4] 2> 942385 T1787 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4] 2> 942388 T1787 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4] 2> 942397 T1787 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4] 2> 942401 T1787 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4] 2> 942402 T1787 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4] 2> 942415 T1787 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
[junit4] 2> 942416 T1787 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4] 2> 942521 T1787 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4] 2> 942522 T1787 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4] 2> 942525 T1787 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4] 2> 942526 T1787 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4] 2> 942535 T1787 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4] 2> 942536 T1787 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4] 2> 942540 T1787 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4] 2> 942540 T1787 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4] 2> 942544 T1787 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 942545 T1787 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 942549 T1787 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4] 2> 942549 T1787 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4] 2> 942553 T1787 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4] 2> 942554 T1787 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4] 2> 942821 T1787 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 942830 T1787 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:60571
[junit4] 2> 942831 T1787 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 942831 T1787 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 942831 T1787 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1373865424107
[junit4] 2> 942832 T1787 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1373865424107/'
[junit4] 2> 942869 T1787 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1373865424107/solr.xml
[junit4] 2> 942941 T1787 oasc.CoreContainer.<init> New CoreContainer 498935290
[junit4] 2> 942942 T1787 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1373865424107/]
[junit4] 2> 942944 T1787 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 942944 T1787 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 942945 T1787 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 942945 T1787 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 942946 T1787 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 942946 T1787 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 942946 T1787 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 942947 T1787 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 942947 T1787 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 942948 T1787 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4] 2> 942966 T1787 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 942967 T1787 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:60568/solr
[junit4] 2> 942967 T1787 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 942968 T1787 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 942972 T1807 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6d084f56 name:ZooKeeperConnection Watcher:127.0.0.1:60568 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 942973 T1787 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 942981 T1787 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4] 2> 942994 T1787 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 942996 T1809 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@c7048d9 name:ZooKeeperConnection Watcher:127.0.0.1:60568/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 942996 T1787 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 942998 T1787 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 943008 T1787 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 943012 T1787 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 943020 T1787 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:60571_
[junit4] 2> 943021 T1787 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:60571_
[junit4] 2> 943026 T1787 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 943040 T1787 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 943048 T1787 oasc.Overseer.start Overseer (id=90037644413370371-127.0.0.1:60571_-n_0000000000) starting
[junit4] 2> 943059 T1787 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 943071 T1811 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 943072 T1787 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 943075 T1787 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 943077 T1787 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 943081 T1810 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 943085 T1812 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 943085 T1812 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 943087 T1812 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 944586 T1810 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 944587 T1810 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:60571_",
[junit4] 2> "base_url":"http://127.0.0.1:60571"}
[junit4] 2> 944587 T1810 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with numShards 1
[junit4] 2> 944588 T1810 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 944603 T1809 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> 945089 T1812 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 945089 T1812 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1373865424107/collection1
[junit4] 2> 945089 T1812 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4] 2> 945090 T1812 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 945091 T1812 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4] 2> 945092 T1812 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1373865424107/collection1/'
[junit4] 2> 945094 T1812 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1373865424107/collection1/lib/README' to classloader
[junit4] 2> 945094 T1812 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1373865424107/collection1/lib/classes/' to classloader
[junit4] 2> 945148 T1812 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4] 2> 945209 T1812 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 945310 T1812 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 945321 T1812 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 946080 T1812 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 946081 T1812 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 946082 T1812 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 946098 T1812 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 946102 T1812 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 946119 T1812 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 946124 T1812 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 946129 T1812 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 946130 T1812 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 946130 T1812 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 946131 T1812 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 946132 T1812 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 946132 T1812 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 946132 T1812 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 946133 T1812 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1373865424107/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZkTest-1373865423779/control/data/
[junit4] 2> 946133 T1812 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@64a7c45e
[junit4] 2> 946134 T1812 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1373865423779/control/data
[junit4] 2> 946134 T1812 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZkTest-1373865423779/control/data/index/
[junit4] 2> 946134 T1812 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZkTest-1373865423779/control/data/index' doesn't exist. Creating new index...
[junit4] 2> 946135 T1812 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1373865423779/control/data/index
[junit4] 2> 946140 T1812 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@536e4d57 lockFactory=org.apache.lucene.store.NativeFSLockFactory@7cb1751c),segFN=segments_1,generation=1}
[junit4] 2> 946140 T1812 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 946144 T1812 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 946145 T1812 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 946145 T1812 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 946146 T1812 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 946146 T1812 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 946146 T1812 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 946147 T1812 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 946147 T1812 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 946148 T1812 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 946159 T1812 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 946167 T1812 oass.SolrIndexSearcher.<init> Opening Searcher@2e3ea558 main
[junit4] 2> 946169 T1812 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 946169 T1812 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 946172 T1813 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@2e3ea558 main{StandardDirectoryReader(segments_1:1)}
[junit4] 2> 946173 T1812 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 946173 T1812 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:60571 collection:control_collection shard:shard1
[junit4] 2> 946173 T1812 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=30000&socketTimeout=30000&retry=false
[junit4] 2> 946192 T1812 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4] 2> 946208 T1812 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 946222 T1812 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 946222 T1812 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 946222 T1812 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:60571/collection1/
[junit4] 2> 946222 T1812 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 946223 T1812 oasc.SyncStrategy.syncToMe http://127.0.0.1:60571/collection1/ has no replicas
[junit4] 2> 946223 T1812 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:60571/collection1/ shard1
[junit4] 2> 946223 T1812 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4] 2> 947611 T1810 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 947633 T1809 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> 947683 T1812 oasc.ZkController.register We are http://127.0.0.1:60571/collection1/ and leader is http://127.0.0.1:60571/collection1/
[junit4] 2> 947683 T1812 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:60571
[junit4] 2> 947683 T1812 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 947683 T1812 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 947684 T1812 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 947693 T1812 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 947695 T1787 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/solr/build/solr-core/test/J0
[junit4] 2> 947696 T1787 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 947696 T1787 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 947707 T1787 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4] 2> 947709 T1787 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 947711 T1816 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@63069b01 name:ZooKeeperConnection Watcher:127.0.0.1:60568/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 947711 T1787 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 947712 T1787 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 947715 T1787 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4] 2> 947982 T1787 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 947985 T1787 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:60576
[junit4] 2> 947986 T1787 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 947986 T1787 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 947987 T1787 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1373865429264
[junit4] 2> 947987 T1787 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1373865429264/'
[junit4] 2> 948024 T1787 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1373865429264/solr.xml
[junit4] 2> 948101 T1787 oasc.CoreContainer.<init> New CoreContainer 889692252
[junit4] 2> 948102 T1787 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1373865429264/]
[junit4] 2> 948104 T1787 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 948104 T1787 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 948105 T1787 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 948105 T1787 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 948105 T1787 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 948106 T1787 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 948106 T1787 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 948107 T1787 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 948107 T1787 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 948108 T1787 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4] 2> 948124 T1787 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 948124 T1787 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:60568/solr
[junit4] 2> 948125 T1787 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 948126 T1787 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 948129 T1827 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7b11337 name:ZooKeeperConnection Watcher:127.0.0.1:60568 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 948129 T1787 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 948132 T1787 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4] 2> 948143 T1787 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 948145 T1829 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@424db64f name:ZooKeeperConnection Watcher:127.0.0.1:60568/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 948145 T1787 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 948150 T1787 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 949140 T1810 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 949142 T1810 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:60571_",
[junit4] 2> "base_url":"http://127.0.0.1:60571"}
[junit4] 2> 949158 T1816 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> 949158 T1787 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:60576_
[junit4] 2> 949158 T1829 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> 949158 T1809 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> 949162 T1787 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:60576_
[junit4] 2> 949174 T1816 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 949174 T1829 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 949175 T1816 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> 949174 T1809 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 949175 T1829 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> 949175 T1809 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> 949183 T1830 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 949183 T1830 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 949185 T1830 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 950666 T1810 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 950667 T1810 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:60576_",
[junit4] 2> "base_url":"http://127.0.0.1:60576"}
[junit4] 2> 950667 T1810 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with numShards 2
[junit4] 2> 950668 T1810 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 950682 T1809 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> 950682 T1829 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> 950682 T1816 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> 951187 T1830 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 951187 T1830 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1373865429264/collection1
[junit4] 2> 951187 T1830 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 951188 T1830 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 951189 T1830 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 951190 T1830 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1373865429264/collection1/'
[junit4] 2> 951192 T1830 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1373865429264/collection1/lib/README' to classloader
[junit4] 2> 951192 T1830 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1373865429264/collection1/lib/classes/' to classloader
[junit4] 2> 951247 T1830 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4] 2> 951307 T1830 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 951409 T1830 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 951420 T1830 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 952052 T1830 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 952053 T1830 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 952054 T1830 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 952067 T1830 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 952071 T1830 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 952088 T1830 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 952093 T1830 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 952098 T1830 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 952100 T1830 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 952100 T1830 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 952100 T1830 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 952101 T1830 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 952102 T1830 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 952102 T1830 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 952102 T1830 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1373865429264/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZkTest-1373865423779/jetty1/
[junit4] 2> 952103 T1830 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@64a7c45e
[junit4] 2> 952104 T1830 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1373865423779/jetty1
[junit4] 2> 952104 T1830 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZkTest-1373865423779/jetty1/index/
[junit4] 2> 952104 T1830 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZkTest-1373865423779/jetty1/index' doesn't exist. Creating new index...
[junit4] 2> 952104 T1830 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1373865423779/jetty1/index
[junit4] 2> 952108 T1830 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@34886f76 lockFactory=org.apache.lucene.store.NativeFSLockFactory@4795789e),segFN=segments_1,generation=1}
[junit4] 2> 952108 T1830 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 952113 T1830 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 952113 T1830 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 952114 T1830 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 952114 T1830 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 952115 T1830 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 952115 T1830 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 952115 T1830 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 952116 T1830 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 952116 T1830 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 952126 T1830 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 952133 T1830 oass.SolrIndexSearcher.<init> Opening Searcher@59ebe425 main
[junit4] 2> 952135 T1830 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 952135 T1830 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 952140 T1831 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@59ebe425 main{StandardDirectoryReader(segments_1:1)}
[junit4] 2> 952142 T1830 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 952142 T1830 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:60576 collection:collection1 shard:shard1
[junit4] 2> 952142 T1830 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=30000&socketTimeout=30000&retry=false
[junit4] 2> 952160 T1830 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 952187 T1830 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 952191 T1830 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 952191 T1830 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 952192 T1830 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:60576/collection1/
[junit4] 2> 952192 T1830 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 952192 T1830 oasc.SyncStrategy.syncToMe http://127.0.0.1:60576/collection1/ has no replicas
[junit4] 2> 952192 T1830 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:60576/collection1/ shard1
[junit4] 2> 952193 T1830 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 952198 T1810 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 952277 T1816 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> 952277 T1829 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> 952277 T1809 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> 952317 T1830 oasc.ZkController.register We are http://127.0.0.1:60576/collection1/ and leader is http://127.0.0.1:60576/collection1/
[junit4] 2> 952317 T1830 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:60576
[junit4] 2> 952317 T1830 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 952317 T1830 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 952318 T1830 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 952320 T1830 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 952321 T1787 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/solr/build/solr-core/test/J0
[junit4] 2> 952322 T1787 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 952323 T1787 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 952601 T1787 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 952604 T1787 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:60595
[junit4] 2> 952605 T1787 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 952605 T1787 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 952605 T1787 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1373865433883
[junit4] 2> 952606 T1787 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1373865433883/'
[junit4] 2> 952642 T1787 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1373865433883/solr.xml
[junit4] 2> 952715 T1787 oasc.CoreContainer.<init> New CoreContainer 1084102584
[junit4] 2> 952715 T1787 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1373865433883/]
[junit4] 2> 952717 T1787 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 952717 T1787 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 952718 T1787 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 952718 T1787 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 952719 T1787 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 952719 T1787 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 952720 T1787 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 952720 T1787 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 952721 T1787 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 952721 T1787 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4] 2> 952738 T1787 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 952739 T1787 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:60568/solr
[junit4] 2> 952739 T1787 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 952740 T1787 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 952743 T1843 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4b27522c name:ZooKeeperConnection Watcher:127.0.0.1:60568 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 952744 T1787 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 952746 T1787 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4] 2> 952758 T1787 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 952761 T1845 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5e31c91f name:ZooKeeperConnection Watcher:127.0.0.1:60568/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 952761 T1787 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 952767 T1787 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 953771 T1787 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:60595_
[junit4] 2> 953783 T1787 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:60595_
[junit4] 2> 953786 T1810 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 953787 T1829 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 953787 T1845 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 953787 T1829 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> 953787 T1816 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 953787 T1810 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:60576_",
[junit4] 2> "base_url":"http://127.0.0.1:60576"}
[junit4] 2> 953788 T1816 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> 953796 T1846 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 953796 T1846 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 953801 T1846 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 953802 T1810 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:60595_",
[junit4] 2> "base_url":"http://127.0.0.1:60595"}
[junit4] 2> 953802 T1810 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4] 2> 953803 T1810 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 953816 T1829 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> 953816 T1845 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> 953816 T1816 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> 953827 T1809 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 953827 T1809 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> 953829 T1809 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> 954803 T1846 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 954803 T1846 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1373865433883/collection1
[junit4] 2> 954803 T1846 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 954805 T1846 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 954805 T1846 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 954809 T1846 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1373865433883/collection1/'
[junit4] 2> 954813 T1846 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1373865433883/collection1/lib/classes/' to classloader
[junit4] 2> 954815 T1846 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1373865433883/collection1/lib/README' to classloader
[junit4] 2> 954896 T1846 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4] 2> 954969 T1846 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 955071 T1846 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 955083 T1846 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 955733 T1846 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 955734 T1846 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 955734 T1846 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 955748 T1846 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 955752 T1846 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 955770 T1846 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 955775 T1846 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 955780 T1846 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 955781 T1846 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 955782 T1846 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 955782 T1846 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 955783 T1846 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 955784 T1846 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 955784 T1846 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 955784 T1846 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1373865433883/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZkTest-1373865423779/jetty2/
[junit4] 2> 955785 T1846 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@64a7c45e
[junit4] 2> 955786 T1846 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1373865423779/jetty2
[junit4] 2> 955786 T1846 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZkTest-1373865423779/jetty2/index/
[junit4] 2> 955787 T1846 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZkTest-1373865423779/jetty2/index' doesn't exist. Creating new index...
[junit4] 2> 955787 T1846 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1373865423779/jetty2/index
[junit4] 2> 955791 T1846 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@2c26c21b lockFactory=org.apache.lucene.store.NativeFSLockFactory@79ee197f),segFN=segments_1,generation=1}
[junit4] 2> 955791 T1846 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 955795 T1846 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 955795 T1846 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 955796 T1846 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 955797 T1846 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 955797 T1846 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 955798 T1846 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 955798 T1846 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 955799 T1846 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 955799 T1846 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 955809 T1846 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 955816 T1846 oass.SolrIndexSearcher.<init> Opening Searcher@58c6c18a main
[junit4] 2> 955817 T1846 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 955818 T1846 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 955822 T1847 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@58c6c18a main{StandardDirectoryReader(segments_1:1)}
[junit4] 2> 955824 T1846 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 955824 T1846 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:60595 collection:collection1 shard:shard2
[junit4] 2> 955824 T1846 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=30000&socketTimeout=30000&retry=false
[junit4] 2> 955842 T1846 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4] 2> 955894 T1846 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
[junit4] 2> 955905 T1846 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 955905 T1846 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 955905 T1846 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:60595/collection1/
[junit4] 2> 955905 T1846 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 955906 T1846 oasc.SyncStrategy.syncToMe http://127.0.0.1:60595/collection1/ has no replicas
[junit4] 2> 955906 T1846 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:60595/collection1/ shard2
[junit4] 2> 955906 T1846 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4] 2> 956832 T1810 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 956885 T1829 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> 956885 T1845 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> 956885 T1809 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> 956885 T1816 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> 956889 T1846 oasc.ZkController.register We are http://127.0.0.1:60595/collection1/ and leader is http://127.0.0.1:60595/collection1/
[junit4] 2> 956889 T1846 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:60595
[junit4] 2> 956889 T1846 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 956889 T1846 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 956890 T1846 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 956894 T1846 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 956901 T1787 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/solr/build/solr-core/test/J0
[junit4] 2> 956901 T1787 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 956902 T1787 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 957184 T1787 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 957187 T1787 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:60598
[junit4] 2> 957188 T1787 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 957188 T1787 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 957189 T1787 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1373865438463
[junit4] 2> 957189 T1787 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1373865438463/'
[junit4] 2> 957226 T1787 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1373865438463/solr.xml
[junit4] 2> 957298 T1787 oasc.CoreContainer.<init> New CoreContainer 315890771
[junit4] 2> 957298 T1787 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1373865438463/]
[junit4] 2> 957300 T1787 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 957301 T1787 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 957301 T1787 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 957301 T1787 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 957302 T1787 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 957302 T1787 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 957303 T1787 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 957303 T1787 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 957304 T1787 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 957304 T1787 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4] 2> 957320 T1787 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 957321 T1787 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:60568/solr
[junit4] 2> 957321 T1787 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 957322 T1787 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 957326 T1859 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@238f96cd name:ZooKeeperConnection Watcher:127.0.0.1:60568 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 957326 T1787 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 957342 T1787 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4] 2> 957352 T1787 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 957355 T1861 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@460323b2 name:ZooKeeperConnection Watcher:127.0.0.1:60568/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 957355 T1787 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 957365 T1787 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 958369 T1787 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:60598_
[junit4] 2> 958372 T1787 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:60598_
[junit4] 2> 958375 T1845 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> 958376 T1861 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 958376 T1816 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 958376 T1809 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 958376 T1829 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 958376 T1809 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> 958376 T1816 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> 958377 T1829 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> 958377 T1845 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 958393 T1862 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 958393 T1862 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 958395 T1862 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 958404 T1810 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 958405 T1810 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:60595_",
[junit4] 2> "base_url":"http://127.0.0.1:60595"}
[junit4] 2> 958410 T1810 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:60598_",
[junit4] 2> "base_url":"http://127.0.0.1:60598"}
[junit4] 2> 958410 T1810 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4] 2> 958410 T1810 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 958421 T1861 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> 958422 T1845 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> 958422 T1809 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> 958422 T1829 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> 958422 T1816 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> 959396 T1862 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 959396 T1862 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1373865438463/collection1
[junit4] 2> 959396 T1862 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 959397 T1862 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 959398 T1862 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 959400 T1862 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1373865438463/collection1/'
[junit4] 2> 959402 T1862 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1373865438463/collection1/lib/README' to classloader
[junit4] 2> 959403 T1862 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1373865438463/collection1/lib/classes/' to classloader
[junit4] 2> 959471 T1862 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4] 2> 959532 T1862 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 959634 T1862 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 959645 T1862 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 960395 T1862 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 960396 T1862 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 960397 T1862 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 960410 T1862 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 960414 T1862 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 960436 T1862 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 960441 T1862 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 960446 T1862 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 960448 T1862 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 960448 T1862 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 960448 T1862 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 960449 T1862 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 960450 T1862 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 960450 T1862 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 960450 T1862 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1373865438463/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZkTest-1373865423779/jetty3/
[junit4] 2> 960451 T1862 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@64a7c45e
[junit4] 2> 960452 T1862 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1373865423779/jetty3
[junit4] 2> 960452 T1862 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZkTest-1373865423779/jetty3/index/
[junit4] 2> 960452 T1862 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZkTest-1373865423779/jetty3/index' doesn't exist. Creating new index...
[junit4] 2> 960452 T1862 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZkTest-1373865423779/jetty3/index
[junit4] 2> 960456 T1862 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@fe2a8a5 lockFactory=org.apache.lucene.store.NativeFSLockFactory@3a6399d9),segFN=segments_1,generation=1}
[junit4] 2> 960456 T1862 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 960461 T1862 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 960461 T1862 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 960462 T1862 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 960462 T1862 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 960463 T1862 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 960463 T1862 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 960464 T1862 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 960464 T1862 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 960465 T1862 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 960474 T1862 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 960482 T1862 oass.SolrIndexSearcher.<init> Opening Searcher@1d6a6644 main
[junit4] 2> 960483 T1862 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 960483 T1862 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 960488 T1863 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1d6a6644 main{StandardDirectoryReader(segments_1:1)}
[junit4] 2> 960490 T1862 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 960490 T1862 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:60598 collection:collection1 shard:shard1
[junit4] 2> 960491 T1862 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=30000&socketTimeout=30000&retry=false
[junit4] 2> 960512 T1862 oasc.ZkController.register We are http://127.0.0.1:60598/collection1/ and leader is http://127.0.0.1:60576/collection1/
[junit4] 2> 960513 T1862 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:60598
[junit4] 2> 960513 T1862 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4] 2> 960513 T1862 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4] 2> ASYNC NEW_CORE C905 name=collection1 org.apache.solr.core.SolrCore@5e496f7d url=http://127.0.0.1:60598/collection1 node=127.0.0.1:60598_ C905_STATE=coll:collection1 core:collection1 props:{state=down, core=collection1, node_name=127.0.0.1:60598_, base_url=http://127.0.0.1:60598}
[junit4] 2> 960514 T1864 C905 P60598 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4] 2> 960514 T1862 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 960517 T1787 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/solr/build/solr-core/test/J0
[junit4] 2> 960518 T1787 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 960518 T1864 C905 P60598 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4] 2> 960519 T1787 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 960519 T1864 C905 P60598 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4] 2> 960520 T1864 C905 P60598 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 960525 T1864 C905 P60598 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 960541 T1819 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: core_node3, state: recovering, checkLive: true, onlyIfLeader: true
[junit4] 2> 960802 T1787 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 960804 T1787 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:60602
[junit4] 2> 960805 T1787 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 960805 T1787 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 960806 T1787 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty4-1373865442084
[junit4] 2> 960806 T1787 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty4-1373865442084/'
[junit4] 2> 960843 T1787 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty4-1373865442084/solr.xml
[junit4] 2> 960915 T1787 oasc.CoreContainer.<init> New CoreContainer 816104190
[junit4] 2> 960916 T1787 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty4-1373865442084/]
[junit4] 2> 960917 T1787 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 960918 T1787 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 960918 T1787 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 960919 T1787 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 960919 T1787 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 960919 T1787 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 960920 T1787 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 960920 T1787 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -
[...truncated too long message...]
ngsFormat(name=TestBloomFilteredLucene41Postings), n_dt1=Pulsing41(freqCutoff=17 minBlockSize=70 maxBlockSize=173), genre_s=PostingsFormat(name=MockRandom), author_t=Pulsing41(freqCutoff=17 minBlockSize=70 maxBlockSize=173), range_facet_l=PostingsFormat(name=TestBloomFilteredLucene41Postings), n_ti1=PostingsFormat(name=MockRandom), text=PostingsFormat(name=Memory doPackFST= true), _version_=Pulsing41(freqCutoff=17 minBlockSize=70 maxBlockSize=173), val_i=PostingsFormat(name=MockRandom), SubjectTerms_mfacet=Pulsing41(freqCutoff=17 minBlockSize=70 maxBlockSize=173), series_t=Pulsing41(freqCutoff=17 minBlockSize=70 maxBlockSize=173), a_t=PostingsFormat(name=TestBloomFilteredLucene41Postings), n_tdt1=Pulsing41(freqCutoff=17 minBlockSize=70 maxBlockSize=173), regex_dup_A_s=PostingsFormat(name=Memory doPackFST= true), price=PostingsFormat(name=Memory doPackFST= true), other_tl1=Pulsing41(freqCutoff=17 minBlockSize=70 maxBlockSize=173), n_l1=PostingsFormat(name=TestBloomFilteredLucene41Postings), a_si=Pulsing41(freqCutoff=17 minBlockSize=70 maxBlockSize=173), inStock=PostingsFormat(name=Memory doPackFST= true)}, docValues:{}, sim=RandomSimilarityProvider(queryNorm=true,coord=yes): {}, locale=ja_JP, timezone=America/Indiana/Winamac
[junit4] 2> NOTE: FreeBSD 9.1-RELEASE-p3 amd64/Sun Microsystems Inc. 1.6.0_32 (64-bit)/cpus=16,threads=2,free=264546648,total=461176832
[junit4] 2> NOTE: All tests run in this JVM: [ZkControllerTest, TestPHPSerializedResponseWriter, TestRealTimeGet, HdfsBasicDistributedZk2Test, MoreLikeThisHandlerTest, SoftAutoCommitTest, TestPropInjectDefaults, TestReversedWildcardFilterFactory, HdfsUnloadDistributedZkTest, TestManagedSchemaFieldResource, PeerSyncTest, TestInfoStreamLogging, PolyFieldTest, CacheHeaderTest, TestFieldTypeResource, SolrIndexSplitterTest, TestWriterPerf, TestPluginEnable, TestLRUCache, FastVectorHighlighterTest, TestSolrIndexConfig, HdfsRecoveryZkTest, TestSolrXmlPersistence, TestSolrDeletionPolicy2, TestBadConfig, SearchHandlerTest, LukeRequestHandlerTest, AutoCommitTest, TestSolrQueryParserResource, StatelessScriptUpdateProcessorFactoryTest, TestStressRecovery, TestCoreContainer, ExternalFileFieldSortTest, PrimUtilsTest, TestRandomDVFaceting, TestCharFilters, FieldMutatingUpdateProcessorTest, SolrInfoMBeanTest, WordBreakSolrSpellCheckerTest, UUIDFieldTest, SliceStateUpdateTest, TestRecoveryHdfs, DistributedQueryElevationComponentTest, ParsingFieldUpdateProcessorsTest, IndexSchemaTest, TestIBSimilarityFactory, TestValueSourceCache, TestQueryUtils, ScriptEngineTest, TestPseudoReturnFields, LeaderElectionTest, TestConfig, MBeansHandlerTest, JsonLoaderTest, HdfsChaosMonkeySafeLeaderTest, ShardSplitTest, TestStressVersions, QueryElevationComponentTest, TestFastWriter, HdfsBasicDistributedZkTest, TestJoin, DistributedTermsComponentTest, TestPerFieldSimilarity, AnalysisAfterCoreReloadTest, SpatialFilterTest, TestFaceting, SOLR749Test, SliceStateTest, BlockDirectoryTest, DateFieldTest, TestFieldTypeCollectionResource, SimpleFacetsTest, CoreAdminHandlerTest, TestMaxScoreQueryParser, TestSolrDeletionPolicy1, TestFieldCollectionResource, BasicDistributedZkTest]
[junit4] 2> NOTE: download the large Jenkins line-docs file by running 'ant get-jenkins-line-docs' in the lucene directory.
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=BasicDistributedZkTest -Dtests.seed=A37D2D93108F855A -Dtests.multiplier=2 -Dtests.nightly=true -Dtests.slow=true -Dtests.linedocsfile=/home/hudson/lucene-data/enwiki.random.lines.txt -Dtests.locale=ja_JP -Dtests.timezone=America/Indiana/Winamac -Dtests.file.encoding=ISO-8859-1
[junit4] ERROR 0.00s J0 | BasicDistributedZkTest (suite) <<<
[junit4] > Throwable #1: com.carrotsearch.randomizedtesting.ThreadLeakError: 1 thread leaked from SUITE scope at org.apache.solr.cloud.BasicDistributedZkTest:
[junit4] > 1) Thread[id=2293, name=recoveryCmdExecutor-995-thread-1, state=RUNNABLE, group=TGRP-BasicDistributedZkTest]
[junit4] > at java.net.PlainSocketImpl.socketConnect(Native Method)
[junit4] > at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:327)
[junit4] > at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:193)
[junit4] > at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:180)
[junit4] > at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:384)
[junit4] > at java.net.Socket.connect(Socket.java:546)
[junit4] > at org.apache.http.conn.scheme.PlainSocketFactory.connectSocket(PlainSocketFactory.java:127)
[junit4] > at org.apache.http.impl.conn.DefaultClientConnectionOperator.openConnection(DefaultClientConnectionOperator.java:180)
[junit4] > at org.apache.http.impl.conn.ManagedClientConnectionImpl.open(ManagedClientConnectionImpl.java:294)
[junit4] > at org.apache.http.impl.client.DefaultRequestDirector.tryConnect(DefaultRequestDirector.java:645)
[junit4] > at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:480)
[junit4] > at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:906)
[junit4] > at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:805)
[junit4] > at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:784)
[junit4] > at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:365)
[junit4] > at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:180)
[junit4] > at org.apache.solr.cloud.SyncStrategy$1.run(SyncStrategy.java:291)
[junit4] > at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1146)
[junit4] > at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
[junit4] > at java.lang.Thread.run(Thread.java:679)
[junit4] > at __randomizedtesting.SeedInfo.seed([A37D2D93108F855A]:0)Throwable #2: com.carrotsearch.randomizedtesting.ThreadLeakError: There are still zombie threads that couldn't be terminated:
[junit4] > 1) Thread[id=2293, name=recoveryCmdExecutor-995-thread-1, state=RUNNABLE, group=TGRP-BasicDistributedZkTest]
[junit4] > at java.net.PlainSocketImpl.socketConnect(Native Method)
[junit4] > at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:327)
[junit4] > at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:193)
[junit4] > at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:180)
[junit4] > at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:384)
[junit4] > at java.net.Socket.connect(Socket.java:546)
[junit4] > at org.apache.http.conn.scheme.PlainSocketFactory.connectSocket(PlainSocketFactory.java:127)
[junit4] > at org.apache.http.impl.conn.DefaultClientConnectionOperator.openConnection(DefaultClientConnectionOperator.java:180)
[junit4] > at org.apache.http.impl.conn.ManagedClientConnectionImpl.open(ManagedClientConnectionImpl.java:294)
[junit4] > at org.apache.http.impl.client.DefaultRequestDirector.tryConnect(DefaultRequestDirector.java:645)
[junit4] > at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:480)
[junit4] > at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:906)
[junit4] > at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:805)
[junit4] > at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:784)
[junit4] > at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:365)
[junit4] > at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:180)
[junit4] > at org.apache.solr.cloud.SyncStrategy$1.run(SyncStrategy.java:291)
[junit4] > at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1146)
[junit4] > at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
[junit4] > at java.lang.Thread.run(Thread.java:679)
[junit4] > at __randomizedtesting.SeedInfo.seed([A37D2D93108F855A]:0)
[junit4] Completed on J0 in 227.70s, 1 test, 2 errors <<< FAILURES!
[...truncated 574 lines...]
BUILD FAILED
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/build.xml:402: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/build.xml:375: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/build.xml:39: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/solr/build.xml:181: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/solr/common-build.xml:449: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/lucene/common-build.xml:1250: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.4/lucene/common-build.xml:893: There were test failures: 317 suites, 1337 tests, 2 suite-level errors, 696 ignored (3 assumptions)
Total time: 83 minutes 52 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure