You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2015/02/08 18:00:24 UTC

[JENKINS] Lucene-Solr-trunk-Linux (32bit/jdk1.8.0_40-ea-b22) - Build # 11761 - Failure!

Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Linux/11761/
Java: 32bit/jdk1.8.0_40-ea-b22 -client -XX:+UseConcMarkSweepGC

1 tests failed.
FAILED:  org.apache.solr.cloud.HttpPartitionTest.test

Error Message:
Captured an uncaught exception in thread: Thread[id=7566, name=SocketProxy-Response-33533:40315, state=RUNNABLE, group=TGRP-HttpPartitionTest]

Stack Trace:
com.carrotsearch.randomizedtesting.UncaughtExceptionError: Captured an uncaught exception in thread: Thread[id=7566, name=SocketProxy-Response-33533:40315, state=RUNNABLE, group=TGRP-HttpPartitionTest]
	at __randomizedtesting.SeedInfo.seed([9B132FABC979468C:1347107167852B74]:0)
Caused by: java.lang.RuntimeException: java.net.SocketException: Socket is closed
	at __randomizedtesting.SeedInfo.seed([9B132FABC979468C]:0)
	at org.apache.solr.cloud.SocketProxy$Bridge$Pump.run(SocketProxy.java:344)
Caused by: java.net.SocketException: Socket is closed
	at java.net.Socket.setSoTimeout(Socket.java:1137)
	at org.apache.solr.cloud.SocketProxy$Bridge$Pump.run(SocketProxy.java:341)




Build Log:
[...truncated 9567 lines...]
   [junit4] Suite: org.apache.solr.cloud.HttpPartitionTest
   [junit4]   2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.HttpPartitionTest 9B132FABC979468C-001/init-core-data-001
   [junit4]   2> 1048826 T7152 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
   [junit4]   2> 1048828 T7152 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   1> client port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 1048829 T7153 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 1048929 T7152 oasc.ZkTestServer.run start zk server on port:59165
   [junit4]   2> 1048930 T7152 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider
   [junit4]   2> 1048931 T7152 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1048934 T7160 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1b7cca9 name:ZooKeeperConnection Watcher:127.0.0.1:59165 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1048934 T7152 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1048936 T7152 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider
   [junit4]   2> 1048936 T7152 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 1048942 T7152 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider
   [junit4]   2> 1048944 T7152 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1048946 T7163 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@dc8ce3 name:ZooKeeperConnection Watcher:127.0.0.1:59165/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1048946 T7152 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1048947 T7152 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider
   [junit4]   2> 1048948 T7152 oascc.SolrZkClient.makePath makePath: /collections/collection1
   [junit4]   2> 1048954 T7152 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
   [junit4]   2> 1048960 T7152 oascc.SolrZkClient.makePath makePath: /collections/control_collection
   [junit4]   2> 1048964 T7152 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
   [junit4]   2> 1048970 T7152 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
   [junit4]   2> 1048971 T7152 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
   [junit4]   2> 1048983 T7152 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
   [junit4]   2> 1048984 T7152 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
   [junit4]   2> 1048990 T7152 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 1048991 T7152 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 1048997 T7152 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
   [junit4]   2> 1048998 T7152 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
   [junit4]   2> 1049003 T7152 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
   [junit4]   2> 1049004 T7152 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
   [junit4]   2> 1049009 T7152 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
   [junit4]   2> 1049010 T7152 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
   [junit4]   2> 1049016 T7152 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml
   [junit4]   2> 1049016 T7152 oascc.SolrZkClient.makePath makePath: /configs/conf1/enumsConfig.xml
   [junit4]   2> 1049022 T7152 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
   [junit4]   2> 1049023 T7152 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
   [junit4]   2> 1049028 T7152 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 1049029 T7152 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 1049034 T7152 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
   [junit4]   2> 1049036 T7152 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
   [junit4]   2> 1049040 T7152 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
   [junit4]   2> 1049041 T7152 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
   [junit4]   2> 1049044 T7154 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x14b6a0e9ad30001, likely client has closed socket
   [junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
   [junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
   [junit4]   2> 	at java.lang.Thread.run(Thread.java:745)
   [junit4]   2> 
   [junit4]   2> 1049374 T7152 oas.SolrTestCaseJ4.writeCoreProperties Writing core.properties file to /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.HttpPartitionTest 9B132FABC979468C-001/control-001/cores/collection1
   [junit4]   2> 1049376 T7152 oejs.Server.doStart jetty-9.2.6.v20141205
   [junit4]   2> 1049378 T7152 oejsh.ContextHandler.doStart Started o.e.j.s.ServletContextHandler@1c5c744{/,null,AVAILABLE}
   [junit4]   2> 1049380 T7152 oejs.AbstractConnector.doStart Started ServerConnector@41aa81{HTTP/1.1}{127.0.0.1:49169}
   [junit4]   2> 1049381 T7152 oejs.Server.doStart Started @1050413ms
   [junit4]   2> 1049382 T7152 oass.SolrDispatchFilter.init SolrDispatchFilter.init()sun.misc.Launcher$AppClassLoader@e2f2a
   [junit4]   2> 1049382 T7152 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 1049382 T7152 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.HttpPartitionTest 9B132FABC979468C-001/control-001
   [junit4]   2> 1049383 T7152 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.HttpPartitionTest 9B132FABC979468C-001/control-001/'
   [junit4]   2> 1049400 T7152 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.HttpPartitionTest 9B132FABC979468C-001/control-001/solr.xml
   [junit4]   2> 1049408 T7152 oasc.CorePropertiesLocator.<init> Config-defined core root directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.HttpPartitionTest 9B132FABC979468C-001/control-001/cores
   [junit4]   2> 1049408 T7152 oasc.CoreContainer.<init> New CoreContainer 10899420
   [junit4]   2> 1049408 T7152 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.HttpPartitionTest 9B132FABC979468C-001/control-001/]
   [junit4]   2> 1049409 T7152 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 1049409 T7152 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 1049410 T7152 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 1049410 T7152 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 1049410 T7152 oashc.HttpShardHandlerFactory.getParameter Setting maxConnections to: 10000
   [junit4]   2> 1049411 T7152 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 1049411 T7152 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 1049411 T7152 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 1049412 T7152 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 1049412 T7152 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 1049412 T7152 oashc.HttpShardHandlerFactory.getParameter Setting useRetries to: false
   [junit4]   2> 1049413 T7152 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
   [junit4]   2> 1049413 T7152 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 1049414 T7152 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 1049414 T7152 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 1049414 T7152 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:59165/solr
   [junit4]   2> 1049415 T7152 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 1049415 T7152 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider
   [junit4]   2> 1049416 T7152 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1049418 T7177 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@18baf0a name:ZooKeeperConnection Watcher:127.0.0.1:59165 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1049418 T7152 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1049419 T7152 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider
   [junit4]   2> 1049423 T7152 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1049425 T7180 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@9e52ef name:ZooKeeperConnection Watcher:127.0.0.1:59165/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1049425 T7152 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1049428 T7152 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 1049435 T7152 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 1049442 T7152 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
   [junit4]   2> 1049449 T7152 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
   [junit4]   2> 1049456 T7152 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
   [junit4]   2> 1049464 T7152 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 1049469 T7152 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:43708_
   [junit4]   2> 1049472 T7152 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:43708_
   [junit4]   2> 1049479 T7152 oascc.SolrZkClient.makePath makePath: /overseer_elect
   [junit4]   2> 1049483 T7152 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 1049490 T7152 oasc.Overseer.close Overseer (id=null) closing
   [junit4]   2> 1049495 T7152 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:43708_
   [junit4]   2> 1049496 T7152 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 1049501 T7152 oasc.Overseer.start Overseer (id=93284828250832899-127.0.0.1:43708_-n_0000000000) starting
   [junit4]   2> 1049507 T7152 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 1049527 T7152 oasc.OverseerAutoReplicaFailoverThread.<init> Starting OverseerAutoReplicaFailoverThread autoReplicaFailoverWorkLoopDelay=10000 autoReplicaFailoverWaitAfterExpiration=30000 autoReplicaFailoverBadNodeExpiration=60000
   [junit4]   2> 1049528 T7182 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 1049531 T7152 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 1049535 T7152 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 1049539 T7152 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1049545 T7181 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 1049546 T7152 oasc.CorePropertiesLocator.discover Looking for core definitions underneath /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.HttpPartitionTest 9B132FABC979468C-001/control-001/cores
   [junit4]   2> 1049548 T7152 oasc.CorePropertiesLocator.discoverUnder Found core collection1 in /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.HttpPartitionTest 9B132FABC979468C-001/control-001/cores/collection1/
   [junit4]   2> 1049548 T7152 oasc.CorePropertiesLocator.discover Found 1 core definitions
   [junit4]   2> 1049550 T7184 oasc.ZkController.publish publishing core=collection1 state=down collection=control_collection
   [junit4]   2> 1049551 T7184 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1049553 T7180 oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected
   [junit4]   2> 1049553 T7184 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 1049560 T7181 oasc.Overseer$ClusterStateUpdater.run processMessage: queueSize: 0, message = {
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "base_url":"http://127.0.0.1:43708",
   [junit4]   2> 	  "node_name":"127.0.0.1:43708_",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"control_collection",
   [junit4]   2> 	  "operation":"state"} current state version: 0
   [junit4]   2> 1049562 T7181 oasco.ReplicaMutator.updateState Update state numShards=1 message={
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "base_url":"http://127.0.0.1:43708",
   [junit4]   2> 	  "node_name":"127.0.0.1:43708_",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"control_collection",
   [junit4]   2> 	  "operation":"state"}
   [junit4]   2> 1049562 T7181 oasco.ClusterStateMutator.createCollection building a new cName: control_collection
   [junit4]   2> 1049562 T7181 oasco.ReplicaMutator.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 1049565 T7180 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> 1050554 T7184 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 1050555 T7184 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
   [junit4]   2> 1050556 T7184 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 1050556 T7184 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
   [junit4]   2> 1050559 T7184 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 1050560 T7184 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.HttpPartitionTest 9B132FABC979468C-001/control-001/cores/collection1/'
   [junit4]   2> 1050585 T7184 oasc.ZkController.watchZKConfDir watch zkdir /configs/conf1
   [junit4]   2> 1050589 T7184 oasc.Config.<init> loaded config solrconfig.xml with version 0 
   [junit4]   2> 1050596 T7184 oasc.SolrConfig.refreshRequestParams current version of requestparams : -1
   [junit4]   2> 1050610 T7184 oasc.SolrConfig.<init> Using Lucene MatchVersion: 6.0.0
   [junit4]   2> 1050626 T7184 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 1050628 T7184 oass.IndexSchema.readSchema Reading Solr Schema from /configs/conf1/schema.xml
   [junit4]   2> 1050642 T7184 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 1050777 T7184 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 1050783 T7184 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 1050784 T7184 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 1050805 T7184 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1050807 T7184 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1050810 T7184 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1050811 T7184 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1050812 T7184 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1050812 T7184 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1050814 T7184 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1050814 T7184 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1050814 T7184 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection control_collection
   [junit4]   2> 1050814 T7184 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 1050815 T7184 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.HttpPartitionTest 9B132FABC979468C-001/control-001/cores/collection1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.HttpPartitionTest 9B132FABC979468C-001/tempDir-001/control/data/
   [junit4]   2> 1050815 T7184 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@166517b
   [junit4]   2> 1050816 T7184 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.HttpPartitionTest 9B132FABC979468C-001/tempDir-001/control/data
   [junit4]   2> 1050816 T7184 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.HttpPartitionTest 9B132FABC979468C-001/tempDir-001/control/data/index/
   [junit4]   2> 1050817 T7184 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.HttpPartitionTest 9B132FABC979468C-001/tempDir-001/control/data/index' doesn't exist. Creating new index...
   [junit4]   2> 1050817 T7184 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.HttpPartitionTest 9B132FABC979468C-001/tempDir-001/control/data/index
   [junit4]   2> 1050818 T7184 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=47, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.5349869505033221]
   [junit4]   2> 1050819 T7184 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@b420b5 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@4bf875),segFN=segments_1,generation=1}
   [junit4]   2> 1050819 T7184 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1050822 T7184 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 1050823 T7184 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 1050823 T7184 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 1050824 T7184 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1050824 T7184 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1050824 T7184 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 1050825 T7184 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1050825 T7184 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1050825 T7184 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 1050826 T7184 oasc.RequestHandlers.initHandlersFromConfig created /update: org.apache.solr.handler.UpdateRequestHandler
   [junit4]   2> 1050827 T7184 oasc.RequestHandlers.initHandlersFromConfig created /update/json: org.apache.solr.handler.UpdateRequestHandler
   [junit4]   2> 1050827 T7184 oasc.RequestHandlers.initHandlersFromConfig created /update/csv: org.apache.solr.handler.UpdateRequestHandler
   [junit4]   2> 1050828 T7184 oasc.RequestHandlers.initHandlersFromConfig created /update/json/docs: org.apache.solr.handler.UpdateRequestHandler
   [junit4]   2> 1050829 T7184 oasc.RequestHandlers.initHandlersFromConfig created /config: org.apache.solr.handler.SolrConfigHandler
   [junit4]   2> 1050829 T7184 oasc.RequestHandlers.initHandlersFromConfig created /schema: org.apache.solr.handler.SchemaHandler
   [junit4]   2> 1050830 T7184 oasc.RequestHandlers.initHandlersFromConfig created /replication: org.apache.solr.handler.ReplicationHandler
   [junit4]   2> 1050830 T7184 oasc.RequestHandlers.initHandlersFromConfig created /get: org.apache.solr.handler.RealTimeGetHandler
   [junit4]   2> 1050831 T7184 oasc.RequestHandlers.initHandlersFromConfig created /admin/luke: org.apache.solr.handler.admin.LukeRequestHandler
   [junit4]   2> 1050832 T7184 oasc.RequestHandlers.initHandlersFromConfig created /admin/system: org.apache.solr.handler.admin.SystemInfoHandler
   [junit4]   2> 1050833 T7184 oasc.RequestHandlers.initHandlersFromConfig created /admin/mbeans: org.apache.solr.handler.admin.SolrInfoMBeanHandler
   [junit4]   2> 1050833 T7184 oasc.RequestHandlers.initHandlersFromConfig created /admin/plugins: org.apache.solr.handler.admin.PluginInfoHandler
   [junit4]   2> 1050834 T7184 oasc.RequestHandlers.initHandlersFromConfig created /admin/threads: org.apache.solr.handler.admin.ThreadDumpHandler
   [junit4]   2> 1050835 T7184 oasc.RequestHandlers.initHandlersFromConfig created /admin/properties: org.apache.solr.handler.admin.PropertiesRequestHandler
   [junit4]   2> 1050835 T7184 oasc.RequestHandlers.initHandlersFromConfig created /admin/logging: org.apache.solr.handler.admin.LoggingHandler
   [junit4]   2> 1050836 T7184 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 1050837 T7184 oasc.RequestHandlers.initHandlersFromConfig created /admin/ping: org.apache.solr.handler.PingRequestHandler
   [junit4]   2> 1050837 T7184 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 1050839 T7184 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 1050840 T7184 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 1050841 T7184 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 1050842 T7184 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 1050843 T7184 oasc.SolrCore.initStatsCache Using default statsCache cache: org.apache.solr.search.stats.LocalStatsCache
   [junit4]   2> 1050844 T7184 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 1050844 T7184 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 1050844 T7184 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=14, maxMergeAtOnceExplicit=26, maxMergedSegmentMB=0.4501953125, floorSegmentMB=2.01953125, forceMergeDeletesPctAllowed=22.40180107546433, segmentsPerTier=42.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
   [junit4]   2> 1050845 T7184 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@b420b5 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@4bf875),segFN=segments_1,generation=1}
   [junit4]   2> 1050845 T7184 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1050846 T7184 oass.SolrIndexSearcher.<init> Opening Searcher@1ad931f[collection1] main
   [junit4]   2> 1050846 T7184 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
   [junit4]   2> 1050847 T7184 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 1050847 T7184 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
   [junit4]   2> 1050848 T7184 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
   [junit4]   2> 1050848 T7184 oasr.RestManager.init Initializing RestManager with initArgs: {}
   [junit4]   2> 1050848 T7184 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 1050849 T7184 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
   [junit4]   2> 1050849 T7184 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 1050849 T7184 oasr.RestManager.init Initializing 0 registered ManagedResources
   [junit4]   2> 1050849 T7184 oash.ReplicationHandler.inform Commits will be reserved for  10000
   [junit4]   2> 1050850 T7184 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 1050850 T7185 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1ad931f[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 1050851 T7188 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:43708 collection:control_collection shard:shard1
   [junit4]   2> 1050851 T7152 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0
   [junit4]   2> 1050851 T7152 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 1050852 T7188 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
   [junit4]   2> 1050853 T7152 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider
   [junit4]   2> 1050854 T7152 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1050855 T7192 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@f1a22a name:ZooKeeperConnection Watcher:127.0.0.1:59165/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1050855 T7152 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1050856 T7152 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider
   [junit4]   2> 1050857 T7152 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1050857 T7188 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 1050859 T7180 oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected
   [junit4]   2> 1050860 T7188 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 1050861 T7188 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> ASYNC  NEW_CORE C5484 name=collection1 org.apache.solr.core.SolrCore@bb361e url=http://127.0.0.1:43708/collection1 node=127.0.0.1:43708_ C5484_STATE=coll:control_collection core:collection1 props:{core=collection1, base_url=http://127.0.0.1:43708, node_name=127.0.0.1:43708_, state=down}
   [junit4]   2> 1050861 T7188 C5484 P43708 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:43708/collection1/
   [junit4]   2> 1050862 T7188 C5484 P43708 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 1050862 T7188 C5484 P43708 oasc.SyncStrategy.syncToMe http://127.0.0.1:43708/collection1/ has no replicas
   [junit4]   2> 1050862 T7188 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:43708/collection1/ shard1
   [junit4]   2> 1050863 T7188 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
   [junit4]   2> 1050863 T7181 oasc.Overseer$ClusterStateUpdater.run processMessage: queueSize: 1, message = {
   [junit4]   2> 	  "operation":"leader",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "collection":"control_collection"} current state version: 1
   [junit4]   2> 1050864 T7152 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:false
   [junit4]   2> 1050865 T7152 oasc.AbstractFullDistribZkTestBase.createJettys Creating collection1 with stateFormat=2
   [junit4]   2> 1050866 T7152 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider
   [junit4]   2> 1050867 T7152 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1050869 T7195 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4d906b name:ZooKeeperConnection Watcher:127.0.0.1:59165/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1050869 T7152 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1050870 T7152 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider
   [junit4]   2> 1050872 T7180 oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected
   [junit4]   2> 1050874 T7181 oasc.Overseer$ClusterStateUpdater.run processMessage: queueSize: 1, message = {
   [junit4]   2> 	  "operation":"leader",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "collection":"control_collection",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:43708",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "state":"active"} current state version: 1
   [junit4]   2> 1050875 T7154 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x14b6a0e9ad30005, likely client has closed socket
   [junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
   [junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
   [junit4]   2> 	at java.lang.Thread.run(Thread.java:745)
   [junit4]   2> 
   [junit4]   2> 1050880 T7181 oasc.Overseer$ClusterStateUpdater.run processMessage: queueSize: 1, message = {
   [junit4]   2> 	  "operation":"create",
   [junit4]   2> 	  "name":"collection1",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "stateFormat":"2"} current state version: 1
   [junit4]   2> 1050880 T7181 oasco.ClusterStateMutator.createCollection building a new cName: collection1
   [junit4]   2> 1050881 T7180 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> 1050882 T7192 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> 1050888 T7196 oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected
   [junit4]   2> 1050889 T7181 oasco.ZkStateWriter.writePendingUpdates going to create_collection /collections/collection1/state.json
   [junit4]   2> 1050891 T7192 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> 1050924 T7188 oasc.ZkController.register We are http://127.0.0.1:43708/collection1/ and leader is http://127.0.0.1:43708/collection1/
   [junit4]   2> 1050924 T7188 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:43708
   [junit4]   2> 1050924 T7188 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 1050924 T7188 oasc.ZkController.publish publishing core=collection1 state=active collection=control_collection
   [junit4]   2> 1050925 T7188 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1050926 T7180 oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected
   [junit4]   2> 1050928 T7181 oasc.Overseer$ClusterStateUpdater.run processMessage: queueSize: 1, message = {
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "core_node_name":"core_node1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "base_url":"http://127.0.0.1:43708",
   [junit4]   2> 	  "node_name":"127.0.0.1:43708_",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "collection":"control_collection",
   [junit4]   2> 	  "operation":"state"} current state version: 3
   [junit4]   2> 1050929 T7181 oasco.ReplicaMutator.updateState Update state numShards=2 message={
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "core_node_name":"core_node1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "base_url":"http://127.0.0.1:43708",
   [junit4]   2> 	  "node_name":"127.0.0.1:43708_",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "collection":"control_collection",
   [junit4]   2> 	  "operation":"state"}
   [junit4]   2> 1051032 T7180 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> 1051033 T7192 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> 1051182 T7152 oas.SolrTestCaseJ4.writeCoreProperties Writing core.properties file to /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.HttpPartitionTest 9B132FABC979468C-001/shard-1-001/cores/collection1
   [junit4]   2> 1051183 T7152 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 1
   [junit4]   2> 1051184 T7152 oejs.Server.doStart jetty-9.2.6.v20141205
   [junit4]   2> 1051186 T7152 oejsh.ContextHandler.doStart Started o.e.j.s.ServletContextHandler@143021d{/,null,AVAILABLE}
   [junit4]   2> 1051186 T7152 oejs.AbstractConnector.doStart Started ServerConnector@83db63{HTTP/1.1}{127.0.0.1:51056}
   [junit4]   2> 1051187 T7152 oejs.Server.doStart Started @1052219ms
   [junit4]   2> 1051187 T7152 oass.SolrDispatchFilter.init SolrDispatchFilter.init()sun.misc.Launcher$AppClassLoader@e2f2a
   [junit4]   2> 1051188 T7152 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 1051188 T7152 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.HttpPartitionTest 9B132FABC979468C-001/shard-1-001
   [junit4]   2> 1051189 T7152 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.HttpPartitionTest 9B132FABC979468C-001/shard-1-001/'
   [junit4]   2> 1051205 T7152 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.HttpPartitionTest 9B132FABC979468C-001/shard-1-001/solr.xml
   [junit4]   2> 1051211 T7152 oasc.CorePropertiesLocator.<init> Config-defined core root directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.HttpPartitionTest 9B132FABC979468C-001/shard-1-001/cores
   [junit4]   2> 1051211 T7152 oasc.CoreContainer.<init> New CoreContainer 298214
   [junit4]   2> 1051211 T7152 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.HttpPartitionTest 9B132FABC979468C-001/shard-1-001/]
   [junit4]   2> 1051212 T7152 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 1051212 T7152 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 1051213 T7152 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 1051213 T7152 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 1051213 T7152 oashc.HttpShardHandlerFactory.getParameter Setting maxConnections to: 10000
   [junit4]   2> 1051214 T7152 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 1051214 T7152 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 1051214 T7152 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 1051214 T7152 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 1051215 T7152 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 1051215 T7152 oashc.HttpShardHandlerFactory.getParameter Setting useRetries to: false
   [junit4]   2> 1051216 T7152 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
   [junit4]   2> 1051216 T7152 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 1051217 T7152 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 1051217 T7152 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 1051218 T7152 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:59165/solr
   [junit4]   2> 1051218 T7152 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 1051218 T7152 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider
   [junit4]   2> 1051219 T7152 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1051220 T7210 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6c2069 name:ZooKeeperConnection Watcher:127.0.0.1:59165 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1051220 T7152 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1051222 T7152 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider
   [junit4]   2> 1051225 T7152 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1051228 T7213 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1b170ef name:ZooKeeperConnection Watcher:127.0.0.1:59165/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1051228 T7152 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1051241 T7152 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1052252 T7152 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:57159_
   [junit4]   2> 1052254 T7152 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:57159_
   [junit4]   2> 1052261 T7152 oasc.Overseer.close Overseer (id=null) closing
   [junit4]   2> 1052265 T7152 oasc.CorePropertiesLocator.discover Looking for core definitions underneath /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.HttpPartitionTest 9B132FABC979468C-001/shard-1-001/cores
   [junit4]   2> 1052266 T7152 oasc.CorePropertiesLocator.discoverUnder Found core collection1 in /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.HttpPartitionTest 9B132FABC979468C-001/shard-1-001/cores/collection1/
   [junit4]   2> 1052267 T7152 oasc.CorePropertiesLocator.discover Found 1 core definitions
   [junit4]   2> 1052272 T7214 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
   [junit4]   2> 1052272 T7214 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1052276 T7180 oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected
   [junit4]   2> 1052278 T7214 oasc.ZkController.preRegister Registering watch for external collection collection1
   [junit4]   2> 1052278 T7181 oasc.Overseer$ClusterStateUpdater.run processMessage: queueSize: 1, message = {
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "base_url":"http://127.0.0.1:57159",
   [junit4]   2> 	  "node_name":"127.0.0.1:57159_",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "operation":"state"} current state version: 4
   [junit4]   2> 1052278 T7214 oascc.ZkStateReader.addZkWatch addZkWatch collection1
   [junit4]   2> 1052280 T7181 oasco.ReplicaMutator.updateState Update state numShards=2 message={
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "base_url":"http://127.0.0.1:57159",
   [junit4]   2> 	  "node_name":"127.0.0.1:57159_",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "operation":"state"}
   [junit4]   2> 1052280 T7214 oascc.ZkStateReader.addZkWatch Updating collection state at /collections/collection1/state.json from ZooKeeper... 
   [junit4]   2> 1052280 T7181 oasco.ReplicaMutator.updateState Collection already exists with numShards=2
   [junit4]   2> 1052281 T7181 oasco.ReplicaMutator.updateState Assigning new node to shard shard=shard2
   [junit4]   2> 1052283 T7214 oascc.ZkStateReader.updateWatchedCollection Updating data for collection1 to ver 0 
   [junit4]   2> 1052283 T7214 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 1052388 T7181 oasco.ZkStateWriter.writePendingUpdates going to update_collection /collections/collection1/state.json version: 0
   [junit4]   2> 1052390 T7213 oascc.ZkStateReader$7.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json, has occurred - updating... 
   [junit4]   2> 1052391 T7213 oascc.ZkStateReader.updateWatchedCollection Updating data for collection1 to ver 1 
   [junit4]   2> 1053284 T7214 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 1053284 T7214 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 1053285 T7214 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 1053285 T7214 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 1053287 T7214 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 1053288 T7214 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.HttpPartitionTest 9B132FABC979468C-001/shard-1-001/cores/collection1/'
   [junit4]   2> 1053320 T7214 oasc.ZkController.watchZKConfDir watch zkdir /configs/conf1
   [junit4]   2> 1053323 T7214 oasc.Config.<init> loaded config solrconfig.xml with version 0 
   [junit4]   2> 1053329 T7214 oasc.SolrConfig.refreshRequestParams current version of requestparams : -1
   [junit4]   2> 1053337 T7214 oasc.SolrConfig.<init> Using Lucene MatchVersion: 6.0.0
   [junit4]   2> 1053350 T7214 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 1053351 T7214 oass.IndexSchema.readSchema Reading Solr Schema from /configs/conf1/schema.xml
   [junit4]   2> 1053358 T7214 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 1053483 T7214 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 1053487 T7214 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 1053489 T7214 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 1053500 T7214 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1053503 T7214 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1053506 T7214 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1053507 T7214 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1053507 T7214 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1053508 T7214 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1053509 T7214 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1053509 T7214 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1053509 T7214 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection collection1
   [junit4]   2> 1053510 T7214 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 1053510 T7214 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.HttpPartitionTest 9B132FABC979468C-001/shard-1-001/cores/collection1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.HttpPartitionTest 9B132FABC979468C-001/tempDir-001/jetty1/
   [junit4]   2> 1053510 T7214 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@166517b
   [junit4]   2> 1053511 T7214 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.HttpPartitionTest 9B132FABC979468C-001/tempDir-001/jetty1
   [junit4]   2> 1053512 T7214 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.HttpPartitionTest 9B132FABC979468C-001/tempDir-001/jetty1/index/
   [junit4]   2> 1053512 T7214 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.HttpPartitionTest 9B132FABC979468C-001/tempDir-001/jetty1/index' doesn't exist. Creating new index...
   [junit4]   2> 1053512 T7214 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.HttpPartitionTest 9B132FABC979468C-001/tempDir-001/jetty1/index
   [junit4]   2> 1053513 T7214 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=47, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.5349869505033221]
   [junit4]   2> 1053513 T7214 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@9f6deb lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@107242d),segFN=segments_1,generation=1}
   [junit4]   2> 1053514 T7214 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1053518 T7214 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 1053518 T7214 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 1053519 T7214 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 1053519 T7214 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1053519 T7214 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1053519 T7214 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 1053520 T7214 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1053520 T7214 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1053520 T7214 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 1053521 T7214 oasc.RequestHandlers.initHandlersFromConfig created /update: org.apache.solr.handler.UpdateRequestHandler
   [junit4]   2> 1053522 T7214 oasc.RequestHandlers.initHandlersFromConfig created /update/json: org.apache.solr.handler.UpdateRequestHandler
   [junit4]   2> 1053523 T7214 oasc.RequestHandlers.initHandlersFromConfig created /update/csv: org.apache.solr.handler.UpdateRequestHandler
   [junit4]   2> 1053523 T7214 oasc.RequestHandlers.initHandlersFromConfig created /update/json/docs: org.apache.solr.handler.UpdateRequestHandler
   [junit4]   2> 1053524 T7214 oasc.RequestHandlers.initHandlersFromConfig created /config: org.apache.solr.handler.SolrConfigHandler
   [junit4]   2> 1053525 T7214 oasc.RequestHandlers.initHandlersFromConfig created /schema: org.apache.solr.handler.SchemaHandler
   [junit4]   2> 1053526 T7214 oasc.RequestHandlers.initHandlersFromConfig created /replication: org.apache.solr.handler.ReplicationHandler
   [junit4]   2> 1053527 T7214 oasc.RequestHandlers.initHandlersFromConfig created /get: org.apache.solr.handler.RealTimeGetHandler
   [junit4]   2> 1053527 T7214 oasc.RequestHandlers.initHandlersFromConfig created /admin/luke: org.apache.solr.handler.admin.LukeRequestHandler
   [junit4]   2> 1053528 T7214 oasc.RequestHandlers.initHandlersFromConfig created /admin/system: org.apache.solr.handler.admin.SystemInfoHandler
   [junit4]   2> 1053529 T7214 oasc.RequestHandlers.initHandlersFromConfig created /admin/mbeans: org.apache.solr.handler.admin.SolrInfoMBeanHandler
   [junit4]   2> 1053530 T7214 oasc.RequestHandlers.initHandlersFromConfig created /admin/plugins: org.apache.solr.handler.admin.PluginInfoHandler
   [junit4]   2> 1053531 T7214 oasc.RequestHandlers.initHandlersFromConfig created /admin/threads: org.apache.solr.handler.admin.ThreadDumpHandler
   [junit4]   2> 1053531 T7214 oasc.RequestHandlers.initHandlersFromConfig created /admin/properties: org.apache.solr.handler.admin.PropertiesRequestHandler
   [junit4]   2> 1053532 T7214 oasc.RequestHandlers.initHandlersFromConfig created /admin/logging: org.apache.solr.handler.admin.LoggingHandler
   [junit4]   2> 1053533 T7214 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 1053534 T7214 oasc.RequestHandlers.initHandlersFromConfig created /admin/ping: org.apache.solr.handler.PingRequestHandler
   [junit4]   2> 1053534 T7214 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 1053537 T7214 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 1053538 T7214 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 1053539 T7214 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 1053540 T7214 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 1053540 T7214 oasc.SolrCore.initStatsCache Using default statsCache cache: org.apache.solr.search.stats.LocalStatsCache
   [junit4]   2> 1053541 T7214 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 1053541 T7214 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 1053543 T7214 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=14, maxMergeAtOnceExplicit=26, maxMergedSegmentMB=0.4501953125, floorSegmentMB=2.01953125, forceMergeDeletesPctAllowed=22.40180107546433, segmentsPerTier=42.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
   [junit4]   2> 1053543 T7214 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@9f6deb lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@107242d),segFN=segments_1,generation=1}
   [junit4]   2> 1053544 T7214 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1053544 T7214 oass.SolrIndexSearcher.<init> Opening Searcher@c666ef[collection1] main
   [junit4]   2> 1053544 T7214 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 1053545 T7214 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 1053545 T7214 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
   [junit4]   2> 1053546 T7214 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
   [junit4]   2> 1053546 T7214 oasr.RestManager.init Initializing RestManager with initArgs: {}
   [junit4]   2> 1053546 T7214 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 1053547 T7214 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
   [junit4]   2> 1053547 T7214 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 1053547 T7214 oasr.RestManager.init Initializing 0 registered ManagedResources
   [junit4]   2> 1053547 T7214 oash.ReplicationHandler.inform Commits will be reserved for  10000
   [junit4]   2> 1053549 T7215 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@c666ef[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 1053549 T7214 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 1053550 T7218 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:57159 collection:collection1 shard:shard2
   [junit4]   2> 1053551 T7152 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0
   [junit4]   2> 1053552 T7152 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 1053552 T7218 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
   [junit4]   2> 1053559 T7218 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
   [junit4]   2> 1053560 T7180 oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected
   [junit4]   2> 1053561 T7218 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 1053561 T7218 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> ASYNC  NEW_CORE C5485 name=collection1 org.apache.solr.core.SolrCore@cb5aca url=http://127.0.0.1:57159/collection1 node=127.0.0.1:57159_ C5485_STATE=coll:collection1 core:collection1 props:{core=collection1, base_url=http://127.0.0.1:57159, node_name=127.0.0.1:57159_, state=down}
   [junit4]   2> 1053561 T7218 C5485 P57159 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:57159/collection1/
   [junit4]   2> 1053561 T7181 oasc.Overseer$ClusterStateUpdater.run processMessage: queueSize: 1, message = {
   [junit4]   2> 	  "operation":"leader",
   [junit4]   2> 	  "shard":"shard2",
   [junit4]   2> 	  "collection":"collection1"} current state version: 4
   [junit4]   2> 1053561 T7218 C5485 P57159 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 1053562 T7218 C5485 P57159 oasc.SyncStrategy.syncToMe http://127.0.0.1:57159/collection1/ has no replicas
   [junit4]   2> 1053562 T7218 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:57159/collection1/ shard2
   [junit4]   2> 1053562 T7218 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
   [junit4]   2> 1053562 T7181 oasco.ZkStateWriter.writePendingUpdates going to update_collection /collections/collection1/state.json version: 1
   [junit4]   2> 1053563 T7213 oascc.ZkStateReader$7.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json, has occurred - updating... 
   [junit4]   2> 1053564 T7213 oascc.ZkStateReader.updateWatchedCollection Updating data for collection1 to ver 2 
   [junit4]   2> 1053566 T7181 oasc.Overseer$ClusterStateUpdater.run processMessage: queueSize: 1, message = {
   [junit4]   2> 	  "operation":"leader",
   [junit4]   2> 	  "shard":"shard2",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:57159",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "state":"active"} current state version: 4
   [junit4]   2> 1053567 T7181 oasco.ZkStateWriter.writePendingUpdates going to update_collection /collections/collection1/state.json version: 2
   [junit4]   2> 1053568 T7213 oascc.ZkStateReader$7.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json, has occurred - updating... 
   [junit4]   2> 1053568 T7213 oascc.ZkStateReader.updateWatchedCollection Updating data for collection1 to ver 3 
   [junit4]   2> 1053570 T7180 oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected
   [junit4]   2> 1053617 T7218 oasc.ZkController.register We are http://127.0.0.1:57159/collection1/ and leader is http://127.0.0.1:57159/collection1/
   [junit4]   2> 1053617 T7218 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:57159
   [junit4]   2> 1053617 T7218 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 1053617 T7218 oasc.ZkController.publish publishing core=collection1 state=active collection=collection1
   [junit4]   2> 1053617 T7218 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1053619 T7180 oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected
   [junit4]   2> 1053620 T7181 oasc.Overseer$ClusterStateUpdater.run processMessage: queueSize: 1, message = {
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "core_node_name":"core_node1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "base_url":"http://127.0.0.1:57159",
   [junit4]   2> 	  "node_name":"127.0.0.1:57159_",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "shard":"shard2",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "operation":"state"} current state version: 4
   [junit4]   2> 1053621 T7181 oasco.ReplicaMutator.updateState Update state numShards=2 message={
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "core_node_name":"core_node1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "base_url":"http://127.0.0.1:57159",
   [junit4]   2> 	  "node_name":"127.0.0.1:57159_",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "shard":"shard2",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "operation":"state"}
   [junit4]   2> 1053623 T7181 oasco.ZkStateWriter.writePendingUpdates going to update_collection /collections/collection1/state.json version: 3
   [junit4]   2> 1053623 T7213 oascc.ZkStateReader$7.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json, has occurred - updating... 
   [junit4]   2> 1053624 T7218 oascc.ZkStateReader.updateWatchedCollection Updating data for collection1 to ver 4 
   [junit4]   2> 1053624 T7213 oascc.ZkStateReader.updateWatchedCollection Updating data for collection1 to ver 4 
   [junit4]   2> 1053837 T7152 oas.SolrTestCaseJ4.writeCoreProperties Writing core.properties file to /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.HttpPartitionTest 9B132FABC979468C-001/shard-2-001/cores/collection1
   [junit4]   2> 1053838 T7152 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 2
   [junit4]   2> 1053839 T7152 oejs.Server.doStart jetty-9.2.6.v20141205
   [junit4]   2> 1053841 T7152 oejsh.ContextHandler.doStart Started o.e.j.s.ServletContextHandler@5fa913{/,null,AVAILABLE}
   [junit4]   2> 1053842 T7152 oejs.AbstractConnector.doStart Started ServerConnector@16ac93d{HTTP/1.1}{127.0.0.1:33576}
   [junit4]   2> 1053842 T7152 oejs.Server.doStart Started @1054874ms
   [junit4]   2> 1053842 T7152 oass.SolrDispatchFilter.init SolrDispatchFilter.init()sun.misc.Launcher$AppClassLoader@e2f2a
   [junit4]   2> 1053843 T7152 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 1053843 T7152 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.HttpPartitionTest 9B132FABC979468C-001/shard-2-001
   [junit4]   2> 1053843 T7152 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.HttpPartitionTest 9B132FABC979468C-001/shard-2-001/'
   [junit4]   2> 1053876 T7152 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.HttpPartitionTest 9B132FABC979468C-001/shard-2-001/solr.xml
   [junit4]   2> 1053884 T7152 oasc.CorePropertiesLocator.<init> Config-defined core root directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.HttpPartitionTest 9B132FABC979468C-001/shard-2-001/cores
   [junit4]   2> 1053884 T7152 oasc.CoreContainer.<init> New CoreContainer 29187761
   [junit4]   2> 1053885 T7152 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.HttpPartitionTest 9B132FABC979468C-001/shard-2-001/]
   [junit4]   2> 1053885 T7152 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 1053885 T7152 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 1053886 T7152 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 1053886 T7152 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 1053886 T7152 oashc.HttpShardHandlerFactory.getParameter Setting maxConnections to: 10000
   [junit4]   2> 1053886 T7152 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 1053887 T7152 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 1053887 T7152 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 1053887 T7152 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 1053888 T7152 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 1053888 T7152 oashc.HttpShardHandlerFactory.getParameter Setting useRetries to: false
   [junit4]   2> 1053888 T7152 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
   [junit4]   2> 1053889 T7152 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 1053889 T7152 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 1053889 T7152 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 1053890 T7152 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:59165/solr
   [junit4]   2> 1053890 T7152 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 1053890 T7152 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider
   [junit4]   2> 1053891 T7152 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1053893 T7233 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1b4eb8d name:ZooKeeperConnection Watcher:127.0.0.1:59165 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1053894 T7152 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1053894 T7152 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider
   [junit4]   2> 1053897 T7152 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1053898 T7236 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@13102ee name:ZooKeeperConnection Watcher:127.0.0.1:59165/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1053898 T7152 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1053910 T7152 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1054918 T7152 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:50099_
   [junit4]   2> 1054920 T7152 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:50099_
   [junit4]   2> 1054927 T7152 oasc.Overseer.close Overseer (id=null) closing
   [junit4]   2> 1054933 T7152 oasc.CorePropertiesLocator.discover Looking for core definitions underneath /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.HttpPartitionTest 9B132FABC979468C-001/shard-2-001/cores
   [junit4]   2> 1054937 T7152 oasc.CorePropertiesLocator.discoverUnder Found core collection1 in /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.HttpPartitionTest 9B132FABC979468C-001/shard-2-001/cores/collection1/
   [junit4]   2> 1054938 T7152 oasc.CorePropertiesLocator.discover Found 1 core definitions
   [junit4]   2> 1054942 T7237 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
   [junit4]   2> 1054942 T7237 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1054944 T7180 oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected
   [junit4]   2> 1054945 T7237 oasc.ZkController.preRegister Registering watch for external collection collection1
   [junit4]   2> 1054945 T7237 oascc.ZkStateReader.addZkWatch addZkWatch collection1
   [junit4]   2> 1054945 T7181 oasc.Overseer$ClusterStateUpdater.run processMessage: queueSize: 1, message = {
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "base_url":"http://127.0.0.1:50099",
   [junit4]   2> 	  "node_name":"127.0.0.1:50099_",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "operation":"state"} current state version: 4
   [junit4]   2> 1054946 T7237 oascc.ZkStateReader.addZkWatch Updating collection state at /collections/collection1/state.json from ZooKeeper... 
   [junit4]   2> 1054947 T7181 oasco.ReplicaMutator.updateState Update state numShards=2 message={
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "base_url":"http://127.0.0.1:50099",
   [junit4]   2> 	  "node_name":"127.0.0.1:50099_",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "operation":"state"}
   [junit4]   2> 1054947 T7181 oasco.ReplicaMutator.updateState Collection already exists with numShards=2
   [junit4]   2> 1054948 T7181 oasco.ReplicaMutator.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 1054949 T7237 oascc.ZkStateReader.updateWatchedCollection Updating data for collection1 to ver 4 
   [junit4]   2> 1054949 T7181 oasco.ZkStateWriter.writePendingUpdates going to update_collection /collections/collection1/state.json version: 4
   [junit4]   2> 1054950 T7237 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 1054950 T7236 oascc.ZkStateReader$7.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json, has occurred - updating... 
   [junit4]   2> 1054950 T7213 oascc.ZkStateReader$7.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json, has occurred - updating... 
   [junit4]   2> 1054951 T7236 oascc.ZkStateReader.updateWatchedCollection Updating data for collection1 to ver 5 
   [junit4]   2> 1054951 T7213 oascc.ZkStateReader.updateWatchedCollection Updating data for collection1 to ver 5 
   [junit4]   2> 1055950 T7237 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 1055951 T7237 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 1055952 T7237 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 1055952 T7237 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 1055954 T7237 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 1055955 T7237 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.HttpPartitionTest 9B132FABC979468C-001/shard-2-001/cores/collection1/'
   [junit4]   2> 1055980 T7237 oasc.ZkController.watchZKConfDir watch zkdir /configs/conf1
   [junit4]   2> 1055983 T7237 oasc.Config.<init> loaded config solrconfig.xml with version 0 
   [junit4]   2> 1055990 T7237 oasc.SolrConfig.refreshRequestParams current version of requestparams : -1
   [junit4]   2> 1055995 T7237 oasc.SolrConfig.<init> Using Lucene MatchVersion: 6.0.0
   [junit4]   2> 1056012 T7237 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 1056014 T7237 oass.IndexSchema.readSchema Reading Solr Schema from /configs/conf1/schema.xml
   [junit4]   2> 1056024 T7237 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 1056149 T7237 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 1056153 T7237 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 1056155 T7237 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 1056172 T7237 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1056177 T7237 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1056181 T7237 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1056182 T7237 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1056182 T7237 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1056183 T7237 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1056184 T7237 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1056185 T7237 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1056185 T7237 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection collection1
   [junit4]   2> 1056186 T7237 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 1056186 T7237 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.HttpPartitionTest 9B132FABC979468C-001/shard-2-001/cores/collection1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.HttpPartitionTest 9B132FABC979468C-001/tempDir-001/jetty2/
   [junit4]   2> 1056187 T7237 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@166517b
   [junit4]   2> 1056188 T7237 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.HttpPartitionTest 9B132FABC979468C-001/tempDir-001/jetty2
   [junit4]   2> 1056188 T7237 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.HttpPartitionTest 9B132FABC979468C-001/tempDir-001/jetty2/index/
   [junit4]   2> 1056188 T7237 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.HttpPartitionTest 9B132FABC979468C-001/tempDir-001/jetty2/index' doesn't exist. Creating new index...
   [junit4]   2> 1056189 T7237 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.HttpPartitionTest 9B132FABC979468C-001/tempDir-001/jetty2/index
   [junit4]   2> 1056189 T7237 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=47, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.5349869505033221]
   [junit4]   2> 1056190 T7237 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@16092f2 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@16981ef),segFN=segments_1,generation=1}
   [junit4]   2> 1056191 T7237 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1056195 T7237 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 1056196 T7237 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 1056196 T7237 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 1056197 T7237 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1056197 T7237 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1056197 T7237 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 1056198 T7237 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1056198 T7237 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1056198 T7237 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 1056200 T7237 oasc.RequestHandlers.initHandlersFromConfig created /update: org.apache.solr.handler.UpdateRequestHandler
   [junit4]   2> 1056200 T7237 oasc.RequestHandlers.initHandlersFromConfig created /update/json: org.apache.solr.handler.UpdateRequestHandler
   [junit4]   2> 1056201 T7237 oasc.RequestHandlers.initHandlersFromConfig created /update/csv: org.apache.solr.handler.UpdateRequestHandler
   [junit4]   2> 1056202 T7237 oasc.RequestHandlers.initHandlersFromConfig created /update/json/docs: org.apache.solr.handler.UpdateRequestHandler
   [junit4]   2> 1056202 T7237 oasc.RequestHandlers.initHandlersFromConfig created /config: org.apache.solr.handler.SolrConfigHandler
   [junit4]   2> 1056203 T7237 oasc.RequestHandlers.initHandlersFromConfig created /schema: org.apache.solr.handler.SchemaHandler
   [junit4]   2> 1056204 T7237 oasc.RequestHandlers.initHandlersFromConfig created /replication: org.apache.solr.handler.ReplicationHandler
   [junit4]   2> 1056205 T7237 oasc.RequestHandlers.initHandlersFromConfig created /get: org.apache.solr.handler.RealTimeGetHandler
   [junit4]   2> 1056206 T7237 oasc.RequestHandlers.initHandlersFromConfig created /admin/luke: org.apache.solr.handler.admin.LukeRequestHandler
   [junit4]   2> 1056207 T7237 oasc.RequestHandlers.initHandlersFromConfig created /admin/system: org.apache.solr.handler.admin.SystemInfoHandler
   [junit4]   2> 1056208 T7237 oasc.RequestHandlers.initHandlersFromConfig created /admin/mbeans: org.apache.solr.handler.admin.SolrInfoMBeanHandler
   [junit4]   2> 1056209 T7237 oasc.RequestHandlers.initHandlersFromConfig created /admin/plugins: org.apache.solr.handler.admin.PluginInfoHandler
   [junit4]   2> 1056209 T7237 oasc.RequestHandlers.initHandlersFromConfig created /admin/threads: org.apache.solr.handler.admin.ThreadDumpHandler
   [junit4]   2> 1056210 T7237 oasc.RequestHandlers.initHandlersFromConfig created /admin/properties: org.apache.solr.handler.admin.PropertiesRequestHandler
   [junit4]   2> 1056211 T7237 oasc.RequestHandlers.initHandlersFromConfig created /admin/logging: org.apache.solr.handler.admin.LoggingHandler
   [junit4]   2> 1056212 T7237 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 1056213 T7237 oasc.RequestHandlers.initHandlersFromConfig created /admin/ping: org.apache.solr.handler.PingRequestHandler
   [junit4]   2> 1056213 T7237 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 1056216 T7237 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 1056217 T7237 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 1056218 T7237 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 1056219 T7237 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 1056220 T7237 oasc.SolrCore.initStatsCache Using default statsCache cache: org.apache.solr.search.stats.LocalStatsCache
   [junit4]   2> 1056221 T7237 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 1056221 T7237 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 1056222 T7237 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=14, maxMergeAtOnceExplicit=26, maxMergedSegmentMB=0.4501953125, floorSegmentMB=2.01953125, forceMergeDeletesPctAllowed=22.40180107546433, segmentsPerTier=42.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
   [junit4]   2> 1056223 T7237 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@16092f2 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@16981ef),segFN=segments_1,generation=1}
   [junit4]   2> 1056223 T7237 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1056224 T7237 oass.SolrIndexSearcher.<init> Opening Searcher@f74c8e[collection1] main
   [junit4]   2> 1056224 T7237 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 1056225 T7237 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 1056225 T7237 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
   [junit4]   2> 1056225 T7237 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
   [junit4]   2> 1056226 T7237 oasr.RestManager.init Initializing RestManager with initArgs: {}
   [junit4]   2> 1056226 T7237 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 1056226 T7237 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
   [junit4]   2> 1056227 T7237 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 1056227 T7237 oasr.RestManager.init Initializing 0 registered ManagedResources
   [junit4]   2> 1056227 T7237 oash.ReplicationHandler.inform Commits will be reserved for  10000
   [junit4]   2> 1056229 T7238 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@f74c8e[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 1056229 T7237 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 1056230 T7241 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:50099 collection:collection1 shard:shard1
   [junit4]   2> 1056231 T7152 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0
   [junit4]   2> 1056231 T7152 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 1056232 T7241 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 1056236 T7241 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 1056238 T7180 oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected
   [junit4]   2> 1056238 T7241 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 1056238 T7241 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> 1056238 T7181 oasc.Overseer$ClusterStateUpdater.run processMessage: queueSize: 1, message = {
   [junit4]   2> 	  "operation":"leader",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "collection":"collection1"} current state version: 4
   [junit4]   2> ASYNC  NEW_CORE C5486 name=collection1 org.apache.solr.core.SolrCore@1612ab3 url=http://127.0.0.1:50099/collection1 node=127.0.0.1:50099_ C5486_STATE=coll:collection1 core:collection1 props:{core=collection1, base_url=http://127.0.0.1:50099, node_name=127.0.0.1:50099_, state=down}
   [junit4]   2> 1056238 T7241 C5486 P50099 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:50099/collection1/
   [junit4]   2> 1056239 T7241 C5486 P50099 

[...truncated too long message...]

teWriter.writePendingUpdates going to update_collection /collections/collection1/state.json version: 19
   [junit4]   2> 1144890 T7538 oascc.ZkStateReader$7.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json, has occurred - updating... 
   [junit4]   2> 1144922 T7152 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
   [junit4]   2> 1144922 T7152 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.HttpPartitionTest 9B132FABC979468C-001/tempDir-001/jetty3 [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.HttpPartitionTest 9B132FABC979468C-001/tempDir-001/jetty3;done=false>>]
   [junit4]   2> 1144923 T7152 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.HttpPartitionTest 9B132FABC979468C-001/tempDir-001/jetty3
   [junit4]   2> 1144923 T7152 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.HttpPartitionTest 9B132FABC979468C-001/tempDir-001/jetty3/index [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.HttpPartitionTest 9B132FABC979468C-001/tempDir-001/jetty3/index;done=false>>]
   [junit4]   2> 1144924 T7152 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.HttpPartitionTest 9B132FABC979468C-001/tempDir-001/jetty3/index
   [junit4]   2> 1144924 T7152 oasc.Overseer.close Overseer (id=93284828250832907-127.0.0.1:44726_-n_0000000003) closing
   [junit4]   2> 1144925 T7582 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:44726_
   [junit4]   2> 1146425 T7538 oascc.ZkStateReader$7.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> 1146425 T7539 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> 1146428 T7152 oejs.AbstractConnector.doStop Stopped ServerConnector@15e26{HTTP/1.1}{127.0.0.1:0}
   [junit4]   2> 1146429 T7152 oejsh.ContextHandler.doStop Stopped o.e.j.s.ServletContextHandler@157e87{/,null,UNAVAILABLE}
   [junit4]   2> 1146432 T7152 oasc.ChaosMonkey.monkeyLog monkey: stop shard! 43708
   [junit4]   2> 1146433 T7152 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:59165 59165
   [junit4]   2> 1147131 T7153 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:59165 59165
   [junit4]   2> 1147134 T7153 oasc.ZkTestServer$ZKServerMain.runFromConfig WARN Watch limit violations: 
   [junit4]   2> 	Maximum concurrent create/delete watches above limit:
   [junit4]   2> 	
   [junit4]   2> 		6	/solr/aliases.json
   [junit4]   2> 		6	/solr/clusterstate.json
   [junit4]   2> 		4	/solr/collections/collection1/state.json
   [junit4]   2> 		4	/solr/configs/conf1
   [junit4]   2> 		3	/solr/collections/c8n_1x3/state.json
   [junit4]   2> 		3	/solr/collections/c8n_1x2_leader_session_loss/state.json
   [junit4]   2> 		2	/solr/collections/c8n_1x2/state.json
   [junit4]   2> 		2	/solr/collections/c8n_crud_1x2/state.json
   [junit4]   2> 	
   [junit4]   2> 	Maximum concurrent data watches above limit:
   [junit4]   2> 	
   [junit4]   2> 		2	/solr/collections/c8n_1x3/leader_elect/shard1/election/93284828250832899-core_node2-n_0000000000
   [junit4]   2> 		2	/solr/overseer_elect/election/93284828250832903-127.0.0.1:57159_-n_0000000001
   [junit4]   2> 	
   [junit4]   2> 	Maximum concurrent children watches above limit:
   [junit4]   2> 	
   [junit4]   2> 		7	/solr/live_nodes
   [junit4]   2> 		3	/solr/overseer/queue
   [junit4]   2> 		3	/solr/overseer/collection-queue-work
   [junit4]   2> 	
   [junit4]   2> 1147135 T7152 oasc.SocketProxy.close WARN Closing 12 connections to: http://127.0.0.1:50099/
   [junit4]   2> 1147136 T7152 oasc.SocketProxy.close WARN Closing 11 connections to: http://127.0.0.1:44726/
   [junit4]   2> 1147137 T7152 oasc.SocketProxy.close WARN Closing 20 connections to: http://127.0.0.1:43708/
   [junit4]   2> 1147137 T7152 oasc.SocketProxy.close WARN Closing 6 connections to: http://127.0.0.1:57159/
   [junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=HttpPartitionTest -Dtests.method=test -Dtests.seed=9B132FABC979468C -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=nl_NL -Dtests.timezone=Australia/Victoria -Dtests.asserts=true -Dtests.file.encoding=UTF-8
   [junit4] ERROR   98.3s J0 | HttpPartitionTest.test <<<
   [junit4]    > Throwable #1: com.carrotsearch.randomizedtesting.UncaughtExceptionError: Captured an uncaught exception in thread: Thread[id=7566, name=SocketProxy-Response-33533:40315, state=RUNNABLE, group=TGRP-HttpPartitionTest]
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([9B132FABC979468C:1347107167852B74]:0)
   [junit4]    > Caused by: java.lang.RuntimeException: java.net.SocketException: Socket is closed
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([9B132FABC979468C]:0)
   [junit4]    > 	at org.apache.solr.cloud.SocketProxy$Bridge$Pump.run(SocketProxy.java:344)
   [junit4]    > Caused by: java.net.SocketException: Socket is closed
   [junit4]    > 	at java.net.Socket.setSoTimeout(Socket.java:1137)
   [junit4]    > 	at org.apache.solr.cloud.SocketProxy$Bridge$Pump.run(SocketProxy.java:341)
   [junit4]   2> 1147164 T7152 oas.SolrTestCaseJ4.deleteCore ###deleteCore
   [junit4]   2> NOTE: test params are: codec=Asserting(Lucene50): {_version_=PostingsFormat(name=Direct), multiDefault=BlockTreeOrds(blocksize=128), a_t=PostingsFormat(name=Direct), intDefault=PostingsFormat(name=Direct), id=PostingsFormat(name=MockRandom), text=PostingsFormat(name=Memory doPackFST= false), range_facet_l=PostingsFormat(name=Direct), timestamp=PostingsFormat(name=Direct)}, docValues:{timestamp=DocValuesFormat(name=Lucene50)}, sim=DefaultSimilarity, locale=nl_NL, timezone=Australia/Victoria
   [junit4]   2> NOTE: Linux 3.13.0-45-generic i386/Oracle Corporation 1.8.0_40-ea (32-bit)/cpus=8,threads=1,free=97026272,total=196583424
   [junit4]   2> NOTE: All tests run in this JVM: [TestInfoStreamLogging, TestDocumentBuilder, TestCustomSort, DeleteInactiveReplicaTest, TestCharFilters, TimeZoneUtilsTest, SynonymTokenizerTest, TestManagedSchemaFieldTypeResource, TestIndexSearcher, DistributedFacetPivotLargeTest, PreAnalyzedFieldTest, TestCursorMarkWithoutUniqueKey, TestElisionMultitermQuery, AnalyticsMergeStrategyTest, DefaultValueUpdateProcessorTest, TestBlendedInfixSuggestions, LukeRequestHandlerTest, TestReloadAndDeleteDocs, TestCSVLoader, TestComplexPhraseQParserPlugin, UnloadDistributedZkTest, DistributedQueueTest, TestSolrXml, TestMiniSolrCloudCluster, TestSchemaNameResource, HdfsWriteToMultipleCollectionsTest, TestPostingsSolrHighlighter, SolrTestCaseJ4Test, DistributedFacetPivotSmallAdvancedTest, TestArbitraryIndexDir, TestRandomDVFaceting, TestSchemaSimilarityResource, CoreAdminCreateDiscoverTest, TestQueryUtils, CloudMLTQParserTest, SolrXmlInZkTest, ExternalCollectionsTest, FacetPivotSmallTest, ClusterStateTest, BJQParserTest, BufferStoreTest, TestIBSimilarityFactory, TestAtomicUpdateErrorCases, CacheHeaderTest, DirectUpdateHandlerTest, TestUniqueKeyFieldResource, DeleteShardTest, QueryElevationComponentTest, TestHashPartitioner, HdfsDirectoryFactoryTest, DistributedSpellCheckComponentTest, SimpleFacetsTest, FieldAnalysisRequestHandlerTest, TestCollationField, TestFastLRUCache, DistributedFacetPivotLongTailTest, TestRestManager, TestReplicationHandler, SyncSliceTest, ZkStateWriterTest, TestSolrConfigHandlerCloud, HdfsChaosMonkeySafeLeaderTest, AliasIntegrationTest, AssignTest, BlockCacheTest, TestSurroundQueryParser, TestAddFieldRealTimeGet, TestAnalyzeInfixSuggestions, TestStressUserVersions, RequiredFieldsTest, TestSweetSpotSimilarityFactory, RequestHandlersTest, DistributedSuggestComponentTest, TestSerializedLuceneMatchVersion, DocValuesMissingTest, SystemInfoHandlerTest, IndexSchemaRuntimeFieldTest, TestShortCircuitedRequests, TestBlobHandler, DateRangeFieldTest, TestSchemaResource, TestComponentsName, OverseerRolesTest, TestCoreContainer, TestCloudManagedSchemaConcurrent, TestStressVersions, TestLRUStatsCache, HttpPartitionTest]
   [junit4] Completed on J0 in 98.77s, 1 test, 1 error <<< FAILURES!

[...truncated 860 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:519: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:467: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:61: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/extra-targets.xml:39: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build.xml:191: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/common-build.xml:512: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:1348: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:956: There were test failures: 464 suites, 1854 tests, 1 error, 46 ignored (21 assumptions)

Total time: 71 minutes 31 seconds
Build step 'Invoke Ant' marked build as failure
[description-setter] Description set: Java: 32bit/jdk1.8.0_40-ea-b22 -client -XX:+UseConcMarkSweepGC
Archiving artifacts
Recording test results
Email was triggered for: Failure - Any
Sending email for trigger: Failure - Any