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/08/13 04:57:30 UTC
[JENKINS] Lucene-Solr-Tests-trunk-Java7 - Build # 4230 - Failure
Build: https://builds.apache.org/job/Lucene-Solr-Tests-trunk-Java7/4230/
1 tests failed.
REGRESSION: org.apache.solr.cloud.FullSolrCloudDistribCmdsTest.testDistribSearch
Error Message:
Java heap space
Stack Trace:
java.lang.OutOfMemoryError: Java heap space
Build Log:
[...truncated 10446 lines...]
[junit4] Suite: org.apache.solr.cloud.FullSolrCloudDistribCmdsTest
[junit4] 2> 1568103 T3040 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /w_/nh
[junit4] 2> 1568109 T3040 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4] 2> Creating dataDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./solrtest-FullSolrCloudDistribCmdsTest-1376360940842
[junit4] 2> 1568111 T3040 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 1568111 T3041 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 1568212 T3040 oasc.ZkTestServer.run start zk server on port:17227
[junit4] 2> 1568213 T3040 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1568217 T3047 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@376f485a name:ZooKeeperConnection Watcher:127.0.0.1:17227 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1568217 T3040 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1568218 T3040 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 1568231 T3040 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1568233 T3049 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@594b4d1f name:ZooKeeperConnection Watcher:127.0.0.1:17227/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1568233 T3040 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1568233 T3040 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4] 2> 1568242 T3040 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4] 2> 1568248 T3040 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4] 2> 1568251 T3040 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4] 2> 1568254 T3040 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4] 2> 1568254 T3040 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4] 2> 1568269 T3040 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
[junit4] 2> 1568270 T3040 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4] 2> 1568373 T3040 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 1568374 T3040 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 1568377 T3040 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4] 2> 1568378 T3040 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4] 2> 1568387 T3040 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4] 2> 1568387 T3040 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4] 2> 1568390 T3040 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4] 2> 1568391 T3040 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4] 2> 1568394 T3040 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4] 2> 1568395 T3040 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4] 2> 1568397 T3040 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 1568398 T3040 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 1568401 T3040 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4] 2> 1568402 T3040 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4] 2> 1568409 T3040 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4] 2> 1568410 T3040 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4] 2> 1568683 T3040 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 1568690 T3040 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:24227
[junit4] 2> 1568690 T3040 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 1568691 T3040 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1568691 T3040 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-controljetty-1376360941145
[junit4] 2> 1568692 T3040 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-controljetty-1376360941145/'
[junit4] 2> 1568733 T3040 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-controljetty-1376360941145/solr.xml
[junit4] 2> 1568828 T3040 oasc.CoreContainer.<init> New CoreContainer 734537376
[junit4] 2> 1568829 T3040 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-controljetty-1376360941145/]
[junit4] 2> 1568831 T3040 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 1568831 T3040 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 1568832 T3040 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 1568832 T3040 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 1568833 T3040 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 1568833 T3040 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 1568834 T3040 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 1568834 T3040 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 1568835 T3040 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 1568835 T3040 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4] 2> 1568851 T3040 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:17227/solr
[junit4] 2> 1568852 T3040 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 1568853 T3040 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1568876 T3060 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@54112dde name:ZooKeeperConnection Watcher:127.0.0.1:17227 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1568877 T3040 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1568944 T3040 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4] 2> 1568955 T3040 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1568957 T3062 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@70adf540 name:ZooKeeperConnection Watcher:127.0.0.1:17227/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1568957 T3040 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1568978 T3040 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 1569037 T3040 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 1569041 T3040 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 1569073 T3040 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:24227_w_%2Fnh
[junit4] 2> 1569075 T3040 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:24227_w_%2Fnh
[junit4] 2> 1569078 T3040 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 1569084 T3040 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 1569086 T3040 oasc.Overseer.start Overseer (id=90201190619480067-127.0.0.1:24227_w_%2Fnh-n_0000000000) starting
[junit4] 2> 1569135 T3040 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 1569145 T3064 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 1569146 T3040 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 1569148 T3040 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 1569155 T3040 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1569158 T3063 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 1569164 T3065 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 1569165 T3065 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1569166 T3065 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 1570661 T3063 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1570662 T3063 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:24227_w_%2Fnh",
[junit4] 2> "base_url":"http://127.0.0.1:24227/w_/nh"}
[junit4] 2> 1570663 T3063 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1]
[junit4] 2> 1570663 T3063 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 1570683 T3062 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> 1571168 T3065 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 1571168 T3065 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-controljetty-1376360941145/collection1
[junit4] 2> 1571168 T3065 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4] 2> 1571169 T3065 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 1571169 T3065 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4] 2> 1571170 T3065 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-controljetty-1376360941145/collection1/'
[junit4] 2> 1571172 T3065 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-controljetty-1376360941145/collection1/lib/classes/' to classloader
[junit4] 2> 1571173 T3065 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-controljetty-1376360941145/collection1/lib/README' to classloader
[junit4] 2> 1571235 T3065 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 1571300 T3065 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 1571402 T3065 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 1571414 T3065 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 1572048 T3065 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 1572057 T3065 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 1572060 T3065 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 1572072 T3065 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1572076 T3065 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1572080 T3065 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 1572081 T3065 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 1572081 T3065 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 1572081 T3065 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 1572082 T3065 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 1572082 T3065 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 1572082 T3065 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 1572083 T3065 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-controljetty-1376360941145/collection1/, dataDir=./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-1376360940842/control/data/
[junit4] 2> 1572083 T3065 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@c40fc1c
[junit4] 2> 1572084 T3065 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-1376360940842/control/data
[junit4] 2> 1572084 T3065 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-1376360940842/control/data/index/
[junit4] 2> 1572084 T3065 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-1376360940842/control/data/index' doesn't exist. Creating new index...
[junit4] 2> 1572084 T3065 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-1376360940842/control/data/index
[junit4] 2> 1572088 T3065 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@51455344 lockFactory=org.apache.lucene.store.NativeFSLockFactory@3ab9e1f3),segFN=segments_1,generation=1}
[junit4] 2> 1572088 T3065 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1572092 T3065 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 1572092 T3065 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 1572093 T3065 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1572094 T3065 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 1572094 T3065 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 1572094 T3065 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 1572094 T3065 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 1572095 T3065 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 1572095 T3065 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 1572106 T3065 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 1572111 T3065 oass.SolrIndexSearcher.<init> Opening Searcher@44a462fb main
[junit4] 2> 1572112 T3065 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 1572112 T3065 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 1572115 T3066 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@44a462fb main{StandardDirectoryReader(segments_1:1)}
[junit4] 2> 1572117 T3065 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 1572117 T3065 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:24227/w_/nh collection:control_collection shard:shard1
[junit4] 2> 1572117 T3065 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=15000&socketTimeout=30000&retry=false
[junit4] 2> 1572128 T3065 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4] 2> 1572148 T3065 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 1572151 T3065 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 1572151 T3065 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 1572151 T3065 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:24227/w_/nh/collection1/
[junit4] 2> 1572151 T3065 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 1572151 T3065 oasc.SyncStrategy.syncToMe http://127.0.0.1:24227/w_/nh/collection1/ has no replicas
[junit4] 2> 1572152 T3065 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:24227/w_/nh/collection1/ shard1
[junit4] 2> 1572152 T3065 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4] 2> 1572186 T3063 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1572193 T3062 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> 1572208 T3065 oasc.ZkController.register We are http://127.0.0.1:24227/w_/nh/collection1/ and leader is http://127.0.0.1:24227/w_/nh/collection1/
[junit4] 2> 1572208 T3065 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:24227/w_/nh
[junit4] 2> 1572208 T3065 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 1572208 T3065 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 1572209 T3065 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1572210 T3065 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1572211 T3040 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0
[junit4] 2> 1572212 T3040 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 1572212 T3040 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 1572219 T3040 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4] 2> 1572220 T3040 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1572222 T3069 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@27618453 name:ZooKeeperConnection Watcher:127.0.0.1:17227/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1572222 T3040 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1572223 T3040 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1572225 T3040 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4] 2> 1572492 T3040 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 1572496 T3040 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:55724
[junit4] 2> 1572497 T3040 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 1572497 T3040 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1572498 T3040 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty1-1376360944958
[junit4] 2> 1572498 T3040 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty1-1376360944958/'
[junit4] 2> 1572540 T3040 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty1-1376360944958/solr.xml
[junit4] 2> 1572635 T3040 oasc.CoreContainer.<init> New CoreContainer 1335877786
[junit4] 2> 1572636 T3040 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty1-1376360944958/]
[junit4] 2> 1572638 T3040 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 1572638 T3040 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 1572639 T3040 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 1572639 T3040 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 1572640 T3040 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 1572640 T3040 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 1572641 T3040 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 1572641 T3040 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 1572642 T3040 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 1572642 T3040 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4] 2> 1572660 T3040 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:17227/solr
[junit4] 2> 1572661 T3040 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 1572662 T3040 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1572700 T3080 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@73ad0516 name:ZooKeeperConnection Watcher:127.0.0.1:17227 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1572701 T3040 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1572703 T3040 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4] 2> 1572711 T3040 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1572713 T3082 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6755f3ea name:ZooKeeperConnection Watcher:127.0.0.1:17227/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1572713 T3040 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1572718 T3040 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1573698 T3063 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1573700 T3063 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:24227_w_%2Fnh",
[junit4] 2> "base_url":"http://127.0.0.1:24227/w_/nh"}
[junit4] 2> 1573727 T3040 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:55724_w_%2Fnh
[junit4] 2> 1573730 T3040 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:55724_w_%2Fnh
[junit4] 2> 1573731 T3062 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> 1573731 T3082 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> 1573731 T3069 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> 1573758 T3082 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1573759 T3069 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1573759 T3062 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 1)
[junit4] 2> 1573786 T3062 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1573792 T3083 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 1573793 T3083 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1573794 T3083 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 1575260 T3063 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1575262 T3063 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:55724_w_%2Fnh",
[junit4] 2> "base_url":"http://127.0.0.1:55724/w_/nh"}
[junit4] 2> 1575262 T3063 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2]
[junit4] 2> 1575262 T3063 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 1575285 T3062 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> 1575285 T3082 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> 1575285 T3069 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> 1575797 T3083 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 1575797 T3083 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty1-1376360944958/collection1
[junit4] 2> 1575797 T3083 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 1575798 T3083 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 1575798 T3083 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 1575799 T3083 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty1-1376360944958/collection1/'
[junit4] 2> 1575801 T3083 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty1-1376360944958/collection1/lib/classes/' to classloader
[junit4] 2> 1575802 T3083 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty1-1376360944958/collection1/lib/README' to classloader
[junit4] 2> 1575863 T3083 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 1575958 T3083 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 1576059 T3083 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 1576071 T3083 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 1576720 T3083 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 1576733 T3083 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 1576738 T3083 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 1576752 T3083 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1576757 T3083 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1576762 T3083 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 1576763 T3083 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 1576763 T3083 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 1576763 T3083 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 1576764 T3083 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 1576765 T3083 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 1576765 T3083 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 1576765 T3083 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty1-1376360944958/collection1/, dataDir=./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-1376360940842/jetty1/
[junit4] 2> 1576766 T3083 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@c40fc1c
[junit4] 2> 1576767 T3083 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-1376360940842/jetty1
[junit4] 2> 1576767 T3083 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-1376360940842/jetty1/index/
[junit4] 2> 1576768 T3083 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-1376360940842/jetty1/index' doesn't exist. Creating new index...
[junit4] 2> 1576768 T3083 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-1376360940842/jetty1/index
[junit4] 2> 1576772 T3083 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@165922c0 lockFactory=org.apache.lucene.store.NativeFSLockFactory@3d0a606d),segFN=segments_1,generation=1}
[junit4] 2> 1576773 T3083 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1576780 T3083 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 1576780 T3083 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 1576781 T3083 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1576782 T3083 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 1576783 T3083 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 1576783 T3083 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 1576783 T3083 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 1576784 T3083 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 1576785 T3083 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 1576801 T3083 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 1576809 T3083 oass.SolrIndexSearcher.<init> Opening Searcher@82690dc main
[junit4] 2> 1576810 T3083 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 1576811 T3083 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 1576817 T3084 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@82690dc main{StandardDirectoryReader(segments_1:1)}
[junit4] 2> 1576820 T3083 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 1576820 T3083 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:55724/w_/nh collection:collection1 shard:shard1
[junit4] 2> 1576820 T3083 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=15000&socketTimeout=30000&retry=false
[junit4] 2> 1576838 T3083 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1576856 T3083 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 1576859 T3083 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 1576859 T3083 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 1576860 T3083 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:55724/w_/nh/collection1/
[junit4] 2> 1576860 T3083 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 1576860 T3083 oasc.SyncStrategy.syncToMe http://127.0.0.1:55724/w_/nh/collection1/ has no replicas
[junit4] 2> 1576861 T3083 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:55724/w_/nh/collection1/ shard1
[junit4] 2> 1576861 T3083 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1578291 T3063 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1578309 T3062 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> 1578309 T3082 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> 1578309 T3069 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> 1578346 T3083 oasc.ZkController.register We are http://127.0.0.1:55724/w_/nh/collection1/ and leader is http://127.0.0.1:55724/w_/nh/collection1/
[junit4] 2> 1578346 T3083 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:55724/w_/nh
[junit4] 2> 1578346 T3083 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 1578346 T3083 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 1578347 T3083 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1578349 T3083 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1578350 T3040 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0
[junit4] 2> 1578350 T3040 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 1578351 T3040 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 1578632 T3040 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 1578636 T3040 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:27721
[junit4] 2> 1578637 T3040 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 1578637 T3040 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1578638 T3040 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty2-1376360951095
[junit4] 2> 1578639 T3040 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty2-1376360951095/'
[junit4] 2> 1578679 T3040 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty2-1376360951095/solr.xml
[junit4] 2> 1578773 T3040 oasc.CoreContainer.<init> New CoreContainer 1058628789
[junit4] 2> 1578774 T3040 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty2-1376360951095/]
[junit4] 2> 1578776 T3040 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 1578777 T3040 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 1578777 T3040 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 1578778 T3040 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 1578778 T3040 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 1578779 T3040 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 1578780 T3040 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 1578780 T3040 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 1578781 T3040 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 1578781 T3040 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4] 2> 1578799 T3040 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:17227/solr
[junit4] 2> 1578799 T3040 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 1578800 T3040 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1578854 T3096 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@19409078 name:ZooKeeperConnection Watcher:127.0.0.1:17227 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1578854 T3040 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1578885 T3040 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4] 2> 1578895 T3040 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1578897 T3098 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@727b5fa name:ZooKeeperConnection Watcher:127.0.0.1:17227/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1578898 T3040 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1578983 T3040 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1579814 T3063 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1579815 T3063 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:55724_w_%2Fnh",
[junit4] 2> "base_url":"http://127.0.0.1:55724/w_/nh"}
[junit4] 2> 1579820 T3062 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> 1579820 T3082 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> 1579820 T3069 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> 1579821 T3098 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> 1579987 T3040 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:27721_w_%2Fnh
[junit4] 2> 1579989 T3040 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:27721_w_%2Fnh
[junit4] 2> 1579991 T3062 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> 1579991 T3082 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> 1579992 T3098 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 1579992 T3069 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 1579992 T3098 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> 1579993 T3069 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> 1579993 T3062 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 1579994 T3082 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 1580002 T3099 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 1580002 T3099 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1580004 T3099 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 1581324 T3063 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1581326 T3063 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:27721_w_%2Fnh",
[junit4] 2> "base_url":"http://127.0.0.1:27721/w_/nh"}
[junit4] 2> 1581326 T3063 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4] 2> 1581326 T3063 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 1581331 T3062 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> 1581331 T3082 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> 1581331 T3069 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> 1581331 T3098 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> 1582006 T3099 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 1582006 T3099 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty2-1376360951095/collection1
[junit4] 2> 1582006 T3099 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 1582007 T3099 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 1582007 T3099 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 1582008 T3099 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty2-1376360951095/collection1/'
[junit4] 2> 1582010 T3099 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty2-1376360951095/collection1/lib/classes/' to classloader
[junit4] 2> 1582010 T3099 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty2-1376360951095/collection1/lib/README' to classloader
[junit4] 2> 1582073 T3099 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 1582139 T3099 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 1582240 T3099 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 1582252 T3099 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 1582923 T3099 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 1582937 T3099 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 1582941 T3099 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 1582955 T3099 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1582960 T3099 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1582965 T3099 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 1582966 T3099 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 1582966 T3099 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 1582966 T3099 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 1582967 T3099 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 1582968 T3099 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 1582968 T3099 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 1582969 T3099 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty2-1376360951095/collection1/, dataDir=./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-1376360940842/jetty2/
[junit4] 2> 1582969 T3099 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@c40fc1c
[junit4] 2> 1582971 T3099 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-1376360940842/jetty2
[junit4] 2> 1582971 T3099 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-1376360940842/jetty2/index/
[junit4] 2> 1582972 T3099 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-1376360940842/jetty2/index' doesn't exist. Creating new index...
[junit4] 2> 1582972 T3099 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-1376360940842/jetty2/index
[junit4] 2> 1582976 T3099 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1fbc59f lockFactory=org.apache.lucene.store.NativeFSLockFactory@3d5a04a0),segFN=segments_1,generation=1}
[junit4] 2> 1582976 T3099 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1582983 T3099 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 1582984 T3099 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 1582985 T3099 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1582986 T3099 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 1582986 T3099 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 1582987 T3099 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 1582987 T3099 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 1582988 T3099 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 1582988 T3099 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 1583005 T3099 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 1583013 T3099 oass.SolrIndexSearcher.<init> Opening Searcher@84b1ff8 main
[junit4] 2> 1583014 T3099 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 1583014 T3099 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 1583020 T3100 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@84b1ff8 main{StandardDirectoryReader(segments_1:1)}
[junit4] 2> 1583023 T3099 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 1583023 T3099 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:27721/w_/nh collection:collection1 shard:shard2
[junit4] 2> 1583023 T3099 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=15000&socketTimeout=30000&retry=false
[junit4] 2> 1583040 T3099 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4] 2> 1583060 T3099 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
[junit4] 2> 1583070 T3099 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 1583070 T3099 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 1583071 T3099 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:27721/w_/nh/collection1/
[junit4] 2> 1583071 T3099 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 1583071 T3099 oasc.SyncStrategy.syncToMe http://127.0.0.1:27721/w_/nh/collection1/ has no replicas
[junit4] 2> 1583072 T3099 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:27721/w_/nh/collection1/ shard2
[junit4] 2> 1583072 T3099 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4] 2> 1584337 T3063 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1584394 T3062 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> 1584394 T3082 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> 1584394 T3069 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> 1584394 T3098 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> 1584412 T3099 oasc.ZkController.register We are http://127.0.0.1:27721/w_/nh/collection1/ and leader is http://127.0.0.1:27721/w_/nh/collection1/
[junit4] 2> 1584412 T3099 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:27721/w_/nh
[junit4] 2> 1584412 T3099 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 1584412 T3099 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 1584413 T3099 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1584415 T3099 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1584416 T3040 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0
[junit4] 2> 1584416 T3040 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 1584417 T3040 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 1584688 T3040 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 1584692 T3040 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:22143
[junit4] 2> 1584692 T3040 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 1584693 T3040 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1584693 T3040 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty3-1376360957161
[junit4] 2> 1584694 T3040 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty3-1376360957161/'
[junit4] 2> 1584734 T3040 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty3-1376360957161/solr.xml
[junit4] 2> 1584827 T3040 oasc.CoreContainer.<init> New CoreContainer 46851821
[junit4] 2> 1584828 T3040 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty3-1376360957161/]
[junit4] 2> 1584830 T3040 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 1584831 T3040 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 1584831 T3040 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 1584832 T3040 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 1584832 T3040 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 1584833 T3040 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 1584833 T3040 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 1584834 T3040 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 1584834 T3040 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 1584835 T3040 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4] 2> 1584852 T3040 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:17227/solr
[junit4] 2> 1584853 T3040 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 1584854 T3040 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1584857 T3113 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@26ac29f2 name:ZooKeeperConnection Watcher:127.0.0.1:17227 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1584857 T3040 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1584874 T3040 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4] 2> 1584887 T3040 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1584888 T3115 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@539e02ab name:ZooKeeperConnection Watcher:127.0.0.1:17227/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1584889 T3040 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1584901 T3040 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1585904 T3040 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:22143_w_%2Fnh
[junit4] 2> 1585916 T3040 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:22143_w_%2Fnh
[junit4] 2> 1585917 T3063 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1585919 T3062 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> 1585919 T3082 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> 1585919 T3098 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 1585919 T3115 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 1585919 T3069 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 1585920 T3063 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:27721_w_%2Fnh",
[junit4] 2> "base_url":"http://127.0.0.1:27721/w_/nh"}
[junit4] 2> 1585920 T3098 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> 1585921 T3082 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 1585920 T3069 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> 1585940 T3116 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 1585940 T3116 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1585941 T3116 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 1585941 T3069 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> 1585942 T3082 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> 1585941 T3115 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> 1585941 T3098 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> 1585945 T3062 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 1585945 T3062 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> 1587446 T3063 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1587448 T3063 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:22143_w_%2Fnh",
[junit4] 2> "base_url":"http://127.0.0.1:22143/w_/nh"}
[junit4] 2> 1587448 T3063 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4] 2> 1587448 T3063 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 1587453 T3062 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> 1587453 T3082 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> 1587453 T3069 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> 1587453 T3115 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> 1587453 T3098 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> 1587944 T3116 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 1587944 T3116 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty3-1376360957161/collection1
[junit4] 2> 1587944 T3116 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 1587945 T3116 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 1587945 T3116 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 1587946 T3116 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty3-1376360957161/collection1/'
[junit4] 2> 1587948 T3116 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty3-1376360957161/collection1/lib/README' to classloader
[junit4] 2> 1587948 T3116 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty3-1376360957161/collection1/lib/classes/' to classloader
[junit4] 2> 1588010 T3116 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 1588076 T3116 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 1588178 T3116 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 1588190 T3116 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 1588872 T3116 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 1588885 T3116 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 1588890 T3116 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 1588904 T3116 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1588909 T3116 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1588913 T3116 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 1588914 T3116 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 1588915 T3116 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 1588915 T3116 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 1588916 T3116 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 1588916 T3116 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 1588917 T3116 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 1588917 T3116 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty3-1376360957161/collection1/, dataDir=./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-1376360940842/jetty3/
[junit4] 2> 1588918 T3116 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@c40fc1c
[junit4] 2> 1588919 T3116 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-1376360940842/jetty3
[junit4] 2> 1588919 T3116 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-1376360940842/jetty3/index/
[junit4] 2> 1588919 T3116 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-1376360940842/jetty3/index' doesn't exist. Creating new index...
[junit4] 2> 1588920 T3116 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-1376360940842/jetty3/index
[junit4] 2> 1588924 T3116 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@59eae620 lockFactory=org.apache.lucene.store.NativeFSLockFactory@4f8bc4f9),segFN=segments_1,generation=1}
[junit4] 2> 1588924 T3116 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1588931 T3116 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 1588931 T3116 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 1588932 T3116 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1588933 T3116 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 1588934 T3116 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 1588934 T3116 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 1588935 T3116 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 1588936 T3116 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 1588936 T3116 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 1588953 T3116 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 1588960 T3116 oass.SolrIndexSearcher.<init> Opening Searcher@287544fc main
[junit4] 2> 1588962 T3116 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 1588962 T3116 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 1588968 T3117 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@287544fc main{StandardDirectoryReader(segments_1:1)}
[junit4] 2> 1588971 T3116 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 1588971 T3116 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:22143/w_/nh collection:collection1 shard:shard1
[junit4] 2> 1588972 T3116 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=15000&socketTimeout=30000&retry=false
[junit4] 2> 1588994 T3116 oasc.ZkController.register We are http://127.0.0.1:22143/w_/nh/collection1/ and leader is http://127.0.0.1:55724/w_/nh/collection1/
[junit4] 2> 1588994 T3116 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:22143/w_/nh
[junit4] 2> 1588994 T3116 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4] 2> 1588995 T3116 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4] 2> ASYNC NEW_CORE C654 name=collection1 org.apache.solr.core.SolrCore@19b33160 url=http://127.0.0.1:22143/w_/nh/collection1 node=127.0.0.1:22143_w_%2Fnh C654_STATE=coll:collection1 core:collection1 props:{state=down, core=collection1, node_name=127.0.0.1:22143_w_%2Fnh, base_url=http://127.0.0.1:22143/w_/nh}
[junit4] 2> 1588995 T3118 C654 P22143 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4] 2> 1588995 T3116 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1588996 T3118 C654 P22143 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4] 2> 1588997 T3118 C654 P22143 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4] 2> 1588997 T3118 C654 P22143 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1588997 T3040 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0
[junit4] 2> 1588998 T3040 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 1588998 T3040 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 1588998 T3118 C654 P22143 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 1589016 T3072 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: core_node3, state: recovering, checkLive: true, onlyIfLeader: true
[junit4] 2> 1589279 T3040 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 1589283 T3040 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:22329
[junit4] 2> 1589284 T3040 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 1589285 T3040 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1589285 T3040 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty4-1376360961746
[junit4] 2> 1589286 T3040 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty4-1376360961746/'
[junit4] 2> 1589326 T3040 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty4-1376360961746/solr.xml
[junit4] 2> 1589421 T3040 oasc.CoreContainer.<init> New CoreContainer 972606160
[junit4] 2> 1589422 T3040 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.FullSolrCloudDistribCmdsTest-jetty4-1376360961746/]
[junit4] 2> 1589424 T3040 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 1589425 T3040 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 1589425 T3040 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 1589426 T3040 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 1589426 T3040 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 1589427 T3040 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 1589427 T3040 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 1589428 T3040 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 1589428 T3040 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 1589429 T3040 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4] 2> 1589447 T3040 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:17227/solr
[junit4] 2> 1589448 T3040 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 1589449 T3040 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1589476 T3130 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@72a57266 name:ZooKeeperConnection Watcher:127.0.0.1:17227 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1589477 T3040 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1589479 T3040 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4] 2> 1589492 T3040 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1589494 T3132 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@300db8de name:ZooKeeperConnection Watcher:127.0.0.1:17227/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1589494 T3040 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1589513 T3040 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1590460 T3063 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1590461 T3063 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":"shard1",
[junit4] 2> "roles":null,
[junit4] 2> "state":"recovering",
[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:22143_w_%2Fnh",
[junit4] 2> "base_url":"http://127.0.0.1:22143/w_/nh"}
[junit4] 2> 1590480 T3062 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> 1590480 T3132 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> 1590480 T3082 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> 1590480 T3115 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> 1590480 T3069 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> 1590480 T3098 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> 1590516 T3040 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:22329_w_%2Fnh
[junit4] 2> 1590518 T3040 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:22329_w_%2Fnh
[junit4] 2> 1590521 T3062 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> 1590521 T3082 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> 1590522 T3098 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4] 2> 1590521 T3132 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> 1590521 T3115 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> 1590522 T3098 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 5)
[junit4] 2> 1590523 T3062 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4] 2> 1590521 T3069 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4] 2> 1590524 T3069 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 5)
[junit4] 2> 1590524 T3082 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4] 2> 1590524 T3132 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4] 2> 1590525 T3115 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4] 2> 1590532 T3133 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 1590532 T3133 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1590534 T3133 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 1591019 T3072 oas
[...truncated too long message...]
PostingsFormat(name=Memory doPackFST= true), 59grand0_s=Pulsing41(freqCutoff=16 minBlockSize=28 maxBlockSize=96), 80grand38_s=PostingsFormat(name=MockSep), 63grand24_s=PostingsFormat(name=MockSep), 52grand18_s=Pulsing41(freqCutoff=16 minBlockSize=28 maxBlockSize=96), 64grand7_s=PostingsFormat(name=MockSep), 9grand2_s=MockFixedIntBlock(blockSize=1189), 20grand5_s=MockFixedIntBlock(blockSize=1189), 23child6_s=MockFixedIntBlock(blockSize=1189), 29child18_s=PostingsFormat(name=Memory doPackFST= true), 76grand74_s=Pulsing41(freqCutoff=16 minBlockSize=28 maxBlockSize=96), 72grand65_s=PostingsFormat(name=Memory doPackFST= true), 38child33_s=MockFixedIntBlock(blockSize=1189), 40grand18_s=MockFixedIntBlock(blockSize=1189), 77grand21_s=MockFixedIntBlock(blockSize=1189), 71grand19_s=Pulsing41(freqCutoff=16 minBlockSize=28 maxBlockSize=96), 65grand36_s=Pulsing41(freqCutoff=16 minBlockSize=28 maxBlockSize=96), 34child16_s=PostingsFormat(name=Memory doPackFST= true), 73grand40_s=PostingsFormat(name=Memory doPackFST= true), 64grand48_s=PostingsFormat(name=Memory doPackFST= true), 26child13_s=PostingsFormat(name=Memory doPackFST= true), 35grand34_s=MockFixedIntBlock(blockSize=1189), 65grand42_s=MockFixedIntBlock(blockSize=1189), 64grand53_s=Pulsing41(freqCutoff=16 minBlockSize=28 maxBlockSize=96), 39grand10_s=PostingsFormat(name=MockSep), 78grand67_s=PostingsFormat(name=Memory doPackFST= true), 18grand16_s=PostingsFormat(name=Memory doPackFST= true), 69grand44_s=PostingsFormat(name=MockSep), 34grand20_s=PostingsFormat(name=MockSep), 5grand0_s=PostingsFormat(name=MockSep), 71grand14_s=PostingsFormat(name=MockSep), 7grand2_s=PostingsFormat(name=MockSep), 79grand75_s=PostingsFormat(name=Memory doPackFST= true), 75grand63_s=MockFixedIntBlock(blockSize=1189), 65grand7_s=Pulsing41(freqCutoff=16 minBlockSize=28 maxBlockSize=96), 37grand23_s=PostingsFormat(name=MockSep), 57grand54_s=PostingsFormat(name=MockSep), 77grand29_s=MockFixedIntBlock(blockSize=1189), 31grand3_s=PostingsFormat(name=MockSep), 20child5_s=MockFixedIntBlock(blockSize=1189), 59grand36_s=MockFixedIntBlock(blockSize=1189), 35child9_s=MockFixedIntBlock(blockSize=1189), 34grand15_s=MockFixedIntBlock(blockSize=1189), 39child4_s=Pulsing41(freqCutoff=16 minBlockSize=28 maxBlockSize=96), 28child7_s=PostingsFormat(name=MockSep), 33child32_s=MockFixedIntBlock(blockSize=1189), 38child0_s=PostingsFormat(name=MockSep), 62grand1_s=PostingsFormat(name=MockSep), 70grand6_s=MockFixedIntBlock(blockSize=1189), 45grand21_s=PostingsFormat(name=Memory doPackFST= true), 58grand54_s=Pulsing41(freqCutoff=16 minBlockSize=28 maxBlockSize=96), 16grand11_s=MockFixedIntBlock(blockSize=1189), 37child27_s=PostingsFormat(name=MockSep), 29child24_s=MockFixedIntBlock(blockSize=1189), 80grand30_s=PostingsFormat(name=MockSep), 36grand14_s=Pulsing41(freqCutoff=16 minBlockSize=28 maxBlockSize=96), 41child7_s=PostingsFormat(name=Memory doPackFST= true), 41grand22_s=MockFixedIntBlock(blockSize=1189), 56grand22_s=MockFixedIntBlock(blockSize=1189), 18child14_s=Pulsing41(freqCutoff=16 minBlockSize=28 maxBlockSize=96), 49grand30_s=PostingsFormat(name=Memory doPackFST= true), 52grand7_s=Pulsing41(freqCutoff=16 minBlockSize=28 maxBlockSize=96), 62grand55_s=Pulsing41(freqCutoff=16 minBlockSize=28 maxBlockSize=96), 38grand13_s=PostingsFormat(name=MockSep), 65grand20_s=MockFixedIntBlock(blockSize=1189), 38child23_s=PostingsFormat(name=Memory doPackFST= true), 81grand24_s=PostingsFormat(name=MockSep), 14child5_s=PostingsFormat(name=Memory doPackFST= true), 28grand20_s=PostingsFormat(name=Memory doPackFST= true), 39grand18_s=PostingsFormat(name=MockSep), 81grand58_s=Pulsing41(freqCutoff=16 minBlockSize=28 maxBlockSize=96), 26child20_s=PostingsFormat(name=Memory doPackFST= true), 59grand41_s=PostingsFormat(name=MockSep), 40child24_s=Pulsing41(freqCutoff=16 minBlockSize=28 maxBlockSize=96), 31child23_s=MockFixedIntBlock(blockSize=1189), 72grand55_s=PostingsFormat(name=MockSep), 22grand14_s=MockFixedIntBlock(blockSize=1189), 74grand14_s=Pulsing41(freqCutoff=16 minBlockSize=28 maxBlockSize=96), 54grand1_s=Pulsing41(freqCutoff=16 minBlockSize=28 maxBlockSize=96), 20grand12_s=MockFixedIntBlock(blockSize=1189), 15child5_s=PostingsFormat(name=MockSep), 77grand1_s=PostingsFormat(name=MockSep), 33grand14_s=MockFixedIntBlock(blockSize=1189), 33child0_s=Pulsing41(freqCutoff=16 minBlockSize=28 maxBlockSize=96), 37child30_s=PostingsFormat(name=MockSep), 41child34_s=Pulsing41(freqCutoff=16 minBlockSize=28 maxBlockSize=96), 40grand22_s=Pulsing41(freqCutoff=16 minBlockSize=28 maxBlockSize=96), 31grand29_s=PostingsFormat(name=MockSep), 45grand5_s=Pulsing41(freqCutoff=16 minBlockSize=28 maxBlockSize=96), 24child19_s=PostingsFormat(name=Memory doPackFST= true), 58grand7_s=Pulsing41(freqCutoff=16 minBlockSize=28 maxBlockSize=96), 55grand36_s=MockFixedIntBlock(blockSize=1189), 68grand35_s=Pulsing41(freqCutoff=16 minBlockSize=28 maxBlockSize=96), 9child0_s=PostingsFormat(name=MockSep), 80grand23_s=PostingsFormat(name=MockSep), 52grand51_s=MockFixedIntBlock(blockSize=1189), 61grand44_s=PostingsFormat(name=MockSep), 77grand14_s=MockFixedIntBlock(blockSize=1189), 68grand62_s=PostingsFormat(name=Memory doPackFST= true), 58grand24_s=MockFixedIntBlock(blockSize=1189), 58grand35_s=MockFixedIntBlock(blockSize=1189), 19child17_s=PostingsFormat(name=Memory doPackFST= true), 70grand64_s=PostingsFormat(name=MockSep), 33child8_s=Pulsing41(freqCutoff=16 minBlockSize=28 maxBlockSize=96), 73grand47_s=MockFixedIntBlock(blockSize=1189), 36child27_s=Pulsing41(freqCutoff=16 minBlockSize=28 maxBlockSize=96), 49grand39_s=PostingsFormat(name=MockSep), 28grand14_s=PostingsFormat(name=MockSep), 57grand33_s=Pulsing41(freqCutoff=16 minBlockSize=28 maxBlockSize=96), 12child7_s=PostingsFormat(name=Memory doPackFST= true), 51grand50_s=MockFixedIntBlock(blockSize=1189), 32child3_s=Pulsing41(freqCutoff=16 minBlockSize=28 maxBlockSize=96), 35child34_s=MockFixedIntBlock(blockSize=1189), 31grand19_s=Pulsing41(freqCutoff=16 minBlockSize=28 maxBlockSize=96), 40grand16_s=PostingsFormat(name=MockSep), 51grand0_s=Pulsing41(freqCutoff=16 minBlockSize=28 maxBlockSize=96), 18child7_s=PostingsFormat(name=Memory doPackFST= true), 76grand14_s=PostingsFormat(name=Memory doPackFST= true), 28child20_s=PostingsFormat(name=Memory doPackFST= true), 14child12_s=Pulsing41(freqCutoff=16 minBlockSize=28 maxBlockSize=96), 65grand50_s=Pulsing41(freqCutoff=16 minBlockSize=28 maxBlockSize=96)}, docValues:{timestamp=DocValuesFormat(name=Lucene42)}, sim=RandomSimilarityProvider(queryNorm=false,coord=yes): {}, locale=iw_IL, timezone=Asia/Krasnoyarsk
[junit4] 2> NOTE: FreeBSD 9.1-RELEASE-p3 amd64/Oracle Corporation 1.7.0_25 (64-bit)/cpus=16,threads=2,free=275897504,total=536870912
[junit4] 2> NOTE: All tests run in this JVM: [TestMaxScoreQueryParser, ZkNodePropsTest, TestPHPSerializedResponseWriter, SpellPossibilityIteratorTest, TestBadConfig, WordBreakSolrSpellCheckerTest, TestDynamicFieldCollectionResource, OverseerCollectionProcessorTest, TestLRUCache, TestFunctionQuery, TestGroupingSearch, BlockDirectoryTest, SuggesterFSTTest, SoftAutoCommitTest, EchoParamsTest, CachingDirectoryFactoryTest, SolrIndexSplitterTest, CoreMergeIndexesAdminHandlerTest, HdfsDirectoryTest, TestCharFilters, OverseerTest, SpatialFilterTest, BlockCacheTest, DateFieldTest, TestFaceting, DocValuesTest, IndexSchemaTest, StressHdfsTest, TestSort, ScriptEngineTest, RecoveryZkTest, TestSearchPerf, TestLMJelinekMercerSimilarityFactory, HdfsChaosMonkeySafeLeaderTest, PrimitiveFieldTypeTest, UpdateRequestProcessorFactoryTest, ShardRoutingTest, TestSolrDeletionPolicy1, TestReversedWildcardFilterFactory, SOLR749Test, TestJmxMonitoredMap, TestSolrIndexConfig, SystemInfoHandlerTest, ZkControllerTest, FileBasedSpellCheckerTest, LukeRequestHandlerTest, TestUniqueKeyFieldResource, TestTrie, SimpleFacetsTest, TestRecoveryHdfs, QueryElevationComponentTest, QueryParsingTest, MoreLikeThisHandlerTest, ZkCLITest, BinaryUpdateRequestHandlerTest, AnalysisAfterCoreReloadTest, TestSurroundQueryParser, SchemaVersionSpecificBehaviorTest, TestRandomDVFaceting, CoreAdminCreateDiscoverTest, TestSolrXmlPersistence, TestElisionMultitermQuery, LeaderElectionTest, AddBlockUpdateTest, BasicFunctionalityTest, TermsComponentTest, CopyFieldTest, TestSolrXMLSerializer, TestBM25SimilarityFactory, AutoCommitTest, TestExtendedDismaxParser, SolrCoreTest, ShardSplitTest, TestRemoteStreaming, DistributedQueryElevationComponentTest, HdfsRecoveryZkTest, CacheHeaderTest, ChaosMonkeySafeLeaderTest, BasicDistributedZk2Test, UnloadDistributedZkTest, LeaderElectionIntegrationTest, BasicZkTest, FullSolrCloudDistribCmdsTest]
[junit4] Completed on J0 in 1667.08s, 1 test, 1 error <<< FAILURES!
[...truncated 16 lines...]
BUILD FAILED
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/build.xml:389: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/build.xml:369: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/build.xml:39: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build.xml:181: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/common-build.xml:450: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/lucene/common-build.xml:1230: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/lucene/common-build.xml:873: There were test failures: 320 suites, 1361 tests, 1 error, 35 ignored (6 assumptions)
Total time: 75 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
[JENKINS] Lucene-Solr-Tests-trunk-Java7 - Build # 4231 - Still
Failing
Posted by Apache Jenkins Server <je...@builds.apache.org>.
Build: https://builds.apache.org/job/Lucene-Solr-Tests-trunk-Java7/4231/
All tests passed
Build Log:
[...truncated 34759 lines...]
-documentation-lint:
[jtidy] Checking for broken html (such as invalid tags)...
[delete] Deleting directory /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/lucene/build/jtidy_tmp
[echo] Checking for broken links...
[exec]
[exec] Crawl/parse...
[exec]
[exec] Verify...
[echo] Checking for malformed docs...
[exec]
[exec] /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/docs/solr-core/overview-summary.html
[exec] missing: org.apache.solr.search.join
[exec]
[exec] Missing javadocs were found!
BUILD FAILED
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/build.xml:389: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/build.xml:60: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build.xml:563: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build.xml:579: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/lucene/common-build.xml:2149: exec returned: 1
Total time: 80 minutes 13 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure